2026-08-26 20:07:57.671213 | Job console starting
2026-08-26 20:07:57.679826 | Updating git repos
2026-08-26 20:08:00.551050 | Cloning repos into workspace
2026-08-26 20:08:04.911716 | Restoring repo states
2026-08-26 20:08:05.645571 | Merging changes
2026-08-26 20:08:06.243715 | Checking out repos
2026-08-26 20:08:10.851471 | Preparing playbooks
2026-08-26 20:08:12.816074 | Running Ansible setup
2026-08-26 20:08:18.126791 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-08-26 20:08:18.740385 | 
2026-08-26 20:08:18.740500 | PLAY [localhost]
2026-08-26 20:08:18.747823 | 
2026-08-26 20:08:18.747898 | TASK [Gathering Facts]
2026-08-26 20:08:19.639508 | localhost | ok
2026-08-26 20:08:19.649856 | 
2026-08-26 20:08:19.649947 | TASK [Setup log path fact]
2026-08-26 20:08:19.673373 | localhost | ok
2026-08-26 20:08:19.685676 | 
2026-08-26 20:08:19.685761 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-08-26 20:08:19.714702 | localhost | ok
2026-08-26 20:08:19.722952 | 
2026-08-26 20:08:19.723044 | TASK [emit-job-header : Print job information]
2026-08-26 20:08:19.764624 | # Job Information
2026-08-26 20:08:19.764789 | Ansible Version: 2.16.18
2026-08-26 20:08:19.764834 | Job: magnum-cluster-api-hydrophone-v1.33.12-calico
2026-08-26 20:08:19.764866 | Pipeline: check
2026-08-26 20:08:19.764895 | Executor: 2d72f0692154
2026-08-26 20:08:19.764923 | Triggered by: https://github.com/vexxhost/magnum-cluster-api/pull/1101
2026-08-26 20:08:19.764994 | Event ID: 31440990-a189-11f1-9200-9448bf33b63d
2026-08-26 20:08:19.768899 | 
2026-08-26 20:08:19.769227 | LOOP [emit-job-header : Print node information]
2026-08-26 20:08:19.882511 | localhost | ok:
2026-08-26 20:08:19.882964 | localhost | # Node Information
2026-08-26 20:08:19.883028 | localhost | Inventory Hostname: controller
2026-08-26 20:08:19.883076 | localhost | Hostname: np0000191197
2026-08-26 20:08:19.883120 | localhost | Username: zuul
2026-08-26 20:08:19.883169 | localhost | Distro: Ubuntu 24.04
2026-08-26 20:08:19.883212 | localhost | Provider: yul1
2026-08-26 20:08:19.883256 | localhost | Region: ca-ymq-1
2026-08-26 20:08:19.883297 | localhost | Label: ubuntu-noble-16
2026-08-26 20:08:19.883338 | localhost | Product Name: OpenStack Nova
2026-08-26 20:08:19.883379 | localhost | Interface IP: 162.253.55.119
2026-08-26 20:08:19.897657 | 
2026-08-26 20:08:19.897781 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-08-26 20:08:20.307201 | localhost -> localhost | changed
2026-08-26 20:08:20.316868 | 
2026-08-26 20:08:20.316935 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-08-26 20:08:21.380063 | localhost -> localhost | changed
2026-08-26 20:08:21.393712 | 
2026-08-26 20:08:21.393773 | PLAY [all]
2026-08-26 20:08:21.403036 | 
2026-08-26 20:08:21.403108 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-08-26 20:08:21.650289 | controller -> localhost | ok
2026-08-26 20:08:21.661803 | 
2026-08-26 20:08:21.662027 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-08-26 20:08:21.700330 | controller | ok
2026-08-26 20:08:21.841830 | controller | included: /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-08-26 20:08:21.848100 | 
2026-08-26 20:08:21.848163 | TASK [add-build-sshkey : Create Temp SSH key]
2026-08-26 20:08:23.039519 | controller -> localhost | Generating public/private rsa key pair.
2026-08-26 20:08:23.039748 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/work/3237ca2b45394bc2ae964af18fe80059_id_rsa
2026-08-26 20:08:23.039789 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/work/3237ca2b45394bc2ae964af18fe80059_id_rsa.pub
2026-08-26 20:08:23.039821 | controller -> localhost | The key fingerprint is:
2026-08-26 20:08:23.039851 | controller -> localhost | SHA256:z9aOQxjkGueVlB7/DPqDRen0N2kCxb2tMTDN5gqbrkw zuul-build-sshkey
2026-08-26 20:08:23.039902 | controller -> localhost | The key's randomart image is:
2026-08-26 20:08:23.039933 | controller -> localhost | +---[RSA 3072]----+
2026-08-26 20:08:23.039969 | controller -> localhost | |           ..o.  |
2026-08-26 20:08:23.040000 | controller -> localhost | |        . + oo+. |
2026-08-26 20:08:23.040029 | controller -> localhost | |       o o +.*  o|
2026-08-26 20:08:23.040058 | controller -> localhost | |      . + =.* +..|
2026-08-26 20:08:23.040086 | controller -> localhost | |       =S+ O.* +.|
2026-08-26 20:08:23.040114 | controller -> localhost | |      . oo=.+.=+.|
2026-08-26 20:08:23.040142 | controller -> localhost | |        Eo++. o..|
2026-08-26 20:08:23.040170 | controller -> localhost | |       o .+oo    |
2026-08-26 20:08:23.040201 | controller -> localhost | |        o.....   |
2026-08-26 20:08:23.040230 | controller -> localhost | +----[SHA256]-----+
2026-08-26 20:08:23.040292 | controller -> localhost | ok: Runtime: 0:00:00.744178
2026-08-26 20:08:23.048358 | 
2026-08-26 20:08:23.048421 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-08-26 20:08:23.083824 | controller | ok
2026-08-26 20:08:23.093208 | controller | included: /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-08-26 20:08:23.101402 | 
2026-08-26 20:08:23.101471 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-08-26 20:08:23.126477 | controller | skipping: Conditional result was False
2026-08-26 20:08:23.138535 | 
2026-08-26 20:08:23.138799 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-08-26 20:08:23.747400 | controller | changed
2026-08-26 20:08:23.754431 | 
2026-08-26 20:08:23.754496 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-08-26 20:08:24.010892 | controller | ok
2026-08-26 20:08:24.016752 | 
2026-08-26 20:08:24.016817 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-08-26 20:08:24.610452 | controller | changed
2026-08-26 20:08:24.618405 | 
2026-08-26 20:08:24.618474 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-08-26 20:08:25.321226 | controller | changed
2026-08-26 20:08:25.329066 | 
2026-08-26 20:08:25.329139 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-08-26 20:08:25.356654 | controller | skipping: Conditional result was False
2026-08-26 20:08:25.369248 | 
2026-08-26 20:08:25.369352 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-08-26 20:08:25.708427 | controller -> localhost | changed
2026-08-26 20:08:25.725599 | 
2026-08-26 20:08:25.725720 | TASK [add-build-sshkey : Add back temp key]
2026-08-26 20:08:25.998901 | controller -> localhost | Identity added: /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/work/3237ca2b45394bc2ae964af18fe80059_id_rsa (zuul-build-sshkey)
2026-08-26 20:08:25.999142 | controller -> localhost | ok: Runtime: 0:00:00.013319
2026-08-26 20:08:26.007843 | 
2026-08-26 20:08:26.007911 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-08-26 20:08:26.349083 | controller | ok
2026-08-26 20:08:26.356258 | 
2026-08-26 20:08:26.356327 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-08-26 20:08:26.381827 | controller | skipping: Conditional result was False
2026-08-26 20:08:26.399540 | 
2026-08-26 20:08:26.399672 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-08-26 20:08:26.758352 | controller | ok
2026-08-26 20:08:26.766884 | 
2026-08-26 20:08:26.766986 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-08-26 20:08:58.793878 | controller | Output suppressed because no_log was given
2026-08-26 20:08:58.811110 | 
2026-08-26 20:08:58.811241 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-08-26 20:08:59.085694 | controller | ok: "logs"
2026-08-26 20:08:59.086214 | controller | ok: All items complete
2026-08-26 20:08:59.086245 | 
2026-08-26 20:08:59.265078 | controller | ok: "artifacts"
2026-08-26 20:08:59.448293 | controller | ok: "docs"
2026-08-26 20:08:59.458278 | 
2026-08-26 20:08:59.458426 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-08-26 20:08:59.705975 | controller | changed: "logs"
2026-08-26 20:08:59.894744 | controller | changed: "artifacts"
2026-08-26 20:09:00.110871 | controller | changed: "docs"
2026-08-26 20:09:00.131386 | 
2026-08-26 20:09:00.131487 | PLAY RECAP
2026-08-26 20:09:00.131551 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-08-26 20:09:00.131592 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-08-26 20:09:00.131624 | 
2026-08-26 20:09:00.275209 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-08-26 20:09:00.291867 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-08-26 20:09:01.074953 | 
2026-08-26 20:09:01.200423 | PLAY [all]
2026-08-26 20:09:01.225568 | 
2026-08-26 20:09:01.225657 | TASK [Fix the permissions of the zuul home directory]
2026-08-26 20:09:01.635038 | controller | changed
2026-08-26 20:09:01.642832 | 
2026-08-26 20:09:01.642910 | TASK [Gather minimum local MTU]
2026-08-26 20:09:01.710747 | controller | ok
2026-08-26 20:09:01.719634 | 
2026-08-26 20:09:01.719706 | TASK [Calculate external_bridge_mtu]
2026-08-26 20:09:01.775170 | controller | ok
2026-08-26 20:09:01.783209 | 
2026-08-26 20:09:01.783303 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-08-26 20:09:01.808324 | controller | skipping: Conditional result was False
2026-08-26 20:09:01.819050 | 
2026-08-26 20:09:01.819276 | TASK [configure-swap : Get ephemeral0 device node]
2026-08-26 20:09:02.365106 | controller | ok: Runtime: 0:00:00.010079
2026-08-26 20:09:02.371078 | 
2026-08-26 20:09:02.371145 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-08-26 20:09:02.396368 | controller | skipping: Conditional result was False
2026-08-26 20:09:02.406971 | 
2026-08-26 20:09:02.407064 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-08-26 20:09:02.441907 | controller | skipping: Conditional result was False
2026-08-26 20:09:02.602479 | 
2026-08-26 20:09:02.602648 | TASK [configure-swap : Setup swap file on root device]
2026-08-26 20:09:02.669916 | controller | ok
2026-08-26 20:09:02.687765 | controller | included: /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-08-26 20:09:02.697118 | 
2026-08-26 20:09:02.697208 | TASK [configure-swap : Calculate required swap]
2026-08-26 20:09:02.836423 | controller | ok
2026-08-26 20:09:02.896794 | 
2026-08-26 20:09:02.896924 | TASK [configure-swap : Get root filesystem]
2026-08-26 20:09:03.154975 | controller | ext4
2026-08-26 20:09:03.441322 | controller | ok: Runtime: 0:00:00.012661
2026-08-26 20:09:03.446830 | 
2026-08-26 20:09:03.446890 | TASK [configure-swap : Save root filesystem]
2026-08-26 20:09:03.472114 | controller | ok
2026-08-26 20:09:03.480457 | 
2026-08-26 20:09:03.480549 | TASK [configure-swap : Debug the root_filesystem variable]
2026-08-26 20:09:03.512873 | controller | ok:
2026-08-26 20:09:03.513043 | controller | {
2026-08-26 20:09:03.513080 | controller |   "root_filesystem": "ext4"
2026-08-26 20:09:03.513108 | controller | }
2026-08-26 20:09:03.520015 | 
2026-08-26 20:09:03.520103 | TASK [configure-swap : Create swap backing file]
2026-08-26 20:09:12.918223 | controller | 8192+0 records in
2026-08-26 20:09:12.918428 | controller | 8192+0 records out
2026-08-26 20:09:12.918456 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 9.10356 s, 944 MB/s
2026-08-26 20:09:13.063033 | controller | ok: Runtime: 0:00:09.113295
2026-08-26 20:09:13.071593 | 
2026-08-26 20:09:13.071700 | TASK [configure-swap : Ensure swapfile perms]
2026-08-26 20:09:13.330523 | controller | changed
2026-08-26 20:09:13.365674 | 
2026-08-26 20:09:13.365790 | TASK [configure-swap : Make swapfile]
2026-08-26 20:09:48.370870 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2026-08-26 20:09:48.372062 | controller | no label, UUID=1ff631c7-5ae9-4564-89e9-8af23019a9db
2026-08-26 20:09:48.440280 | controller | ok: Runtime: 0:00:34.746240
2026-08-26 20:09:48.446005 | 
2026-08-26 20:09:48.446100 | TASK [configure-swap : Write swap to fstab]
2026-08-26 20:09:48.898513 | controller | changed
2026-08-26 20:09:48.905933 | 
2026-08-26 20:09:48.906004 | TASK [configure-swap : Add all swap]
2026-08-26 20:09:49.445302 | controller | ok: Runtime: 0:00:00.050880
2026-08-26 20:09:49.451360 | 
2026-08-26 20:09:49.451434 | TASK [configure-swap : Debug the swap_required variable]
2026-08-26 20:09:49.487356 | controller | ok:
2026-08-26 20:09:49.487571 | controller | {
2026-08-26 20:09:49.487613 | controller |   "swap_required": "8192"
2026-08-26 20:09:49.487642 | controller | }
2026-08-26 20:09:49.495445 | 
2026-08-26 20:09:49.495512 | TASK [configure-swap : Set swappiness]
2026-08-26 20:09:49.924627 | controller | changed
2026-08-26 20:09:49.932914 | 
2026-08-26 20:09:49.933037 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-08-26 20:09:49.978502 | controller | ok:
2026-08-26 20:09:49.978655 | controller | {
2026-08-26 20:09:49.978682 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-08-26 20:09:49.978708 | controller | }
2026-08-26 20:09:49.989951 | 
2026-08-26 20:09:49.990017 | TASK [setup-stack-user : Create stack group]
2026-08-26 20:09:50.643654 | controller | changed
2026-08-26 20:09:50.650307 | 
2026-08-26 20:09:50.650461 | TASK [setup-stack-user : Create the stack user home folder]
2026-08-26 20:09:50.921488 | controller | changed
2026-08-26 20:09:50.927221 | 
2026-08-26 20:09:50.927286 | TASK [setup-stack-user : Create stack user]
2026-08-26 20:09:51.545897 | controller | changed
2026-08-26 20:09:51.552682 | 
2026-08-26 20:09:51.552747 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-08-26 20:09:51.820737 | controller | changed
2026-08-26 20:09:51.831376 | 
2026-08-26 20:09:51.831455 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-08-26 20:09:53.007963 | controller | changed
2026-08-26 20:09:53.015200 | 
2026-08-26 20:09:53.015267 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-08-26 20:09:53.336380 | controller | changed
2026-08-26 20:09:53.346299 | 
2026-08-26 20:09:53.346362 | TASK [setup-tempest-user : Create tempest group]
2026-08-26 20:09:53.665786 | controller | changed
2026-08-26 20:09:53.674185 | 
2026-08-26 20:09:53.674333 | TASK [setup-tempest-user : Create tempest user]
2026-08-26 20:09:54.080216 | controller | changed
2026-08-26 20:09:54.086854 | 
2026-08-26 20:09:54.086918 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-08-26 20:09:54.969925 | controller | changed
2026-08-26 20:09:54.983103 | 
2026-08-26 20:09:54.983204 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-08-26 20:09:55.363877 | controller | ok: Not all paths examined, check warnings for details
2026-08-26 20:09:55.382969 | 
2026-08-26 20:09:55.383228 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-08-26 20:09:56.789847 | controller | ok: Item: Runtime: 0:00:01.091585
2026-08-26 20:09:57.485039 | controller | ok: Item: Runtime: 0:00:00.453610
2026-08-26 20:09:58.318174 | controller | ok: Item: Runtime: 0:00:00.576077
2026-08-26 20:09:58.928256 | controller | ok: Item: Runtime: 0:00:00.364079
2026-08-26 20:09:59.346885 | controller | ok: Item: Runtime: 0:00:00.162449
2026-08-26 20:09:59.644290 | controller | ok: Item: Runtime: 0:00:00.065269
2026-08-26 20:10:01.238464 | controller | ok: Item: Runtime: 0:00:01.348774
2026-08-26 20:10:04.610584 | controller | ok: Item: Runtime: 0:00:03.142846
2026-08-26 20:10:05.132253 | controller | ok: Item: Runtime: 0:00:00.263613
2026-08-26 20:10:05.659795 | controller | ok: Item: Runtime: 0:00:00.294934
2026-08-26 20:10:06.160263 | controller | ok: Item: Runtime: 0:00:00.284735
2026-08-26 20:10:06.681915 | controller | ok: Item: Runtime: 0:00:00.245849
2026-08-26 20:10:07.522877 | controller | ok: Item: Runtime: 0:00:00.596759
2026-08-26 20:10:08.321102 | controller | ok: Item: Runtime: 0:00:00.553541
2026-08-26 20:10:08.963169 | controller | ok: Item: Runtime: 0:00:00.396787
2026-08-26 20:10:09.429281 | controller | ok: Item: Runtime: 0:00:00.197794
2026-08-26 20:10:09.474742 | 
2026-08-26 20:10:09.474889 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-08-26 20:10:09.727266 | controller | ok: All paths examined
2026-08-26 20:10:09.735252 | 
2026-08-26 20:10:09.735331 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-08-26 20:10:10.002503 | controller | ok: All paths examined
2026-08-26 20:10:10.010687 | 
2026-08-26 20:10:10.010757 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-08-26 20:10:10.496187 | controller | ok: Item: Runtime: 0:00:00.206749
2026-08-26 20:10:10.496684 | controller | changed: All items complete
2026-08-26 20:10:10.496723 | 
2026-08-26 20:10:10.994999 | controller | ok: Item: Runtime: 0:00:00.275071
2026-08-26 20:10:11.046403 | 
2026-08-26 20:10:11.046780 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-08-26 20:10:11.146464 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.148556 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.151626 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.155158 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.158509 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.162110 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.165516 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.169030 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.172667 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.176289 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.179740 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.183214 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.186238 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.190658 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.193124 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.196532 | controller | skipping: Conditional result was False
2026-08-26 20:10:11.282083 | 
2026-08-26 20:10:11.282218 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-08-26 20:10:14.742335 | controller | changed
2026-08-26 20:10:14.757119 | 
2026-08-26 20:10:14.757202 | TASK [setup-devstack-log-dir : Create logs directory]
2026-08-26 20:10:15.019536 | controller | changed
2026-08-26 20:10:15.034674 | 
2026-08-26 20:10:15.034767 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-08-26 20:10:15.328846 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-08-26 20:10:15.584408 | controller | ERROR
2026-08-26 20:10:15.584659 | controller | {
2026-08-26 20:10:15.584689 | controller |   "delta": "0:00:00.012211",
2026-08-26 20:10:15.584711 | controller |   "end": "2026-08-26 20:10:15.329443",
2026-08-26 20:10:15.584730 | controller |   "msg": "non-zero return code",
2026-08-26 20:10:15.584749 | controller |   "rc": 1,
2026-08-26 20:10:15.584766 | controller |   "start": "2026-08-26 20:10:15.317232"
2026-08-26 20:10:15.584784 | controller | }
2026-08-26 20:10:15.584808 | controller | ERROR: Ignoring Errors
2026-08-26 20:10:15.591757 | 
2026-08-26 20:10:15.591845 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-08-26 20:10:15.854129 | controller | ok
2026-08-26 20:10:15.865291 | 
2026-08-26 20:10:16.170297 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-08-26 20:10:16.456796 | controller | /usr/bin/journalctl
2026-08-26 20:10:16.743362 | controller | ok: Runtime: 0:00:00.007447
2026-08-26 20:10:16.751317 | 
2026-08-26 20:10:16.751382 | TASK [start-fresh-logging : Get current date]
2026-08-26 20:10:17.020003 | controller | 2026-08-26 20:10:17
2026-08-26 20:10:17.290661 | controller | ok: Runtime: 0:00:00.009250
2026-08-26 20:10:17.296396 | 
2026-08-26 20:10:17.296463 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-08-26 20:10:17.925602 | controller | changed
2026-08-26 20:10:17.936635 | 
2026-08-26 20:10:17.936705 | TASK [start-fresh-logging : Stop rsyslog]
2026-08-26 20:10:17.961444 | controller | skipping: Conditional result was False
2026-08-26 20:10:17.972412 | 
2026-08-26 20:10:17.972548 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-08-26 20:10:18.512599 | controller | skipping: Conditional result was False
2026-08-26 20:10:18.521387 | 
2026-08-26 20:10:18.521471 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-08-26 20:10:19.060132 | controller | skipping: Conditional result was False
2026-08-26 20:10:19.070702 | 
2026-08-26 20:10:19.070801 | TASK [start-fresh-logging : Recreate syslog file]
2026-08-26 20:10:19.087650 | controller | skipping: Conditional result was False
2026-08-26 20:10:19.095303 | 
2026-08-26 20:10:19.095400 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-08-26 20:10:19.626377 | controller | skipping: Conditional result was False
2026-08-26 20:10:19.639200 | 
2026-08-26 20:10:19.639270 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-08-26 20:10:20.223143 | controller | skipping: Conditional result was False
2026-08-26 20:10:20.233585 | 
2026-08-26 20:10:20.233682 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-08-26 20:10:20.259679 | controller | skipping: Conditional result was False
2026-08-26 20:10:20.382324 | 
2026-08-26 20:10:20.382399 | TASK [start-fresh-logging : Recreate kern.log file]
2026-08-26 20:10:20.408737 | controller | skipping: Conditional result was False
2026-08-26 20:10:20.419886 | 
2026-08-26 20:10:20.419975 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-08-26 20:10:20.954250 | controller | skipping: Conditional result was False
2026-08-26 20:10:20.964555 | 
2026-08-26 20:10:20.964650 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-08-26 20:10:21.498441 | controller | skipping: Conditional result was False
2026-08-26 20:10:21.511295 | 
2026-08-26 20:10:21.511392 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-08-26 20:10:21.537582 | controller | skipping: Conditional result was False
2026-08-26 20:10:21.548361 | 
2026-08-26 20:10:21.548453 | TASK [start-fresh-logging : Start rsyslog]
2026-08-26 20:10:21.582060 | controller | skipping: Conditional result was False
2026-08-26 20:10:21.600724 | 
2026-08-26 20:10:21.600856 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-08-26 20:10:22.154804 | controller | ok
2026-08-26 20:10:22.197988 | 
2026-08-26 20:10:22.198038 | PLAY RECAP
2026-08-26 20:10:22.198084 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-08-26 20:10:22.198106 | 
2026-08-26 20:10:22.472810 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-08-26 20:10:22.483873 | PRE-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-08-26 20:10:25.157498 | 
2026-08-26 20:10:25.157605 | PLAY [all]
2026-08-26 20:10:25.169402 | 
2026-08-26 20:10:25.169477 | TASK [Install curl]
2026-08-26 20:10:39.118223 | controller | ok
2026-08-26 20:10:39.125531 | 
2026-08-26 20:10:39.125610 | TASK [ensure-rust : Use rustup]
2026-08-26 20:10:39.159348 | controller | ok
2026-08-26 20:10:39.169887 | controller | included: /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/ensure-rust/tasks/rustup.yaml
2026-08-26 20:10:39.175286 | 
2026-08-26 20:10:39.175349 | TASK [ensure-rust : Install Rust]
2026-08-26 20:10:52.470431 | controller | curl: (6) Could not resolve host: sh.rustup.rs
2026-08-26 20:10:52.722712 | controller | ERROR
2026-08-26 20:10:52.723124 | controller | {
2026-08-26 20:10:52.723170 | controller |   "delta": "0:00:12.940505",
2026-08-26 20:10:52.723202 | controller |   "end": "2026-08-26 20:10:52.478502",
2026-08-26 20:10:52.723231 | controller |   "msg": "non-zero return code",
2026-08-26 20:10:52.723259 | controller |   "rc": 6,
2026-08-26 20:10:52.723294 | controller |   "start": "2026-08-26 20:10:39.537997"
2026-08-26 20:10:52.723326 | controller | }
failure
2026-08-26 20:10:52.725294 | 
2026-08-26 20:10:52.725365 | PLAY RECAP
2026-08-26 20:10:52.725428 | controller | ok: 2 changed: 0 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-08-26 20:10:52.725460 | 
2026-08-26 20:10:52.842803 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-08-26 20:10:52.849592 | POST-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-08-26 20:10:54.867692 | 
2026-08-26 20:10:54.867822 | PLAY [all]
2026-08-26 20:10:54.878749 | 
2026-08-26 20:10:54.878824 | LOOP [Copy individual Hydrophone result files]
2026-08-26 20:10:55.300530 | controller | ERROR: Item: e2e.log
2026-08-26 20:10:55.300833 | controller | {
2026-08-26 20:10:55.300872 | controller |   "ansible_loop_var": "item",
2026-08-26 20:10:55.300902 | controller |   "item": "e2e.log",
2026-08-26 20:10:55.300978 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/e2e.log not found"
2026-08-26 20:10:55.301006 | controller | }
2026-08-26 20:10:55.613094 | controller | ERROR: Item: junit_01.xml
2026-08-26 20:10:55.613341 | controller | {
2026-08-26 20:10:55.613422 | controller |   "ansible_loop_var": "item",
2026-08-26 20:10:55.613475 | controller |   "item": "junit_01.xml",
2026-08-26 20:10:55.613522 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/junit_01.xml not found"
2026-08-26 20:10:55.613568 | controller | }
2026-08-26 20:10:55.631522 | controller | ERROR: Ignoring Errors
2026-08-26 20:10:55.637981 | 
2026-08-26 20:10:55.638055 | TASK [Copy Hydrophone results tarball to output folder]
2026-08-26 20:10:55.999872 | controller | ERROR
2026-08-26 20:10:56.000113 | controller | {
2026-08-26 20:10:56.000143 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results.tar.gz not found"
2026-08-26 20:10:56.000165 | controller | }
2026-08-26 20:10:56.000190 | controller | ERROR: Ignoring Errors
2026-08-26 20:10:56.040014 | 
2026-08-26 20:10:56.040117 | TASK [Return built artifacts to Zuul]
2026-08-26 20:10:56.136222 | controller | ok
2026-08-26 20:10:56.143491 | 
2026-08-26 20:10:56.143551 | TASK [Get the Docker volume ID]
2026-08-26 20:10:56.687467 | controller | ERROR
2026-08-26 20:10:56.687767 | controller | {
2026-08-26 20:10:56.687808 | controller |   "msg": "[Errno 2] No such file or directory: b'docker'",
2026-08-26 20:10:56.687837 | controller |   "rc": 2
2026-08-26 20:10:56.687864 | controller | }
2026-08-26 20:10:56.687902 | controller | ERROR: Ignoring Errors
2026-08-26 20:10:56.695589 | 
2026-08-26 20:10:56.695657 | TASK [Copy all of the pod logs]
2026-08-26 20:10:56.721277 | controller | ERROR
2026-08-26 20:10:56.721455 | controller | {
2026-08-26 20:10:56.721483 | controller |   "msg": "The task includes an option with an undefined variable. The error was: list object has no element 0. list object has no element 0\n\nThe error appears to be in '/var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/untrusted/project_5/github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml': line 42, column 11, but may\nbe elsewhere in the file depending on the exact syntax problem.\n\nThe offending line appears to be:\n\n\n        - name: Copy all of the pod logs\n          ^ here\n"
2026-08-26 20:10:56.721519 | controller | }
2026-08-26 20:10:56.721545 | controller | ERROR: Ignoring Errors
2026-08-26 20:10:56.722498 | 
2026-08-26 20:10:56.722543 | PLAY RECAP
2026-08-26 20:10:56.722586 | controller | ok: 5 changed: 0 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 4
2026-08-26 20:10:56.722608 | 
2026-08-26 20:10:56.865536 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-08-26 20:10:56.876243 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-08-26 20:10:57.848400 | 
2026-08-26 20:10:57.848551 | PLAY [all]
2026-08-26 20:10:57.867666 | 
2026-08-26 20:10:57.867763 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-08-26 20:10:58.323307 | controller | changed
2026-08-26 20:10:58.453651 | 
2026-08-26 20:10:58.453807 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-08-26 20:10:59.497750 | controller | ok: Runtime: 0:00:00.504232
2026-08-26 20:10:59.504215 | 
2026-08-26 20:10:59.504286 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-08-26 20:11:00.050776 | controller | ok: Runtime: 0:00:00.020594
2026-08-26 20:11:00.058872 | 
2026-08-26 20:11:00.058965 | TASK [export-devstack-journal : Export journal]
2026-08-26 20:11:00.668864 | controller | ok: Runtime: 0:00:00.025379
2026-08-26 20:11:00.679277 | 
2026-08-26 20:11:00.679350 | TASK [export-devstack-journal : Save journal README]
2026-08-26 20:11:01.604693 | controller | changed
2026-08-26 20:11:01.619786 | 
2026-08-26 20:11:01.619906 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-08-26 20:11:01.895169 | controller | changed
2026-08-26 20:11:01.902530 | 
2026-08-26 20:11:01.902614 | TASK [apache-logs-conf : Find logs]
2026-08-26 20:11:02.239018 | controller | Output suppressed because no_log was given
2026-08-26 20:11:02.246623 | 
2026-08-26 20:11:02.246781 | LOOP [apache-logs-conf : Dereference files]
2026-08-26 20:11:02.289718 | 
2026-08-26 20:11:02.290087 | LOOP [apache-logs-conf : Create hard links]
2026-08-26 20:11:02.326132 | 
2026-08-26 20:11:02.326279 | TASK [apache-logs-conf : Find logs]
2026-08-26 20:11:02.360868 | 
2026-08-26 20:11:02.361130 | LOOP [apache-logs-conf : Dereference files]
2026-08-26 20:11:02.398971 | 
2026-08-26 20:11:02.399290 | LOOP [apache-logs-conf : Create hard links]
2026-08-26 20:11:02.452177 | 
2026-08-26 20:11:02.663758 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-08-26 20:11:02.929238 | controller | changed
2026-08-26 20:11:02.937536 | 
2026-08-26 20:11:02.937607 | TASK [apache-logs-conf : Define config paths]
2026-08-26 20:11:02.980500 | controller | ok
2026-08-26 20:11:02.988143 | 
2026-08-26 20:11:02.988212 | TASK [apache-logs-conf : Discover configurations]
2026-08-26 20:11:03.228680 | controller | Output suppressed because no_log was given
2026-08-26 20:11:03.237179 | 
2026-08-26 20:11:03.237247 | LOOP [apache-logs-conf : Dereference configurations]
2026-08-26 20:11:03.272545 | 
2026-08-26 20:11:03.272656 | LOOP [apache-logs-conf : Link configurations]
2026-08-26 20:11:03.324021 | 
2026-08-26 20:11:03.324252 | TASK [capture-performance-data : Generate statistics]
2026-08-26 20:11:04.051087 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-08-26 20:11:04.071279 | controller | Using python 3.12 to install setuptools
2026-08-26 20:11:04.131141 | controller | /usr/bin/python3.12: No module named pip
2026-08-26 20:11:04.146164 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-08-26 20:11:04.368804 | controller | ERROR
2026-08-26 20:11:04.369132 | controller | {
2026-08-26 20:11:04.369175 | controller |   "delta": "0:00:00.541967",
2026-08-26 20:11:04.369198 | controller |   "end": "2026-08-26 20:11:04.148507",
2026-08-26 20:11:04.369217 | controller |   "msg": "non-zero return code",
2026-08-26 20:11:04.369243 | controller |   "rc": 127,
2026-08-26 20:11:04.369271 | controller |   "start": "2026-08-26 20:11:03.606540"
2026-08-26 20:11:04.369290 | controller | }
2026-08-26 20:11:04.369352 | controller | ERROR: Ignoring Errors
2026-08-26 20:11:04.383352 | 
2026-08-26 20:11:04.383449 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-08-26 20:11:04.643028 | controller | changed
2026-08-26 20:11:04.649726 | 
2026-08-26 20:11:04.649792 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-08-26 20:11:08.766435 | controller | Output suppressed because no_log was given
2026-08-26 20:11:08.784965 | 
2026-08-26 20:11:08.785076 | LOOP [devstack-project-conf : Copy configuration files]
2026-08-26 20:11:08.913031 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.913310 | 
2026-08-26 20:11:08.914734 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.917875 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.920877 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.923891 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.926739 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.929784 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.932867 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.935935 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.939218 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.943186 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.946416 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.949204 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.952586 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.955708 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.958532 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.961187 | controller | skipping: Conditional result was False
2026-08-26 20:11:08.963651 | controller | skipping: Conditional result was False
2026-08-26 20:11:09.021216 | 
2026-08-26 20:11:09.021331 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-08-26 20:11:09.299327 | controller | ok
2026-08-26 20:11:09.306761 | 
2026-08-26 20:11:09.306822 | TASK [devstack-project-conf : Copy configuration files]
2026-08-26 20:11:09.867113 | controller | skipping: Conditional result was False
2026-08-26 20:11:09.900999 | 
2026-08-26 20:11:09.901181 | TASK [capture-system-logs : Stage various logs and reports]
2026-08-26 20:11:10.338163 | controller | /usr/bin/python3: No module named pip
2026-08-26 20:11:11.588488 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-08-26 20:11:11.959327 | controller | ok: Runtime: 0:00:01.383096
2026-08-26 20:11:11.972814 | 
2026-08-26 20:11:11.972887 | LOOP [stage-output : Register sources]
2026-08-26 20:11:22.637440 | controller | Output suppressed because no_log was given
2026-08-26 20:11:22.652721 | 
2026-08-26 20:11:22.652843 | TASK [stage-output : Check sudo]
2026-08-26 20:11:23.197045 | controller | ok: Runtime: 0:00:00.027560
2026-08-26 20:11:23.327194 | 
2026-08-26 20:11:23.327332 | LOOP [stage-output : Set source and destination for files and folders]
2026-08-26 20:11:23.438653 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.439043 | 
2026-08-26 20:11:23.440313 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.443072 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.446070 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.487149 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.487733 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.489628 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.492690 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.495444 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.497807 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.505298 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.509277 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.512700 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.515657 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.535043 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.535516 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.536606 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.539394 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.542204 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.545473 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.548920 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.552219 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.555845 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.582686 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.583194 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.678329 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.688881 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.703176 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.714050 | controller | Output suppressed because no_log was given
2026-08-26 20:11:23.735320 | 
2026-08-26 20:11:23.735447 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-08-26 20:11:23.808913 | controller | ok
2026-08-26 20:11:23.817082 | 
2026-08-26 20:11:23.973508 | LOOP [stage-output : Ensure target folders exist]
2026-08-26 20:11:24.239147 | controller | changed: "docs"
2026-08-26 20:11:24.463784 | controller | changed: "artifacts"
2026-08-26 20:11:24.702475 | controller | ok: "logs"
2026-08-26 20:11:24.717566 | 
2026-08-26 20:11:24.717730 | LOOP [stage-output : Copy files and folders to staging folder]
2026-08-26 20:11:25.003358 | controller | ok: Item: Runtime: 0:00:00.006564
2026-08-26 20:11:25.105203 | controller | changed: All items complete
2026-08-26 20:11:25.105352 | 
2026-08-26 20:11:25.215340 | controller | ok: Item: Runtime: 0:00:00.006893
2026-08-26 20:11:25.446830 | controller | ok: Item: Runtime: 0:00:00.007889
2026-08-26 20:11:25.689058 | controller | ok: Item: Runtime: 0:00:00.008347
2026-08-26 20:11:25.943128 | controller | ok: Item: Runtime: 0:00:00.008358
2026-08-26 20:11:26.197805 | controller | ok: Item: Runtime: 0:00:00.008391
2026-08-26 20:11:26.426615 | controller | ok: Item: Runtime: 0:00:00.008840
2026-08-26 20:11:26.715356 | controller | ok: Item: Runtime: 0:00:00.008316
2026-08-26 20:11:27.023868 | controller | ok: Item: Runtime: 0:00:00.008195
2026-08-26 20:11:27.211654 | controller | ok: Item: Runtime: 0:00:00.008513
2026-08-26 20:11:27.454417 | controller | ok: Item: Runtime: 0:00:00.006624
2026-08-26 20:11:27.689203 | controller | ok: Item: Runtime: 0:00:00.008456
2026-08-26 20:11:27.930249 | controller | ok: Item: Runtime: 0:00:00.008832
2026-08-26 20:11:28.177764 | controller | ok: Item: Runtime: 0:00:00.007325
2026-08-26 20:11:28.419790 | controller | ok: Item: Runtime: 0:00:00.007774
2026-08-26 20:11:28.655466 | controller | ok: Item: Runtime: 0:00:00.007465
2026-08-26 20:11:28.746844 | 
2026-08-26 20:11:28.746989 | TASK [stage-output : Make all log files readable]
2026-08-26 20:11:29.013039 | controller | changed
2026-08-26 20:11:29.019232 | 
2026-08-26 20:11:29.019297 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-08-26 20:11:29.385971 | controller | changed: Renamed files for staging.
2026-08-26 20:11:29.392868 | 
2026-08-26 20:11:29.392947 | TASK [stage-output : Discover log files for compression]
2026-08-26 20:11:29.407047 | controller | skipping: Conditional result was False
2026-08-26 20:11:29.425999 | 
2026-08-26 20:11:29.426122 | LOOP [stage-output : Archive everything from logs]
2026-08-26 20:11:29.467190 | 
2026-08-26 20:11:30.543039 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-08-26 20:11:31.289125 | controller | changed:
2026-08-26 20:11:31.289296 | controller | created directory /var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/work/logs/controller
2026-08-26 20:11:31.289325 | controller | cd+++++++++ logs/
2026-08-26 20:11:31.289347 | controller | >f+++++++++ logs/deprecations_log.txt
2026-08-26 20:11:31.289368 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-08-26 20:11:31.289389 | controller | >f+++++++++ logs/devstack.journal.gz
2026-08-26 20:11:31.289408 | controller | >f+++++++++ logs/df.txt
2026-08-26 20:11:31.289428 | controller | >f+++++++++ logs/dpkg-l.txt
2026-08-26 20:11:31.289447 | controller | >f+++++++++ logs/iptables.txt
2026-08-26 20:11:31.289465 | controller | >f+++++++++ logs/listen53.txt
2026-08-26 20:11:31.289484 | controller | >f+++++++++ logs/local_conf.txt
2026-08-26 20:11:31.289502 | controller | >f+++++++++ logs/mount.txt
2026-08-26 20:11:31.289520 | controller | >f+++++++++ logs/performance.json
2026-08-26 20:11:31.289539 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-08-26 20:11:31.289558 | controller | >f+++++++++ logs/resolv_conf.txt
2026-08-26 20:11:31.289576 | controller | >f+++++++++ logs/services.txt
2026-08-26 20:11:31.289599 | controller | >f+++++++++ logs/sudoers
2026-08-26 20:11:31.289619 | controller | >f+++++++++ logs/syslog.txt
2026-08-26 20:11:31.289637 | controller | cd+++++++++ logs/apache/
2026-08-26 20:11:31.289656 | controller | cd+++++++++ logs/apache_config/
2026-08-26 20:11:31.289675 | controller | cd+++++++++ logs/etc/
2026-08-26 20:11:31.289694 | controller | cd+++++++++ logs/sudoers.d/
2026-08-26 20:11:31.289712 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-08-26 20:11:31.289731 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-08-26 20:11:31.289750 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-08-26 20:11:31.289769 | controller | >f+++++++++ logs/sudoers.d/README
2026-08-26 20:11:31.289788 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-08-26 20:11:31.302623 | 
2026-08-26 20:11:31.302747 | TASK [Check if a tempest log exits]
2026-08-26 20:11:31.579396 | controller | ok
2026-08-26 20:11:31.585549 | 
2026-08-26 20:11:31.585615 | TASK [Link post-devstack tempest.log]
2026-08-26 20:11:31.603660 | controller | skipping: Conditional result was False
2026-08-26 20:11:31.613630 | 
2026-08-26 20:11:31.613730 | TASK [Capture most recent qemu crash dump, if any]
2026-08-26 20:11:31.923387 | controller | /bin/bash: line 1: coredumpctl: command not found
2026-08-26 20:11:32.326546 | controller | ERROR
2026-08-26 20:11:32.326779 | controller | {
2026-08-26 20:11:32.326820 | controller |   "delta": "0:00:00.008015",
2026-08-26 20:11:32.326849 | controller |   "end": "2026-08-26 20:11:31.924068",
2026-08-26 20:11:32.326876 | controller |   "msg": "non-zero return code",
2026-08-26 20:11:32.326902 | controller |   "rc": 127,
2026-08-26 20:11:32.326929 | controller |   "start": "2026-08-26 20:11:31.916053"
2026-08-26 20:11:32.326954 | controller | }
2026-08-26 20:11:32.326988 | controller | ERROR: Ignoring Errors
2026-08-26 20:11:32.334666 | 
2026-08-26 20:11:32.334775 | TASK [Collect Guru Meditation Reports from OpenStack services]
2026-08-26 20:11:32.877199 | controller | ERROR
2026-08-26 20:11:32.877784 | controller | {
2026-08-26 20:11:32.877829 | controller |   "delta": "0:00:00.105586",
2026-08-26 20:11:32.877860 | controller |   "end": "2026-08-26 20:11:32.723610",
2026-08-26 20:11:32.877886 | controller |   "msg": "non-zero return code",
2026-08-26 20:11:32.877911 | controller |   "rc": -12,
2026-08-26 20:11:32.877937 | controller |   "start": "2026-08-26 20:11:32.618024"
2026-08-26 20:11:32.877975 | controller | }
2026-08-26 20:11:32.878011 | controller | ERROR: Ignoring Errors
2026-08-26 20:11:32.879960 | 
2026-08-26 20:11:32.880026 | PLAY RECAP
2026-08-26 20:11:32.880093 | controller | ok: 27 changed: 18 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 3
2026-08-26 20:11:32.880123 | 
2026-08-26 20:11:33.043919 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-08-26 20:11:33.072463 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-08-26 20:11:33.806977 | 
2026-08-26 20:11:33.807132 | PLAY [all]
2026-08-26 20:11:33.823465 | 
2026-08-26 20:11:33.823566 | TASK [fetch-output : Set log path for multiple nodes]
2026-08-26 20:11:33.881705 | controller | skipping: Conditional result was False
2026-08-26 20:11:33.895879 | 
2026-08-26 20:11:34.022419 | TASK [fetch-output : Set log path for single node]
2026-08-26 20:11:34.083849 | controller | ok
2026-08-26 20:11:34.089793 | 
2026-08-26 20:11:34.089872 | LOOP [fetch-output : Ensure local output dirs]
2026-08-26 20:11:34.605312 | controller -> localhost | ok: "/var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/work/logs"
2026-08-26 20:11:34.879017 | controller -> localhost | changed: "/var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/work/artifacts"
2026-08-26 20:11:35.149323 | controller -> localhost | changed: "/var/lib/zuul/builds/3237ca2b45394bc2ae964af18fe80059/work/docs"
2026-08-26 20:11:35.163404 | 
2026-08-26 20:11:35.163593 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-08-26 20:11:36.029278 | controller | changed: .d..t...... ./
2026-08-26 20:11:36.029473 | controller | changed: All items complete
2026-08-26 20:11:36.029509 | 
2026-08-26 20:11:36.503640 | controller | changed: .d..t...... ./
2026-08-26 20:11:37.066789 | controller | changed: .d..t...... ./
2026-08-26 20:11:37.096540 | 
2026-08-26 20:11:37.096715 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-08-26 20:11:37.576896 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.037880
2026-08-26 20:11:37.933956 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009944
2026-08-26 20:11:37.955483 | 
2026-08-26 20:11:37.955629 | PLAY [all]
2026-08-26 20:11:37.962458 | 
2026-08-26 20:11:37.962530 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-08-26 20:11:38.492543 | controller | changed
2026-08-26 20:11:38.502332 | 
2026-08-26 20:11:38.502385 | PLAY RECAP
2026-08-26 20:11:38.502436 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-08-26 20:11:38.502459 | 
2026-08-26 20:11:38.659874 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-08-26 20:11:38.728212 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-08-26 20:11:39.426395 | 
2026-08-26 20:11:39.426554 | PLAY [localhost]
2026-08-26 20:11:39.437409 | 
2026-08-26 20:11:39.437482 | TASK [Generate Zuul manifest]
2026-08-26 20:11:39.459447 | localhost | ok
2026-08-26 20:11:39.530208 | 
2026-08-26 20:11:39.626279 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-08-26 20:11:40.199718 | localhost | changed
2026-08-26 20:11:40.250259 | 
2026-08-26 20:11:40.250921 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-08-26 20:11:40.295546 | localhost | ok
2026-08-26 20:11:40.304274 | 
2026-08-26 20:11:40.304345 | TASK [Upload logs]
2026-08-26 20:11:40.325489 | localhost | ok
2026-08-26 20:11:40.519676 | 
2026-08-26 20:11:40.519826 | TASK [Set zuul-log-path fact]
2026-08-26 20:11:40.542603 | localhost | ok
2026-08-26 20:11:40.566853 | 
2026-08-26 20:11:40.567004 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-08-26 20:11:40.596731 | localhost | ok
2026-08-26 20:11:40.605271 | 
2026-08-26 20:11:40.605361 | TASK [upload-logs : Create log directories]
2026-08-26 20:11:41.186156 | localhost | changed
2026-08-26 20:11:41.198711 | 
2026-08-26 20:11:41.199534 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-08-26 20:11:41.690562 | localhost -> localhost | ok: Runtime: 0:00:00.023885
2026-08-26 20:11:41.702535 | 
2026-08-26 20:11:41.702635 | TASK [upload-logs : Upload logs to log server]
2026-08-26 20:11:42.257835 | localhost | Output suppressed because no_log was given
2026-08-26 20:11:42.261813 | 
2026-08-26 20:11:42.261885 | LOOP [upload-logs : Compress console log and json output]
2026-08-26 20:11:42.309767 | localhost | skipping: Conditional result was False
2026-08-26 20:11:42.420352 | localhost | skipping: Conditional result was False
2026-08-26 20:11:42.430235 | 
2026-08-26 20:11:42.430376 | LOOP [upload-logs : Upload compressed console log and json output]
2026-08-26 20:11:42.479921 | localhost | skipping: Conditional result was False
2026-08-26 20:11:42.480444 | 
2026-08-26 20:11:42.484126 | localhost | skipping: Conditional result was False
2026-08-26 20:11:42.491465 | 
2026-08-26 20:11:42.491602 | LOOP [upload-logs : Upload console log and json output]