2026-08-26 20:13:33.811215 | Job console starting
2026-08-26 20:13:33.826611 | Updating git repos
2026-08-26 20:13:41.312703 | Cloning repos into workspace
2026-08-26 20:13:52.717995 | Restoring repo states
2026-08-26 20:13:54.526501 | Merging changes
2026-08-26 20:13:55.378821 | Checking out repos
2026-08-26 20:14:04.247613 | Preparing playbooks
2026-08-26 20:14:10.679610 | Running Ansible setup
2026-08-26 20:14:16.303324 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-08-26 20:14:16.996069 | 
2026-08-26 20:14:16.996206 | PLAY [localhost]
2026-08-26 20:14:17.009422 | 
2026-08-26 20:14:17.009671 | TASK [Gathering Facts]
2026-08-26 20:14:17.923394 | localhost | ok
2026-08-26 20:14:17.935988 | 
2026-08-26 20:14:17.936101 | TASK [Setup log path fact]
2026-08-26 20:14:17.965958 | localhost | ok
2026-08-26 20:14:17.978630 | 
2026-08-26 20:14:17.978703 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-08-26 20:14:18.019064 | localhost | ok
2026-08-26 20:14:18.025817 | 
2026-08-26 20:14:18.025894 | TASK [emit-job-header : Print job information]
2026-08-26 20:14:18.067737 | # Job Information
2026-08-26 20:14:18.067932 | Ansible Version: 2.16.18
2026-08-26 20:14:18.067978 | Job: magnum-cluster-api-hydrophone-v1.34.8-calico
2026-08-26 20:14:18.068011 | Pipeline: check
2026-08-26 20:14:18.068042 | Executor: 2d72f0692154
2026-08-26 20:14:18.068071 | Triggered by: https://github.com/vexxhost/magnum-cluster-api/pull/1124
2026-08-26 20:14:18.068106 | Event ID: 4888c370-a189-11f1-883d-c8d2ca039ac0
2026-08-26 20:14:18.072280 | 
2026-08-26 20:14:18.072378 | LOOP [emit-job-header : Print node information]
2026-08-26 20:14:18.192467 | localhost | ok:
2026-08-26 20:14:18.192674 | localhost | # Node Information
2026-08-26 20:14:18.192764 | localhost | Inventory Hostname: controller
2026-08-26 20:14:18.192790 | localhost | Hostname: np0000191223
2026-08-26 20:14:18.192811 | localhost | Username: zuul
2026-08-26 20:14:18.192856 | localhost | Distro: Ubuntu 24.04
2026-08-26 20:14:18.192878 | localhost | Provider: yul1
2026-08-26 20:14:18.192897 | localhost | Region: ca-ymq-1
2026-08-26 20:14:18.192916 | localhost | Label: ubuntu-noble-16
2026-08-26 20:14:18.192934 | localhost | Product Name: OpenStack Nova
2026-08-26 20:14:18.193930 | localhost | Interface IP: 162.253.55.214
2026-08-26 20:14:18.211618 | 
2026-08-26 20:14:18.211788 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-08-26 20:14:18.669568 | localhost -> localhost | changed
2026-08-26 20:14:18.676567 | 
2026-08-26 20:14:18.676648 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-08-26 20:14:19.617426 | localhost -> localhost | changed
2026-08-26 20:14:19.627607 | 
2026-08-26 20:14:19.627670 | PLAY [all]
2026-08-26 20:14:19.637599 | 
2026-08-26 20:14:19.637676 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-08-26 20:14:19.891200 | controller -> localhost | ok
2026-08-26 20:14:19.897980 | 
2026-08-26 20:14:19.898048 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-08-26 20:14:19.944069 | controller | ok
2026-08-26 20:14:19.960326 | controller | included: /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-08-26 20:14:19.966500 | 
2026-08-26 20:14:19.966559 | TASK [add-build-sshkey : Create Temp SSH key]
2026-08-26 20:14:21.183621 | controller -> localhost | Generating public/private rsa key pair.
2026-08-26 20:14:21.183814 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/work/0d950d6bc28a486a9aa5abfe15be3baf_id_rsa
2026-08-26 20:14:21.183845 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/work/0d950d6bc28a486a9aa5abfe15be3baf_id_rsa.pub
2026-08-26 20:14:21.183868 | controller -> localhost | The key fingerprint is:
2026-08-26 20:14:21.183889 | controller -> localhost | SHA256:Sxw5BA2tPGzBVLDcSH98jgn4LaU6Nept6rm369YQ/v4 zuul-build-sshkey
2026-08-26 20:14:21.183923 | controller -> localhost | The key's randomart image is:
2026-08-26 20:14:21.183945 | controller -> localhost | +---[RSA 3072]----+
2026-08-26 20:14:21.183975 | controller -> localhost | |     o*Bo        |
2026-08-26 20:14:21.183997 | controller -> localhost | |     ooBoo       |
2026-08-26 20:14:21.184020 | controller -> localhost | |     o=oB + .    |
2026-08-26 20:14:21.184040 | controller -> localhost | |      *o.O =     |
2026-08-26 20:14:21.184060 | controller -> localhost | |     . oS.+ .    |
2026-08-26 20:14:21.184080 | controller -> localhost | |       =o+       |
2026-08-26 20:14:21.184099 | controller -> localhost | |      + .+       |
2026-08-26 20:14:21.184119 | controller -> localhost | |     . ++ o      |
2026-08-26 20:14:21.184142 | controller -> localhost | |     .*B=+..E    |
2026-08-26 20:14:21.184162 | controller -> localhost | +----[SHA256]-----+
2026-08-26 20:14:21.184211 | controller -> localhost | ok: Runtime: 0:00:00.700963
2026-08-26 20:14:21.190505 | 
2026-08-26 20:14:21.190570 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-08-26 20:14:21.223343 | controller | ok
2026-08-26 20:14:21.236475 | controller | included: /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-08-26 20:14:21.245310 | 
2026-08-26 20:14:21.245376 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-08-26 20:14:21.270600 | controller | skipping: Conditional result was False
2026-08-26 20:14:21.279979 | 
2026-08-26 20:14:21.280103 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-08-26 20:14:22.450590 | controller | changed
2026-08-26 20:14:22.456389 | 
2026-08-26 20:14:22.456454 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-08-26 20:14:22.706093 | controller | ok
2026-08-26 20:14:22.725330 | 
2026-08-26 20:14:22.725458 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-08-26 20:14:23.372465 | controller | changed
2026-08-26 20:14:23.378915 | 
2026-08-26 20:14:23.378982 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-08-26 20:14:24.124747 | controller | changed
2026-08-26 20:14:24.130048 | 
2026-08-26 20:14:24.130110 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-08-26 20:14:24.154888 | controller | skipping: Conditional result was False
2026-08-26 20:14:24.165688 | 
2026-08-26 20:14:24.165778 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-08-26 20:14:24.495500 | controller -> localhost | changed
2026-08-26 20:14:24.512664 | 
2026-08-26 20:14:24.512772 | TASK [add-build-sshkey : Add back temp key]
2026-08-26 20:14:24.854152 | controller -> localhost | Identity added: /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/work/0d950d6bc28a486a9aa5abfe15be3baf_id_rsa (zuul-build-sshkey)
2026-08-26 20:14:24.854492 | controller -> localhost | ok: Runtime: 0:00:00.013743
2026-08-26 20:14:24.860758 | 
2026-08-26 20:14:24.862537 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-08-26 20:14:25.191463 | controller | ok
2026-08-26 20:14:25.198985 | 
2026-08-26 20:14:25.199081 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-08-26 20:14:25.223332 | controller | skipping: Conditional result was False
2026-08-26 20:14:25.242800 | 
2026-08-26 20:14:25.242867 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-08-26 20:14:25.628786 | controller | ok
2026-08-26 20:14:25.636745 | 
2026-08-26 20:14:25.636812 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-08-26 20:14:57.536559 | controller | Output suppressed because no_log was given
2026-08-26 20:14:57.548821 | 
2026-08-26 20:14:57.548971 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-08-26 20:14:57.823709 | controller | ok: "logs"
2026-08-26 20:14:57.824013 | controller | ok: All items complete
2026-08-26 20:14:57.824040 | 
2026-08-26 20:14:58.030743 | controller | ok: "artifacts"
2026-08-26 20:14:58.269363 | controller | ok: "docs"
2026-08-26 20:14:58.285673 | 
2026-08-26 20:14:58.285777 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-08-26 20:14:58.561290 | controller | changed: "logs"
2026-08-26 20:14:58.799452 | controller | changed: "artifacts"
2026-08-26 20:14:59.082851 | controller | changed: "docs"
2026-08-26 20:14:59.098192 | 
2026-08-26 20:14:59.098918 | PLAY RECAP
2026-08-26 20:14:59.099065 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-08-26 20:14:59.099111 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-08-26 20:14:59.099151 | 
2026-08-26 20:14:59.258605 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-08-26 20:14:59.271579 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-08-26 20:14:59.921993 | 
2026-08-26 20:14:59.922122 | PLAY [all]
2026-08-26 20:14:59.939953 | 
2026-08-26 20:14:59.940041 | TASK [Fix the permissions of the zuul home directory]
2026-08-26 20:15:00.349796 | controller | changed
2026-08-26 20:15:00.358521 | 
2026-08-26 20:15:00.358743 | TASK [Gather minimum local MTU]
2026-08-26 20:15:00.436635 | controller | ok
2026-08-26 20:15:00.443173 | 
2026-08-26 20:15:00.443244 | TASK [Calculate external_bridge_mtu]
2026-08-26 20:15:00.513513 | controller | ok
2026-08-26 20:15:00.528434 | 
2026-08-26 20:15:00.528691 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-08-26 20:15:00.555949 | controller | skipping: Conditional result was False
2026-08-26 20:15:00.567418 | 
2026-08-26 20:15:00.567500 | TASK [configure-swap : Get ephemeral0 device node]
2026-08-26 20:15:01.129807 | controller | ok: Runtime: 0:00:00.010720
2026-08-26 20:15:01.143084 | 
2026-08-26 20:15:01.143167 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-08-26 20:15:01.178209 | controller | skipping: Conditional result was False
2026-08-26 20:15:01.192859 | 
2026-08-26 20:15:01.192940 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-08-26 20:15:01.228261 | controller | skipping: Conditional result was False
2026-08-26 20:15:01.239776 | 
2026-08-26 20:15:01.239871 | TASK [configure-swap : Setup swap file on root device]
2026-08-26 20:15:01.318324 | controller | ok
2026-08-26 20:15:01.333740 | controller | included: /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-08-26 20:15:01.342001 | 
2026-08-26 20:15:01.342072 | TASK [configure-swap : Calculate required swap]
2026-08-26 20:15:01.456236 | controller | ok
2026-08-26 20:15:01.507857 | 
2026-08-26 20:15:01.507995 | TASK [configure-swap : Get root filesystem]
2026-08-26 20:15:01.752807 | controller | ext4
2026-08-26 20:15:02.052093 | controller | ok: Runtime: 0:00:00.013535
2026-08-26 20:15:02.058398 | 
2026-08-26 20:15:02.058472 | TASK [configure-swap : Save root filesystem]
2026-08-26 20:15:02.100795 | controller | ok
2026-08-26 20:15:02.109412 | 
2026-08-26 20:15:02.109527 | TASK [configure-swap : Debug the root_filesystem variable]
2026-08-26 20:15:02.153252 | controller | ok:
2026-08-26 20:15:02.153509 | controller | {
2026-08-26 20:15:02.153543 | controller |   "root_filesystem": "ext4"
2026-08-26 20:15:02.153570 | controller | }
2026-08-26 20:15:02.162121 | 
2026-08-26 20:15:02.162288 | TASK [configure-swap : Create swap backing file]
2026-08-26 20:15:11.596722 | controller | 8192+0 records in
2026-08-26 20:15:11.596921 | controller | 8192+0 records out
2026-08-26 20:15:11.596947 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 9.06448 s, 948 MB/s
2026-08-26 20:15:11.718485 | controller | ok: Runtime: 0:00:09.074169
2026-08-26 20:15:11.726225 | 
2026-08-26 20:15:11.726497 | TASK [configure-swap : Ensure swapfile perms]
2026-08-26 20:15:12.001189 | controller | changed
2026-08-26 20:15:12.109955 | 
2026-08-26 20:15:12.110084 | TASK [configure-swap : Make swapfile]
2026-08-26 20:15:44.106043 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2026-08-26 20:15:44.106174 | controller | no label, UUID=358a6d74-91eb-4ac3-8cf0-911920a4de67
2026-08-26 20:15:44.184942 | controller | ok: Runtime: 0:00:31.697324
2026-08-26 20:15:44.190723 | 
2026-08-26 20:15:44.190791 | TASK [configure-swap : Write swap to fstab]
2026-08-26 20:15:44.624440 | controller | changed
2026-08-26 20:15:44.633780 | 
2026-08-26 20:15:44.633903 | TASK [configure-swap : Add all swap]
2026-08-26 20:15:45.172482 | controller | ok: Runtime: 0:00:00.017840
2026-08-26 20:15:45.178785 | 
2026-08-26 20:15:45.178853 | TASK [configure-swap : Debug the swap_required variable]
2026-08-26 20:15:45.213217 | controller | ok:
2026-08-26 20:15:45.213482 | controller | {
2026-08-26 20:15:45.213527 | controller |   "swap_required": "8192"
2026-08-26 20:15:45.213559 | controller | }
2026-08-26 20:15:45.224337 | 
2026-08-26 20:15:45.224565 | TASK [configure-swap : Set swappiness]
2026-08-26 20:15:45.686844 | controller | changed
2026-08-26 20:15:45.694168 | 
2026-08-26 20:15:45.694235 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-08-26 20:15:45.731235 | controller | ok:
2026-08-26 20:15:45.731377 | controller | {
2026-08-26 20:15:45.731414 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-08-26 20:15:45.731450 | controller | }
2026-08-26 20:15:45.744982 | 
2026-08-26 20:15:45.745046 | TASK [setup-stack-user : Create stack group]
2026-08-26 20:15:46.231469 | controller | changed
2026-08-26 20:15:46.237239 | 
2026-08-26 20:15:46.237309 | TASK [setup-stack-user : Create the stack user home folder]
2026-08-26 20:15:46.515067 | controller | changed
2026-08-26 20:15:46.557387 | 
2026-08-26 20:15:46.557522 | TASK [setup-stack-user : Create stack user]
2026-08-26 20:15:47.150328 | controller | changed
2026-08-26 20:15:47.159700 | 
2026-08-26 20:15:47.159796 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-08-26 20:15:47.437456 | controller | changed
2026-08-26 20:15:47.446724 | 
2026-08-26 20:15:47.446824 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-08-26 20:15:48.762956 | controller | changed
2026-08-26 20:15:48.774811 | 
2026-08-26 20:15:48.774877 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-08-26 20:15:49.094528 | controller | changed
2026-08-26 20:15:49.104664 | 
2026-08-26 20:15:49.104726 | TASK [setup-tempest-user : Create tempest group]
2026-08-26 20:15:49.476289 | controller | changed
2026-08-26 20:15:49.484446 | 
2026-08-26 20:15:49.484514 | TASK [setup-tempest-user : Create tempest user]
2026-08-26 20:15:49.913948 | controller | changed
2026-08-26 20:15:49.925457 | 
2026-08-26 20:15:49.925553 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-08-26 20:15:50.845112 | controller | changed
2026-08-26 20:15:50.857586 | 
2026-08-26 20:15:50.857650 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-08-26 20:15:51.214715 | controller | ok: Not all paths examined, check warnings for details
2026-08-26 20:15:51.233038 | 
2026-08-26 20:15:51.233107 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-08-26 20:15:52.591012 | controller | ok: Item: Runtime: 0:00:01.026374
2026-08-26 20:15:53.254974 | controller | ok: Item: Runtime: 0:00:00.402955
2026-08-26 20:15:54.031154 | controller | ok: Item: Runtime: 0:00:00.531091
2026-08-26 20:15:54.663685 | controller | ok: Item: Runtime: 0:00:00.375263
2026-08-26 20:15:55.086108 | controller | ok: Item: Runtime: 0:00:00.175781
2026-08-26 20:15:55.597264 | controller | ok: Item: Runtime: 0:00:00.064362
2026-08-26 20:15:57.136776 | controller | ok: Item: Runtime: 0:00:01.273898
2026-08-26 20:16:00.752279 | controller | ok: Item: Runtime: 0:00:03.354744
2026-08-26 20:16:01.266037 | controller | ok: Item: Runtime: 0:00:00.264023
2026-08-26 20:16:01.867064 | controller | ok: Item: Runtime: 0:00:00.342612
2026-08-26 20:16:02.395347 | controller | ok: Item: Runtime: 0:00:00.271163
2026-08-26 20:16:02.909898 | controller | ok: Item: Runtime: 0:00:00.242968
2026-08-26 20:16:03.785650 | controller | ok: Item: Runtime: 0:00:00.644098
2026-08-26 20:16:04.678017 | controller | ok: Item: Runtime: 0:00:00.636470
2026-08-26 20:16:05.384062 | controller | ok: Item: Runtime: 0:00:00.465988
2026-08-26 20:16:05.799350 | controller | ok: Item: Runtime: 0:00:00.182922
2026-08-26 20:16:05.833011 | 
2026-08-26 20:16:05.833176 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-08-26 20:16:06.544923 | controller | ok: All paths examined
2026-08-26 20:16:10.188569 | 
2026-08-26 20:16:10.188692 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-08-26 20:16:10.466094 | controller | ok: All paths examined
2026-08-26 20:16:10.476413 | 
2026-08-26 20:16:10.476562 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-08-26 20:16:10.972994 | controller | ok: Item: Runtime: 0:00:00.198694
2026-08-26 20:16:10.973262 | controller | changed: All items complete
2026-08-26 20:16:10.973310 | 
2026-08-26 20:16:11.486516 | controller | ok: Item: Runtime: 0:00:00.267445
2026-08-26 20:16:11.501052 | 
2026-08-26 20:16:11.501225 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-08-26 20:16:11.592062 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.380924 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.382740 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.384602 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.386332 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.387805 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.389300 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.390526 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.391158 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.391778 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.392401 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.393111 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.393891 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.394627 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.395356 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.395988 | controller | skipping: Conditional result was False
2026-08-26 20:16:12.477656 | 
2026-08-26 20:16:12.477783 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-08-26 20:16:15.314128 | controller | changed
2026-08-26 20:16:15.328751 | 
2026-08-26 20:16:15.328836 | TASK [setup-devstack-log-dir : Create logs directory]
2026-08-26 20:16:15.595648 | controller | changed
2026-08-26 20:16:15.612881 | 
2026-08-26 20:16:15.612979 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-08-26 20:16:15.891771 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-08-26 20:16:16.156063 | controller | ERROR
2026-08-26 20:16:16.156314 | controller | {
2026-08-26 20:16:16.156342 | controller |   "delta": "0:00:00.010774",
2026-08-26 20:16:16.156362 | controller |   "end": "2026-08-26 20:16:15.892354",
2026-08-26 20:16:16.156380 | controller |   "msg": "non-zero return code",
2026-08-26 20:16:16.156398 | controller |   "rc": 1,
2026-08-26 20:16:16.156416 | controller |   "start": "2026-08-26 20:16:15.881580"
2026-08-26 20:16:16.156433 | controller | }
2026-08-26 20:16:16.156458 | controller | ERROR: Ignoring Errors
2026-08-26 20:16:16.164146 | 
2026-08-26 20:16:16.164213 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-08-26 20:16:16.435010 | controller | ok
2026-08-26 20:16:16.447893 | 
2026-08-26 20:16:16.447953 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-08-26 20:16:16.709349 | controller | /usr/bin/journalctl
2026-08-26 20:16:17.277777 | controller | ok: Runtime: 0:00:00.007884
2026-08-26 20:16:17.284418 | 
2026-08-26 20:16:17.284484 | TASK [start-fresh-logging : Get current date]
2026-08-26 20:16:17.561659 | controller | 2026-08-26 20:16:17
2026-08-26 20:16:17.828035 | controller | ok: Runtime: 0:00:00.009476
2026-08-26 20:16:17.833745 | 
2026-08-26 20:16:17.833811 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-08-26 20:16:18.450010 | controller | changed
2026-08-26 20:16:18.456613 | 
2026-08-26 20:16:18.456674 | TASK [start-fresh-logging : Stop rsyslog]
2026-08-26 20:16:18.481497 | controller | skipping: Conditional result was False
2026-08-26 20:16:18.494558 | 
2026-08-26 20:16:18.494700 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-08-26 20:16:19.029353 | controller | skipping: Conditional result was False
2026-08-26 20:16:19.205314 | 
2026-08-26 20:16:19.205415 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-08-26 20:16:19.736520 | controller | skipping: Conditional result was False
2026-08-26 20:16:19.743643 | 
2026-08-26 20:16:19.743711 | TASK [start-fresh-logging : Recreate syslog file]
2026-08-26 20:16:19.769577 | controller | skipping: Conditional result was False
2026-08-26 20:16:19.780200 | 
2026-08-26 20:16:19.780270 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-08-26 20:16:20.312993 | controller | skipping: Conditional result was False
2026-08-26 20:16:20.323445 | 
2026-08-26 20:16:20.323553 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-08-26 20:16:20.899758 | controller | skipping: Conditional result was False
2026-08-26 20:16:21.432583 | 
2026-08-26 20:16:21.432697 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-08-26 20:16:21.457380 | controller | skipping: Conditional result was False
2026-08-26 20:16:21.469575 | 
2026-08-26 20:16:21.469677 | TASK [start-fresh-logging : Recreate kern.log file]
2026-08-26 20:16:21.494637 | controller | skipping: Conditional result was False
2026-08-26 20:16:21.506228 | 
2026-08-26 20:16:21.506319 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-08-26 20:16:22.041975 | controller | skipping: Conditional result was False
2026-08-26 20:16:22.053229 | 
2026-08-26 20:16:22.053320 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-08-26 20:16:22.586715 | controller | skipping: Conditional result was False
2026-08-26 20:16:22.598093 | 
2026-08-26 20:16:22.598195 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-08-26 20:16:22.623212 | controller | skipping: Conditional result was False
2026-08-26 20:16:22.634809 | 
2026-08-26 20:16:22.634916 | TASK [start-fresh-logging : Start rsyslog]
2026-08-26 20:16:22.662167 | controller | skipping: Conditional result was False
2026-08-26 20:16:22.679952 | 
2026-08-26 20:16:22.680039 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-08-26 20:16:23.315205 | controller | ok
2026-08-26 20:16:23.330163 | 
2026-08-26 20:16:23.330285 | PLAY RECAP
2026-08-26 20:16:23.330360 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-08-26 20:16:23.330399 | 
2026-08-26 20:16:23.539411 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-08-26 20:16:23.608596 | PRE-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-08-26 20:16:24.882318 | 
2026-08-26 20:16:25.181454 | PLAY [all]
2026-08-26 20:16:25.379070 | 
2026-08-26 20:16:25.379229 | TASK [Install curl]
2026-08-26 20:16:48.629310 | controller | ok
2026-08-26 20:16:48.636764 | 
2026-08-26 20:16:48.636873 | TASK [ensure-rust : Use rustup]
2026-08-26 20:16:48.660273 | controller | ok
2026-08-26 20:16:48.684375 | controller | included: /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/ensure-rust/tasks/rustup.yaml
2026-08-26 20:16:48.695518 | 
2026-08-26 20:16:48.695598 | TASK [ensure-rust : Install Rust]
2026-08-26 20:16:49.256937 | controller | info: downloading installer
2026-08-26 20:16:52.531713 | controller | warn: It looks like you have an existing rustup settings file at:
2026-08-26 20:16:52.531795 | controller | warn: /opt/rust/settings.toml
2026-08-26 20:16:52.531807 | controller | warn: Rustup will install the default toolchain as specified in the settings file,
2026-08-26 20:16:52.531857 | controller | warn: instead of the one inferred from the default host triple.
2026-08-26 20:16:52.579287 | controller | info: profile set to default
2026-08-26 20:16:52.579355 | controller | info: default host triple is x86_64-unknown-linux-gnu
2026-08-26 20:16:52.581445 | controller | info: syncing channel updates for stable-x86_64-unknown-linux-gnu
2026-08-26 20:17:17.706523 | controller | error: could not download file from 'https://static.rust-lang.org/dist/channel-rust-stable.toml.sha256' to '/opt/rust/tmp/lz9n4ad_gud709hi_file': error downloading file: error sending request for url (https://static.rust-lang.org/dist/channel-rust-stable.toml.sha256): client error (Connect): dns error: failed to lookup address information: Temporary failure in name resolution
2026-08-26 20:17:17.855663 | controller | ERROR
2026-08-26 20:17:17.856172 | controller | {
2026-08-26 20:17:17.856218 | controller |   "delta": "0:00:28.607333",
2026-08-26 20:17:17.856250 | controller |   "end": "2026-08-26 20:17:17.734981",
2026-08-26 20:17:17.856277 | controller |   "msg": "non-zero return code",
2026-08-26 20:17:17.856303 | controller |   "rc": 1,
2026-08-26 20:17:17.856332 | controller |   "start": "2026-08-26 20:16:49.127648"
2026-08-26 20:17:17.856359 | controller | }
failure
2026-08-26 20:17:17.858161 | 
2026-08-26 20:17:17.858221 | PLAY RECAP
2026-08-26 20:17:17.858279 | controller | ok: 2 changed: 0 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-08-26 20:17:17.858314 | 
2026-08-26 20:17:18.013940 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-08-26 20:17:18.031994 | POST-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-08-26 20:17:18.786106 | 
2026-08-26 20:17:18.786238 | PLAY [all]
2026-08-26 20:17:18.798424 | 
2026-08-26 20:17:18.798548 | LOOP [Copy individual Hydrophone result files]
2026-08-26 20:17:19.332088 | controller | ERROR: Item: e2e.log
2026-08-26 20:17:19.332456 | controller | {
2026-08-26 20:17:19.332515 | controller |   "ansible_loop_var": "item",
2026-08-26 20:17:19.332558 | controller |   "item": "e2e.log",
2026-08-26 20:17:19.332655 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/e2e.log not found"
2026-08-26 20:17:19.332692 | controller | }
2026-08-26 20:17:19.648505 | controller | ERROR: Item: junit_01.xml
2026-08-26 20:17:19.751061 | controller | {
2026-08-26 20:17:19.751216 | controller |   "ansible_loop_var": "item",
2026-08-26 20:17:19.751277 | controller |   "item": "junit_01.xml",
2026-08-26 20:17:19.751324 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/junit_01.xml not found"
2026-08-26 20:17:19.751369 | controller | }
2026-08-26 20:17:19.761688 | controller | ERROR: Ignoring Errors
2026-08-26 20:17:19.769509 | 
2026-08-26 20:17:19.769577 | TASK [Copy Hydrophone results tarball to output folder]
2026-08-26 20:17:20.110536 | controller | ERROR
2026-08-26 20:17:20.110755 | controller | {
2026-08-26 20:17:20.110786 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results.tar.gz not found"
2026-08-26 20:17:20.110808 | controller | }
2026-08-26 20:17:20.110833 | controller | ERROR: Ignoring Errors
2026-08-26 20:17:20.130117 | 
2026-08-26 20:17:20.130238 | TASK [Return built artifacts to Zuul]
2026-08-26 20:17:20.176675 | controller | ok
2026-08-26 20:17:20.185279 | 
2026-08-26 20:17:20.185400 | TASK [Get the Docker volume ID]
2026-08-26 20:17:20.733619 | controller | ERROR
2026-08-26 20:17:20.882732 | controller | {
2026-08-26 20:17:20.882860 | controller |   "msg": "[Errno 2] No such file or directory: b'docker'",
2026-08-26 20:17:20.882897 | controller |   "rc": 2
2026-08-26 20:17:20.882927 | controller | }
2026-08-26 20:17:20.882986 | controller | ERROR: Ignoring Errors
2026-08-26 20:17:20.904837 | 
2026-08-26 20:17:20.909319 | TASK [Copy all of the pod logs]
2026-08-26 20:17:20.967149 | controller | ERROR
2026-08-26 20:17:20.967391 | controller | {
2026-08-26 20:17:20.967461 | 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/0d950d6bc28a486a9aa5abfe15be3baf/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:17:20.967489 | controller | }
2026-08-26 20:17:20.967516 | controller | ERROR: Ignoring Errors
2026-08-26 20:17:20.968512 | 
2026-08-26 20:17:20.968556 | PLAY RECAP
2026-08-26 20:17:20.968603 | controller | ok: 5 changed: 0 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 4
2026-08-26 20:17:20.968625 | 
2026-08-26 20:17:21.200792 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-08-26 20:17:21.224766 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-08-26 20:17:22.108504 | 
2026-08-26 20:17:22.273969 | PLAY [all]
2026-08-26 20:17:22.316322 | 
2026-08-26 20:17:22.316693 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-08-26 20:17:22.751274 | controller | changed
2026-08-26 20:17:22.879156 | 
2026-08-26 20:17:22.879374 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-08-26 20:17:23.960361 | controller | ok: Runtime: 0:00:00.488661
2026-08-26 20:17:23.967766 | 
2026-08-26 20:17:23.967840 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-08-26 20:17:24.522360 | controller | ok: Runtime: 0:00:00.019861
2026-08-26 20:17:24.529521 | 
2026-08-26 20:17:24.529644 | TASK [export-devstack-journal : Export journal]
2026-08-26 20:17:25.116134 | controller | ok: Runtime: 0:00:00.023605
2026-08-26 20:17:25.331843 | 
2026-08-26 20:17:25.331958 | TASK [export-devstack-journal : Save journal README]
2026-08-26 20:17:26.341269 | controller | changed
2026-08-26 20:17:26.364214 | 
2026-08-26 20:17:26.364535 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-08-26 20:17:26.654522 | controller | changed
2026-08-26 20:17:26.663029 | 
2026-08-26 20:17:26.663094 | TASK [apache-logs-conf : Find logs]
2026-08-26 20:17:27.012672 | controller | Output suppressed because no_log was given
2026-08-26 20:17:27.019923 | 
2026-08-26 20:17:27.019993 | LOOP [apache-logs-conf : Dereference files]
2026-08-26 20:17:27.048375 | 
2026-08-26 20:17:27.048744 | LOOP [apache-logs-conf : Create hard links]
2026-08-26 20:17:27.087653 | 
2026-08-26 20:17:27.087823 | TASK [apache-logs-conf : Find logs]
2026-08-26 20:17:27.136845 | 
2026-08-26 20:17:27.137046 | LOOP [apache-logs-conf : Dereference files]
2026-08-26 20:17:27.173340 | 
2026-08-26 20:17:27.173542 | LOOP [apache-logs-conf : Create hard links]
2026-08-26 20:17:27.217773 | 
2026-08-26 20:17:27.218030 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-08-26 20:17:27.485542 | controller | changed
2026-08-26 20:17:27.491554 | 
2026-08-26 20:17:27.491619 | TASK [apache-logs-conf : Define config paths]
2026-08-26 20:17:27.526414 | controller | ok
2026-08-26 20:17:27.732985 | 
2026-08-26 20:17:27.733100 | TASK [apache-logs-conf : Discover configurations]
2026-08-26 20:17:27.991452 | controller | Output suppressed because no_log was given
2026-08-26 20:17:27.996771 | 
2026-08-26 20:17:27.996853 | LOOP [apache-logs-conf : Dereference configurations]
2026-08-26 20:17:28.028156 | 
2026-08-26 20:17:28.028321 | LOOP [apache-logs-conf : Link configurations]
2026-08-26 20:17:28.063869 | 
2026-08-26 20:17:28.064050 | TASK [capture-performance-data : Generate statistics]
2026-08-26 20:17:29.662713 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-08-26 20:17:29.684807 | controller | Using python 3.12 to install setuptools
2026-08-26 20:17:29.742885 | controller | /usr/bin/python3.12: No module named pip
2026-08-26 20:17:29.758760 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-08-26 20:17:30.107642 | controller | ERROR
2026-08-26 20:17:30.107998 | controller | {
2026-08-26 20:17:30.108076 | controller |   "delta": "0:00:00.565037",
2026-08-26 20:17:30.108111 | controller |   "end": "2026-08-26 20:17:29.761469",
2026-08-26 20:17:30.108138 | controller |   "msg": "non-zero return code",
2026-08-26 20:17:30.108233 | controller |   "rc": 127,
2026-08-26 20:17:30.108265 | controller |   "start": "2026-08-26 20:17:29.196432"
2026-08-26 20:17:30.108291 | controller | }
2026-08-26 20:17:30.108328 | controller | ERROR: Ignoring Errors
2026-08-26 20:17:30.129674 | 
2026-08-26 20:17:30.129838 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-08-26 20:17:30.572880 | controller | changed
2026-08-26 20:17:30.687383 | 
2026-08-26 20:17:30.687698 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-08-26 20:17:34.848133 | controller | Output suppressed because no_log was given
2026-08-26 20:17:34.856684 | 
2026-08-26 20:17:34.856755 | LOOP [devstack-project-conf : Copy configuration files]
2026-08-26 20:17:34.941977 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.942366 | 
2026-08-26 20:17:34.944287 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.946059 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.947892 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.950010 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.952773 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.956393 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.959308 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.962111 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.964895 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.967612 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.977731 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.979488 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.980415 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.981138 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.982098 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.983993 | controller | skipping: Conditional result was False
2026-08-26 20:17:34.986751 | controller | skipping: Conditional result was False
2026-08-26 20:17:35.066576 | 
2026-08-26 20:17:35.066732 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-08-26 20:17:35.326756 | controller | ok
2026-08-26 20:17:35.336873 | 
2026-08-26 20:17:35.337099 | TASK [devstack-project-conf : Copy configuration files]
2026-08-26 20:17:35.873417 | controller | skipping: Conditional result was False
2026-08-26 20:17:35.888715 | 
2026-08-26 20:17:35.888807 | TASK [capture-system-logs : Stage various logs and reports]
2026-08-26 20:17:36.291090 | controller | /usr/bin/python3: No module named pip
2026-08-26 20:17:37.559209 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-08-26 20:17:37.931878 | controller | ok: Runtime: 0:00:01.396009
2026-08-26 20:17:37.944731 | 
2026-08-26 20:17:37.944811 | LOOP [stage-output : Register sources]
2026-08-26 20:17:48.422330 | controller | Output suppressed because no_log was given
2026-08-26 20:17:48.436162 | 
2026-08-26 20:17:48.436237 | TASK [stage-output : Check sudo]
2026-08-26 20:17:48.974841 | controller | ok: Runtime: 0:00:00.017864
2026-08-26 20:17:48.981108 | 
2026-08-26 20:17:48.981176 | LOOP [stage-output : Set source and destination for files and folders]
2026-08-26 20:17:49.102719 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.103203 | 
2026-08-26 20:17:49.105094 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.106532 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.109377 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.162491 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.163007 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.163934 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.167286 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.171881 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.174955 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.176375 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.179252 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.196002 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.203708 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.235280 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.236272 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.237960 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.238538 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.238912 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.239283 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.241846 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.245498 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.248850 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.280004 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.280502 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.373615 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.500635 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.508941 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.513630 | controller | Output suppressed because no_log was given
2026-08-26 20:17:49.529196 | 
2026-08-26 20:17:49.529790 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-08-26 20:17:49.609732 | controller | ok
2026-08-26 20:17:49.621938 | 
2026-08-26 20:17:49.622073 | LOOP [stage-output : Ensure target folders exist]
2026-08-26 20:17:49.939120 | controller | changed: "docs"
2026-08-26 20:17:50.188854 | controller | changed: "artifacts"
2026-08-26 20:17:50.407222 | controller | ok: "logs"
2026-08-26 20:17:50.438597 | 
2026-08-26 20:17:50.438744 | LOOP [stage-output : Copy files and folders to staging folder]
2026-08-26 20:17:50.756693 | controller | ok: Item: Runtime: 0:00:00.011611
2026-08-26 20:17:50.759280 | controller | changed: All items complete
2026-08-26 20:17:50.759397 | 
2026-08-26 20:17:51.016151 | controller | ok: Item: Runtime: 0:00:00.008958
2026-08-26 20:17:51.313174 | controller | ok: Item: Runtime: 0:00:00.011059
2026-08-26 20:17:51.577531 | controller | ok: Item: Runtime: 0:00:00.009675
2026-08-26 20:17:51.828913 | controller | ok: Item: Runtime: 0:00:00.009291
2026-08-26 20:17:52.091493 | controller | ok: Item: Runtime: 0:00:00.008222
2026-08-26 20:17:52.362370 | controller | ok: Item: Runtime: 0:00:00.008757
2026-08-26 20:17:52.647708 | controller | ok: Item: Runtime: 0:00:00.008652
2026-08-26 20:17:52.978787 | controller | ok: Item: Runtime: 0:00:00.008898
2026-08-26 20:17:53.169947 | controller | ok: Item: Runtime: 0:00:00.009303
2026-08-26 20:17:53.429203 | controller | ok: Item: Runtime: 0:00:00.008527
2026-08-26 20:17:53.678295 | controller | ok: Item: Runtime: 0:00:00.008390
2026-08-26 20:17:53.938596 | controller | ok: Item: Runtime: 0:00:00.008095
2026-08-26 20:17:54.188919 | controller | ok: Item: Runtime: 0:00:00.008779
2026-08-26 20:17:54.444743 | controller | ok: Item: Runtime: 0:00:00.008081
2026-08-26 20:17:54.662815 | controller | ok: Item: Runtime: 0:00:00.008313
2026-08-26 20:17:54.871789 | 
2026-08-26 20:17:54.871911 | TASK [stage-output : Make all log files readable]
2026-08-26 20:17:55.163672 | controller | changed
2026-08-26 20:17:55.190947 | 
2026-08-26 20:17:55.191588 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-08-26 20:17:55.618629 | controller | changed: Renamed files for staging.
2026-08-26 20:17:55.623956 | 
2026-08-26 20:17:55.624020 | TASK [stage-output : Discover log files for compression]
2026-08-26 20:17:55.648722 | controller | skipping: Conditional result was False
2026-08-26 20:17:55.660218 | 
2026-08-26 20:17:55.660312 | LOOP [stage-output : Archive everything from logs]
2026-08-26 20:17:55.702354 | 
2026-08-26 20:17:55.702481 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-08-26 20:17:56.624587 | controller | changed:
2026-08-26 20:17:56.624757 | controller | created directory /var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/work/logs/controller
2026-08-26 20:17:56.624785 | controller | cd+++++++++ logs/
2026-08-26 20:17:56.624807 | controller | >f+++++++++ logs/deprecations_log.txt
2026-08-26 20:17:56.624827 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-08-26 20:17:56.624846 | controller | >f+++++++++ logs/devstack.journal.gz
2026-08-26 20:17:56.624865 | controller | >f+++++++++ logs/df.txt
2026-08-26 20:17:56.624884 | controller | >f+++++++++ logs/dpkg-l.txt
2026-08-26 20:17:56.624903 | controller | >f+++++++++ logs/iptables.txt
2026-08-26 20:17:56.624921 | controller | >f+++++++++ logs/listen53.txt
2026-08-26 20:17:56.624940 | controller | >f+++++++++ logs/local_conf.txt
2026-08-26 20:17:56.624983 | controller | >f+++++++++ logs/mount.txt
2026-08-26 20:17:56.625005 | controller | >f+++++++++ logs/performance.json
2026-08-26 20:17:56.625024 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-08-26 20:17:56.625043 | controller | >f+++++++++ logs/resolv_conf.txt
2026-08-26 20:17:56.625062 | controller | >f+++++++++ logs/services.txt
2026-08-26 20:17:56.625086 | controller | >f+++++++++ logs/sudoers
2026-08-26 20:17:56.625105 | controller | >f+++++++++ logs/syslog.txt
2026-08-26 20:17:56.625124 | controller | cd+++++++++ logs/apache/
2026-08-26 20:17:56.625142 | controller | cd+++++++++ logs/apache_config/
2026-08-26 20:17:56.625161 | controller | cd+++++++++ logs/etc/
2026-08-26 20:17:56.625180 | controller | cd+++++++++ logs/sudoers.d/
2026-08-26 20:17:56.625205 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-08-26 20:17:56.625228 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-08-26 20:17:56.625246 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-08-26 20:17:56.625265 | controller | >f+++++++++ logs/sudoers.d/README
2026-08-26 20:17:56.625283 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-08-26 20:17:56.650960 | 
2026-08-26 20:17:56.651099 | TASK [Check if a tempest log exits]
2026-08-26 20:17:56.914881 | controller | ok
2026-08-26 20:17:56.920287 | 
2026-08-26 20:17:56.920352 | TASK [Link post-devstack tempest.log]
2026-08-26 20:17:56.946053 | controller | skipping: Conditional result was False
2026-08-26 20:17:56.955213 | 
2026-08-26 20:17:56.955305 | TASK [Capture most recent qemu crash dump, if any]
2026-08-26 20:17:57.226932 | controller | /bin/bash: line 1: coredumpctl: command not found
2026-08-26 20:17:57.497716 | controller | ERROR
2026-08-26 20:17:57.498041 | controller | {
2026-08-26 20:17:57.498093 | controller |   "delta": "0:00:00.009238",
2026-08-26 20:17:57.498127 | controller |   "end": "2026-08-26 20:17:57.227573",
2026-08-26 20:17:57.498155 | controller |   "msg": "non-zero return code",
2026-08-26 20:17:57.498182 | controller |   "rc": 127,
2026-08-26 20:17:57.498210 | controller |   "start": "2026-08-26 20:17:57.218335"
2026-08-26 20:17:57.498237 | controller | }
2026-08-26 20:17:57.498271 | controller | ERROR: Ignoring Errors
2026-08-26 20:17:57.508266 | 
2026-08-26 20:17:57.508495 | TASK [Collect Guru Meditation Reports from OpenStack services]
2026-08-26 20:17:58.067820 | controller | ERROR
2026-08-26 20:17:58.068085 | controller | {
2026-08-26 20:17:58.068127 | controller |   "delta": "0:00:00.109757",
2026-08-26 20:17:58.068156 | controller |   "end": "2026-08-26 20:17:57.932424",
2026-08-26 20:17:58.068183 | controller |   "msg": "non-zero return code",
2026-08-26 20:17:58.068208 | controller |   "rc": -12,
2026-08-26 20:17:58.068232 | controller |   "start": "2026-08-26 20:17:57.822667"
2026-08-26 20:17:58.068256 | controller | }
2026-08-26 20:17:58.068289 | controller | ERROR: Ignoring Errors
2026-08-26 20:17:58.070118 | 
2026-08-26 20:17:58.070178 | PLAY RECAP
2026-08-26 20:17:58.070241 | controller | ok: 27 changed: 18 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 3
2026-08-26 20:17:58.070271 | 
2026-08-26 20:17:58.242386 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-08-26 20:17:58.271015 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-08-26 20:17:59.702583 | 
2026-08-26 20:17:59.702838 | PLAY [all]
2026-08-26 20:17:59.730041 | 
2026-08-26 20:17:59.730260 | TASK [fetch-output : Set log path for multiple nodes]
2026-08-26 20:17:59.770985 | controller | skipping: Conditional result was False
2026-08-26 20:17:59.782807 | 
2026-08-26 20:17:59.782914 | TASK [fetch-output : Set log path for single node]
2026-08-26 20:17:59.823363 | controller | ok
2026-08-26 20:17:59.828822 | 
2026-08-26 20:17:59.828892 | LOOP [fetch-output : Ensure local output dirs]
2026-08-26 20:18:00.499081 | controller -> localhost | ok: "/var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/work/logs"
2026-08-26 20:18:00.736865 | controller -> localhost | changed: "/var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/work/artifacts"
2026-08-26 20:18:00.959057 | controller -> localhost | changed: "/var/lib/zuul/builds/0d950d6bc28a486a9aa5abfe15be3baf/work/docs"
2026-08-26 20:18:00.980414 | 
2026-08-26 20:18:00.980607 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-08-26 20:18:02.012616 | controller | changed: .d..t...... ./
2026-08-26 20:18:02.012806 | controller | changed: All items complete
2026-08-26 20:18:02.012833 | 
2026-08-26 20:18:02.553167 | controller | changed: .d..t...... ./
2026-08-26 20:18:03.068429 | controller | changed: .d..t...... ./
2026-08-26 20:18:03.091443 | 
2026-08-26 20:18:03.091576 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-08-26 20:18:03.805260 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007414
2026-08-26 20:18:04.040007 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007583
2026-08-26 20:18:04.183101 | 
2026-08-26 20:18:04.183260 | PLAY [all]
2026-08-26 20:18:04.192619 | 
2026-08-26 20:18:04.192716 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-08-26 20:18:04.728318 | controller | changed
2026-08-26 20:18:04.904511 | 
2026-08-26 20:18:04.904605 | PLAY RECAP
2026-08-26 20:18:04.904649 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-08-26 20:18:04.904671 | 
2026-08-26 20:18:05.031456 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-08-26 20:18:05.147434 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-08-26 20:18:05.849120 | 
2026-08-26 20:18:05.849252 | PLAY [localhost]
2026-08-26 20:18:05.861457 | 
2026-08-26 20:18:05.861535 | TASK [Generate Zuul manifest]
2026-08-26 20:18:05.884165 | localhost | ok
2026-08-26 20:18:06.071507 | 
2026-08-26 20:18:06.071828 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-08-26 20:18:06.805609 | localhost | changed
2026-08-26 20:18:06.832605 | 
2026-08-26 20:18:06.832766 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-08-26 20:18:06.888215 | localhost | ok
2026-08-26 20:18:06.897344 | 
2026-08-26 20:18:06.897434 | TASK [Upload logs]
2026-08-26 20:18:06.920434 | localhost | ok
2026-08-26 20:18:07.198037 | 
2026-08-26 20:18:07.198622 | TASK [Set zuul-log-path fact]
2026-08-26 20:18:07.219492 | localhost | ok
2026-08-26 20:18:07.273550 | 
2026-08-26 20:18:07.273685 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-08-26 20:18:07.306587 | localhost | ok
2026-08-26 20:18:07.316231 | 
2026-08-26 20:18:07.316316 | TASK [upload-logs : Create log directories]
2026-08-26 20:18:07.927968 | localhost | changed
2026-08-26 20:18:07.934234 | 
2026-08-26 20:18:07.934855 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-08-26 20:18:08.486355 | localhost -> localhost | ok: Runtime: 0:00:00.004679
2026-08-26 20:18:08.493340 | 
2026-08-26 20:18:08.493441 | TASK [upload-logs : Upload logs to log server]
2026-08-26 20:18:09.343895 | localhost | Output suppressed because no_log was given
2026-08-26 20:18:09.350883 | 
2026-08-26 20:18:09.351158 | LOOP [upload-logs : Compress console log and json output]
2026-08-26 20:18:09.407140 | localhost | skipping: Conditional result was False
2026-08-26 20:18:09.414835 | localhost | skipping: Conditional result was False
2026-08-26 20:18:09.446487 | 
2026-08-26 20:18:09.446668 | LOOP [upload-logs : Upload compressed console log and json output]
2026-08-26 20:18:09.499744 | localhost | skipping: Conditional result was False
2026-08-26 20:18:09.500170 | 
2026-08-26 20:18:09.504645 | localhost | skipping: Conditional result was False
2026-08-26 20:18:09.520527 | 
2026-08-26 20:18:09.520620 | LOOP [upload-logs : Upload console log and json output]