2026-02-16 17:20:44.534208 | Job console starting
2026-02-16 17:20:44.547049 | Updating git repos
2026-02-16 17:20:52.466865 | Cloning repos into workspace
2026-02-16 17:21:00.653931 | Restoring repo states
2026-02-16 17:21:03.335822 | Merging changes
2026-02-16 17:21:03.790251 | Checking out repos
2026-02-16 17:21:08.129428 | Preparing playbooks
2026-02-16 17:21:11.863375 | Running Ansible setup
2026-02-16 17:21:15.661670 | PRE-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-02-16 17:21:16.319594 | 
2026-02-16 17:21:16.319757 | PLAY [localhost]
2026-02-16 17:21:16.334980 | 
2026-02-16 17:21:16.335609 | TASK [Gathering Facts]
2026-02-16 17:21:17.225650 | localhost | ok
2026-02-16 17:21:17.232830 | 
2026-02-16 17:21:17.232912 | TASK [Setup log path fact]
2026-02-16 17:21:17.254532 | localhost | ok
2026-02-16 17:21:17.266884 | 
2026-02-16 17:21:17.266962 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-16 17:21:17.308412 | localhost | ok
2026-02-16 17:21:17.316041 | 
2026-02-16 17:21:17.316112 | TASK [emit-job-header : Print job information]
2026-02-16 17:21:17.351469 | # Job Information
2026-02-16 17:21:17.351626 | Ansible Version: 2.16.15
2026-02-16 17:21:17.351671 | Job: magnum-cluster-api-sonobuoy-v1.35.1-cilium
2026-02-16 17:21:17.351703 | Pipeline: check
2026-02-16 17:21:17.351730 | Executor: 3a2793d2bd32
2026-02-16 17:21:17.351756 | Triggered by: https://github.com/vexxhost/magnum-cluster-api/pull/884
2026-02-16 17:21:17.351789 | Event ID: 942d9220-0b5b-11f1-9435-38659876bbc5
2026-02-16 17:21:17.356460 | 
2026-02-16 17:21:17.356620 | LOOP [emit-job-header : Print node information]
2026-02-16 17:21:17.454980 | localhost | ok:
2026-02-16 17:21:17.455245 | localhost | # Node Information
2026-02-16 17:21:17.455283 | localhost | Inventory Hostname: controller
2026-02-16 17:21:17.455311 | localhost | Hostname: np0000155591
2026-02-16 17:21:17.455337 | localhost | Username: zuul
2026-02-16 17:21:17.455365 | localhost | Distro: Ubuntu 24.04
2026-02-16 17:21:17.455390 | localhost | Provider: yul1
2026-02-16 17:21:17.455415 | localhost | Region: ca-ymq-1
2026-02-16 17:21:17.455438 | localhost | Label: ubuntu-noble-16
2026-02-16 17:21:17.455462 | localhost | Product Name: OpenStack Nova
2026-02-16 17:21:17.455486 | localhost | Interface IP: 199.204.45.3
2026-02-16 17:21:17.468302 | 
2026-02-16 17:21:17.468551 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-16 17:21:17.870664 | localhost -> localhost | changed
2026-02-16 17:21:17.876088 | 
2026-02-16 17:21:17.876168 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-16 17:21:18.933621 | localhost -> localhost | changed
2026-02-16 17:21:18.942570 | 
2026-02-16 17:21:18.942643 | PLAY [all]
2026-02-16 17:21:18.957760 | 
2026-02-16 17:21:18.957896 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-16 17:21:19.195898 | controller -> localhost | ok
2026-02-16 17:21:19.202788 | 
2026-02-16 17:21:19.202860 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-16 17:21:19.233366 | controller | ok
2026-02-16 17:21:19.251473 | controller | included: /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-16 17:21:19.267600 | 
2026-02-16 17:21:19.267819 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-16 17:21:20.507956 | controller -> localhost | Generating public/private rsa key pair.
2026-02-16 17:21:20.508207 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/work/d07a2f6c11394cbfbca5a497c788e911_id_rsa
2026-02-16 17:21:20.508251 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/work/d07a2f6c11394cbfbca5a497c788e911_id_rsa.pub
2026-02-16 17:21:20.508284 | controller -> localhost | The key fingerprint is:
2026-02-16 17:21:20.508316 | controller -> localhost | SHA256:zcBQTf3fhpKKY/ucMzepze0w95x2HXk+RdBzuw+0SUk zuul-build-sshkey
2026-02-16 17:21:20.508368 | controller -> localhost | The key's randomart image is:
2026-02-16 17:21:20.508399 | controller -> localhost | +---[RSA 3072]----+
2026-02-16 17:21:20.508459 | controller -> localhost | |      ...o..   . |
2026-02-16 17:21:20.508493 | controller -> localhost | |       o  . . E.o|
2026-02-16 17:21:20.508523 | controller -> localhost | |        o    o o+|
2026-02-16 17:21:20.508553 | controller -> localhost | |         +    =..|
2026-02-16 17:21:20.508581 | controller -> localhost | |        S o  + *+|
2026-02-16 17:21:20.508609 | controller -> localhost | |            o =+*|
2026-02-16 17:21:20.508637 | controller -> localhost | |         . .oo.+*|
2026-02-16 17:21:20.508665 | controller -> localhost | |        +.+++= =*|
2026-02-16 17:21:20.508696 | controller -> localhost | |       ..+==oo+.=|
2026-02-16 17:21:20.508726 | controller -> localhost | +----[SHA256]-----+
2026-02-16 17:21:20.508796 | controller -> localhost | ok: Runtime: 0:00:00.751468
2026-02-16 17:21:20.517257 | 
2026-02-16 17:21:20.517332 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-16 17:21:20.554440 | controller | ok
2026-02-16 17:21:20.567160 | controller | included: /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-16 17:21:20.575796 | 
2026-02-16 17:21:20.575874 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-16 17:21:20.601243 | controller | skipping: Conditional result was False
2026-02-16 17:21:20.613838 | 
2026-02-16 17:21:20.613931 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-16 17:21:21.171379 | controller | changed
2026-02-16 17:21:21.177897 | 
2026-02-16 17:21:21.177965 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-16 17:21:21.400461 | controller | ok
2026-02-16 17:21:21.406220 | 
2026-02-16 17:21:21.406287 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-16 17:21:21.977695 | controller | changed
2026-02-16 17:21:21.983885 | 
2026-02-16 17:21:21.983949 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-16 17:21:22.539058 | controller | changed
2026-02-16 17:21:22.548979 | 
2026-02-16 17:21:22.549069 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-16 17:21:22.574609 | controller | skipping: Conditional result was False
2026-02-16 17:21:22.584130 | 
2026-02-16 17:21:22.584217 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-16 17:21:23.016794 | controller -> localhost | changed
2026-02-16 17:21:23.034315 | 
2026-02-16 17:21:23.034437 | TASK [add-build-sshkey : Add back temp key]
2026-02-16 17:21:23.460165 | controller -> localhost | Identity added: /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/work/d07a2f6c11394cbfbca5a497c788e911_id_rsa (zuul-build-sshkey)
2026-02-16 17:21:23.460439 | controller -> localhost | ok: Runtime: 0:00:00.014062
2026-02-16 17:21:23.531877 | 
2026-02-16 17:21:23.532154 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-16 17:21:23.837949 | controller | ok
2026-02-16 17:21:23.843173 | 
2026-02-16 17:21:23.843237 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-16 17:21:23.867790 | controller | skipping: Conditional result was False
2026-02-16 17:21:23.878577 | 
2026-02-16 17:21:23.878643 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-16 17:21:24.221449 | controller | ok
2026-02-16 17:21:24.236277 | 
2026-02-16 17:21:24.236398 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-16 17:21:45.325068 | controller | Output suppressed because no_log was given
2026-02-16 17:21:45.337426 | 
2026-02-16 17:21:45.337500 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-16 17:21:45.578316 | controller | ok: "logs"
2026-02-16 17:21:45.578598 | controller | ok: All items complete
2026-02-16 17:21:45.578627 | 
2026-02-16 17:21:45.771534 | controller | ok: "artifacts"
2026-02-16 17:21:45.983015 | controller | ok: "docs"
2026-02-16 17:21:45.991750 | 
2026-02-16 17:21:45.991929 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-16 17:21:46.215498 | controller | changed: "logs"
2026-02-16 17:21:46.421872 | controller | changed: "artifacts"
2026-02-16 17:21:46.653086 | controller | changed: "docs"
2026-02-16 17:21:46.674440 | 
2026-02-16 17:21:46.674587 | PLAY RECAP
2026-02-16 17:21:46.674727 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-02-16 17:21:46.674773 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-16 17:21:46.674804 | 
2026-02-16 17:21:46.869460 | PRE-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-02-16 17:21:46.877395 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-16 17:21:47.484911 | 
2026-02-16 17:21:47.485064 | PLAY [all]
2026-02-16 17:21:47.502238 | 
2026-02-16 17:21:47.502312 | TASK [Fix the permissions of the zuul home directory]
2026-02-16 17:21:47.984674 | controller | changed
2026-02-16 17:21:47.993103 | 
2026-02-16 17:21:47.993214 | TASK [Gather minimum local MTU]
2026-02-16 17:21:48.081918 | controller | ok
2026-02-16 17:21:48.087236 | 
2026-02-16 17:21:48.087304 | TASK [Calculate external_bridge_mtu]
2026-02-16 17:21:48.145555 | controller | ok
2026-02-16 17:21:48.151343 | 
2026-02-16 17:21:48.151509 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-02-16 17:21:48.177877 | controller | skipping: Conditional result was False
2026-02-16 17:21:48.190899 | 
2026-02-16 17:21:48.190974 | TASK [configure-swap : Get ephemeral0 device node]
2026-02-16 17:21:48.731858 | controller | ok: Runtime: 0:00:00.010184
2026-02-16 17:21:48.739151 | 
2026-02-16 17:21:48.739223 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-02-16 17:21:48.764899 | controller | skipping: Conditional result was False
2026-02-16 17:21:48.775051 | 
2026-02-16 17:21:48.775122 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-02-16 17:21:48.801621 | controller | skipping: Conditional result was False
2026-02-16 17:21:48.814116 | 
2026-02-16 17:21:48.814195 | TASK [configure-swap : Setup swap file on root device]
2026-02-16 17:21:48.867595 | controller | ok
2026-02-16 17:21:48.881845 | controller | included: /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-02-16 17:21:48.895319 | 
2026-02-16 17:21:48.895548 | TASK [configure-swap : Calculate required swap]
2026-02-16 17:21:48.951912 | controller | ok
2026-02-16 17:21:48.957462 | 
2026-02-16 17:21:48.957536 | TASK [configure-swap : Get root filesystem]
2026-02-16 17:21:49.240538 | controller | ext4
2026-02-16 17:21:49.536539 | controller | ok: Runtime: 0:00:00.013389
2026-02-16 17:21:49.541945 | 
2026-02-16 17:21:49.542007 | TASK [configure-swap : Save root filesystem]
2026-02-16 17:21:49.572310 | controller | ok
2026-02-16 17:21:49.578975 | 
2026-02-16 17:21:49.579043 | TASK [configure-swap : Debug the root_filesystem variable]
2026-02-16 17:21:49.616373 | controller | ok:
2026-02-16 17:21:49.616664 | controller | {
2026-02-16 17:21:49.616720 | controller |   "root_filesystem": "ext4"
2026-02-16 17:21:49.616763 | controller | }
2026-02-16 17:21:49.625441 | 
2026-02-16 17:21:49.625512 | TASK [configure-swap : Create swap backing file]
2026-02-16 17:22:00.033405 | controller | 8192+0 records in
2026-02-16 17:22:00.033652 | controller | 8192+0 records out
2026-02-16 17:22:00.033671 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 10.1413 s, 847 MB/s
2026-02-16 17:22:00.174404 | controller | ok: Runtime: 0:00:10.151664
2026-02-16 17:22:00.179900 | 
2026-02-16 17:22:00.179966 | TASK [configure-swap : Ensure swapfile perms]
2026-02-16 17:22:00.427160 | controller | changed
2026-02-16 17:22:00.433448 | 
2026-02-16 17:22:00.433519 | TASK [configure-swap : Make swapfile]
2026-02-16 17:22:15.742628 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2026-02-16 17:22:15.743437 | controller | no label, UUID=15c07ee8-03cf-42ea-868b-1457e704b16b
2026-02-16 17:22:16.043111 | controller | ok: Runtime: 0:00:15.067530
2026-02-16 17:22:16.049474 | 
2026-02-16 17:22:16.049541 | TASK [configure-swap : Write swap to fstab]
2026-02-16 17:22:16.519264 | controller | changed
2026-02-16 17:22:16.527093 | 
2026-02-16 17:22:16.527166 | TASK [configure-swap : Add all swap]
2026-02-16 17:22:17.063483 | controller | ok: Runtime: 0:00:00.081121
2026-02-16 17:22:17.071937 | 
2026-02-16 17:22:17.072009 | TASK [configure-swap : Debug the swap_required variable]
2026-02-16 17:22:17.110115 | controller | ok:
2026-02-16 17:22:17.110307 | controller | {
2026-02-16 17:22:17.110334 | controller |   "swap_required": "8192"
2026-02-16 17:22:17.110356 | controller | }
2026-02-16 17:22:17.116445 | 
2026-02-16 17:22:17.116513 | TASK [configure-swap : Set swappiness]
2026-02-16 17:22:17.527011 | controller | changed
2026-02-16 17:22:17.533520 | 
2026-02-16 17:22:17.533594 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-02-16 17:22:17.569196 | controller | ok:
2026-02-16 17:22:17.569329 | controller | {
2026-02-16 17:22:17.569356 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-02-16 17:22:17.569382 | controller | }
2026-02-16 17:22:17.579160 | 
2026-02-16 17:22:17.579229 | TASK [setup-stack-user : Create stack group]
2026-02-16 17:22:18.009057 | controller | changed
2026-02-16 17:22:18.016784 | 
2026-02-16 17:22:18.016873 | TASK [setup-stack-user : Create the stack user home folder]
2026-02-16 17:22:18.265049 | controller | changed
2026-02-16 17:22:18.270871 | 
2026-02-16 17:22:18.270936 | TASK [setup-stack-user : Create stack user]
2026-02-16 17:22:18.804909 | controller | changed
2026-02-16 17:22:18.812577 | 
2026-02-16 17:22:18.812662 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-02-16 17:22:19.075681 | controller | changed
2026-02-16 17:22:19.083273 | 
2026-02-16 17:22:19.083342 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-02-16 17:22:20.167687 | controller | changed
2026-02-16 17:22:20.176032 | 
2026-02-16 17:22:20.176120 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-02-16 17:22:20.424490 | controller | changed
2026-02-16 17:22:20.438514 | 
2026-02-16 17:22:20.438580 | TASK [setup-tempest-user : Create tempest group]
2026-02-16 17:22:20.747557 | controller | changed
2026-02-16 17:22:20.752883 | 
2026-02-16 17:22:20.752946 | TASK [setup-tempest-user : Create tempest user]
2026-02-16 17:22:21.142547 | controller | changed
2026-02-16 17:22:21.232047 | 
2026-02-16 17:22:21.232265 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-02-16 17:22:22.013026 | controller | changed
2026-02-16 17:22:22.026591 | 
2026-02-16 17:22:22.026682 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-02-16 17:22:22.361956 | controller | ok: Not all paths examined, check warnings for details
2026-02-16 17:22:22.376455 | 
2026-02-16 17:22:22.376537 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-02-16 17:22:22.854498 | controller | ok: Item: Runtime: 0:00:00.184550
2026-02-16 17:22:23.398442 | controller | ok: Item: Runtime: 0:00:00.330082
2026-02-16 17:22:24.160407 | controller | ok: Item: Runtime: 0:00:00.545349
2026-02-16 17:22:24.437866 | controller | ok: Item: Runtime: 0:00:00.062726
2026-02-16 17:22:24.931566 | controller | ok: Item: Runtime: 0:00:00.265165
2026-02-16 17:22:26.496414 | controller | ok: Item: Runtime: 0:00:01.335439
2026-02-16 17:22:29.970169 | controller | ok: Item: Runtime: 0:00:03.254778
2026-02-16 17:22:30.286977 | controller | ok: Item: Runtime: 0:00:00.097905
2026-02-16 17:22:30.701885 | controller | ok: Item: Runtime: 0:00:00.186899
2026-02-16 17:22:31.042082 | controller | ok: Item: Runtime: 0:00:00.120373
2026-02-16 17:22:31.764716 | controller | ok: Item: Runtime: 0:00:00.503354
2026-02-16 17:22:32.475396 | controller | ok: Item: Runtime: 0:00:00.490344
2026-02-16 17:22:32.939223 | controller | ok: Item: Runtime: 0:00:00.237565
2026-02-16 17:22:33.368953 | controller | ok: Item: Runtime: 0:00:00.209886
2026-02-16 17:22:33.943625 | controller | ok: Item: Runtime: 0:00:00.351760
2026-02-16 17:22:35.229401 | controller | ok: Item: Runtime: 0:00:01.057847
2026-02-16 17:22:35.253650 | 
2026-02-16 17:22:35.253847 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-02-16 17:22:35.470896 | controller | ok: All paths examined
2026-02-16 17:22:35.477514 | 
2026-02-16 17:22:35.477585 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-02-16 17:22:35.718594 | controller | ok: All paths examined
2026-02-16 17:22:35.725360 | 
2026-02-16 17:22:35.725429 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-02-16 17:22:36.149019 | controller | ok: Item: Runtime: 0:00:00.141208
2026-02-16 17:22:36.149306 | controller | changed: All items complete
2026-02-16 17:22:36.149335 | 
2026-02-16 17:22:36.557689 | controller | ok: Item: Runtime: 0:00:00.185042
2026-02-16 17:22:36.568857 | 
2026-02-16 17:22:36.569046 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-02-16 17:22:36.614421 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.616930 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.620368 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.623923 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.627273 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.631272 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.635639 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.639786 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.644177 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.648264 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.651912 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.655171 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.658330 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.661483 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.665094 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.668312 | controller | skipping: Conditional result was False
2026-02-16 17:22:36.698409 | 
2026-02-16 17:22:36.698575 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-02-16 17:22:39.052146 | controller | changed
2026-02-16 17:22:39.064439 | 
2026-02-16 17:22:39.064571 | TASK [setup-devstack-log-dir : Create logs directory]
2026-02-16 17:22:39.303028 | controller | changed
2026-02-16 17:22:39.363417 | 
2026-02-16 17:22:39.363580 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-02-16 17:22:39.612206 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-02-16 17:22:39.899763 | controller | ERROR
2026-02-16 17:22:39.899989 | controller | {
2026-02-16 17:22:39.900018 | controller |   "delta": "0:00:00.009866",
2026-02-16 17:22:39.900039 | controller |   "end": "2026-02-16 17:22:39.612660",
2026-02-16 17:22:39.900057 | controller |   "msg": "non-zero return code",
2026-02-16 17:22:39.900075 | controller |   "rc": 1,
2026-02-16 17:22:39.900092 | controller |   "start": "2026-02-16 17:22:39.602794"
2026-02-16 17:22:39.900109 | controller | }
2026-02-16 17:22:39.900132 | controller | ERROR: Ignoring Errors
2026-02-16 17:22:39.907625 | 
2026-02-16 17:22:39.907694 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-02-16 17:22:40.146247 | controller | ok
2026-02-16 17:22:40.157975 | 
2026-02-16 17:22:40.158039 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-02-16 17:22:40.379582 | controller | /usr/bin/journalctl
2026-02-16 17:22:40.693908 | controller | ok: Runtime: 0:00:00.006595
2026-02-16 17:22:40.699500 | 
2026-02-16 17:22:40.699572 | TASK [start-fresh-logging : Get current date]
2026-02-16 17:22:40.955893 | controller | 2026-02-16 17:22:40
2026-02-16 17:22:41.250940 | controller | ok: Runtime: 0:00:00.009343
2026-02-16 17:22:41.257268 | 
2026-02-16 17:22:41.257342 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-02-16 17:22:41.820758 | controller | changed
2026-02-16 17:22:41.827405 | 
2026-02-16 17:22:41.827470 | TASK [start-fresh-logging : Stop rsyslog]
2026-02-16 17:22:41.844392 | controller | skipping: Conditional result was False
2026-02-16 17:22:41.854086 | 
2026-02-16 17:22:41.854178 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-02-16 17:22:42.384541 | controller | skipping: Conditional result was False
2026-02-16 17:22:42.399527 | 
2026-02-16 17:22:42.399664 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-02-16 17:22:42.929264 | controller | skipping: Conditional result was False
2026-02-16 17:22:42.940766 | 
2026-02-16 17:22:42.940847 | TASK [start-fresh-logging : Recreate syslog file]
2026-02-16 17:22:42.965307 | controller | skipping: Conditional result was False
2026-02-16 17:22:42.976010 | 
2026-02-16 17:22:42.976108 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-02-16 17:22:43.507529 | controller | skipping: Conditional result was False
2026-02-16 17:22:43.518928 | 
2026-02-16 17:22:43.519021 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-02-16 17:22:44.049309 | controller | skipping: Conditional result was False
2026-02-16 17:22:44.055776 | 
2026-02-16 17:22:44.055841 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-02-16 17:22:44.080447 | controller | skipping: Conditional result was False
2026-02-16 17:22:44.086759 | 
2026-02-16 17:22:44.086827 | TASK [start-fresh-logging : Recreate kern.log file]
2026-02-16 17:22:44.112593 | controller | skipping: Conditional result was False
2026-02-16 17:22:44.119930 | 
2026-02-16 17:22:44.120078 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-02-16 17:22:44.716012 | controller | skipping: Conditional result was False
2026-02-16 17:22:44.727788 | 
2026-02-16 17:22:44.727907 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-02-16 17:22:45.259979 | controller | skipping: Conditional result was False
2026-02-16 17:22:45.271020 | 
2026-02-16 17:22:45.271132 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-02-16 17:22:45.285971 | controller | skipping: Conditional result was False
2026-02-16 17:22:45.300016 | 
2026-02-16 17:22:45.300088 | TASK [start-fresh-logging : Start rsyslog]
2026-02-16 17:22:45.324286 | controller | skipping: Conditional result was False
2026-02-16 17:22:45.339536 | 
2026-02-16 17:22:45.339604 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-02-16 17:22:45.712899 | controller | ok
2026-02-16 17:22:45.722097 | 
2026-02-16 17:22:45.722149 | PLAY RECAP
2026-02-16 17:22:45.722196 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-02-16 17:22:45.722217 | 
2026-02-16 17:22:45.868808 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-16 17:22:45.878527 | PRE-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/sonobuoy/pre.yml@main]
2026-02-16 17:22:46.523965 | 
2026-02-16 17:22:46.524117 | PLAY [all]
2026-02-16 17:22:46.536618 | 
2026-02-16 17:22:46.536709 | TASK [ensure-rust : Use rustup]
2026-02-16 17:22:46.569908 | controller | ok
2026-02-16 17:22:46.578191 | controller | included: /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/ensure-rust/tasks/rustup.yaml
2026-02-16 17:22:46.583887 | 
2026-02-16 17:22:46.584257 | TASK [ensure-rust : Install Rust]
2026-02-16 17:22:46.966460 | controller | /bin/bash: line 2: curl: command not found
2026-02-16 17:22:47.123578 | controller | ERROR
2026-02-16 17:22:47.123875 | controller | {
2026-02-16 17:22:47.123920 | controller |   "delta": "0:00:00.008703",
2026-02-16 17:22:47.123955 | controller |   "end": "2026-02-16 17:22:46.969866",
2026-02-16 17:22:47.123984 | controller |   "msg": "non-zero return code",
2026-02-16 17:22:47.124011 | controller |   "rc": 127,
2026-02-16 17:22:47.124038 | controller |   "start": "2026-02-16 17:22:46.961163"
2026-02-16 17:22:47.124071 | controller | }
failure
2026-02-16 17:22:47.126132 | 
2026-02-16 17:22:47.126205 | PLAY RECAP
2026-02-16 17:22:47.126279 | controller | ok: 1 changed: 0 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-02-16 17:22:47.126311 | 
2026-02-16 17:22:47.251867 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/sonobuoy/pre.yml@main]
2026-02-16 17:22:47.259989 | POST-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/sonobuoy/post.yml@main]
2026-02-16 17:22:47.843261 | 
2026-02-16 17:22:47.843394 | PLAY [all]
2026-02-16 17:22:47.860180 | 
2026-02-16 17:22:47.860275 | TASK [Return built artifacts to Zuul]
2026-02-16 17:22:47.894733 | controller | ok
2026-02-16 17:22:47.900220 | 
2026-02-16 17:22:47.900295 | TASK [Get the Docker volume ID]
2026-02-16 17:22:48.438624 | controller | ERROR
2026-02-16 17:22:48.439012 | controller | {
2026-02-16 17:22:48.439055 | controller |   "msg": "[Errno 2] No such file or directory: b'docker'",
2026-02-16 17:22:48.439086 | controller |   "rc": 2
2026-02-16 17:22:48.439112 | controller | }
2026-02-16 17:22:48.439148 | controller | ERROR: Ignoring Errors
2026-02-16 17:22:48.446651 | 
2026-02-16 17:22:48.446720 | TASK [Copy all of the pod logs]
2026-02-16 17:22:48.479770 | controller | ERROR
2026-02-16 17:22:48.479975 | controller | {
2026-02-16 17:22:48.480015 | 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/d07a2f6c11394cbfbca5a497c788e911/untrusted/project_5/github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/sonobuoy/post.yml': line 21, 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-02-16 17:22:48.480046 | controller | }
2026-02-16 17:22:48.480082 | controller | ERROR: Ignoring Errors
2026-02-16 17:22:48.481234 | 
2026-02-16 17:22:48.481295 | PLAY RECAP
2026-02-16 17:22:48.481352 | controller | ok: 3 changed: 0 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 2
2026-02-16 17:22:48.481381 | 
2026-02-16 17:22:48.601828 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/sonobuoy/post.yml@main]
2026-02-16 17:22:48.608884 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-16 17:22:49.278619 | 
2026-02-16 17:22:49.278789 | PLAY [all]
2026-02-16 17:22:49.300843 | 
2026-02-16 17:22:49.300950 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-02-16 17:22:49.703247 | controller | changed
2026-02-16 17:22:49.710202 | 
2026-02-16 17:22:49.710313 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-02-16 17:22:50.752097 | controller | ok: Runtime: 0:00:00.448709
2026-02-16 17:22:50.759326 | 
2026-02-16 17:22:50.759404 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-02-16 17:22:51.298720 | controller | ok: Runtime: 0:00:00.022111
2026-02-16 17:22:51.307508 | 
2026-02-16 17:22:51.307654 | TASK [export-devstack-journal : Export journal]
2026-02-16 17:22:51.849502 | controller | ok: Runtime: 0:00:00.022074
2026-02-16 17:22:51.856160 | 
2026-02-16 17:22:51.856233 | TASK [export-devstack-journal : Save journal README]
2026-02-16 17:22:52.729575 | controller | changed
2026-02-16 17:22:52.776813 | 
2026-02-16 17:22:52.776977 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-02-16 17:22:53.022615 | controller | changed
2026-02-16 17:22:53.028536 | 
2026-02-16 17:22:53.028606 | TASK [apache-logs-conf : Find logs]
2026-02-16 17:22:53.351209 | controller | Output suppressed because no_log was given
2026-02-16 17:22:53.356563 | 
2026-02-16 17:22:53.356631 | LOOP [apache-logs-conf : Dereference files]
2026-02-16 17:22:53.388161 | 
2026-02-16 17:22:53.388289 | LOOP [apache-logs-conf : Create hard links]
2026-02-16 17:22:53.425976 | 
2026-02-16 17:22:53.426122 | TASK [apache-logs-conf : Find logs]
2026-02-16 17:22:53.461560 | 
2026-02-16 17:22:53.461737 | LOOP [apache-logs-conf : Dereference files]
2026-02-16 17:22:53.497147 | 
2026-02-16 17:22:53.497283 | LOOP [apache-logs-conf : Create hard links]
2026-02-16 17:22:53.534318 | 
2026-02-16 17:22:53.534552 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-02-16 17:22:53.779522 | controller | changed
2026-02-16 17:22:53.785949 | 
2026-02-16 17:22:53.786104 | TASK [apache-logs-conf : Define config paths]
2026-02-16 17:22:53.821049 | controller | ok
2026-02-16 17:22:53.828017 | 
2026-02-16 17:22:53.828087 | TASK [apache-logs-conf : Discover configurations]
2026-02-16 17:22:54.055030 | controller | Output suppressed because no_log was given
2026-02-16 17:22:54.061790 | 
2026-02-16 17:22:54.061850 | LOOP [apache-logs-conf : Dereference configurations]
2026-02-16 17:22:54.097237 | 
2026-02-16 17:22:54.097399 | LOOP [apache-logs-conf : Link configurations]
2026-02-16 17:22:54.127263 | 
2026-02-16 17:22:54.127387 | TASK [capture-performance-data : Generate statistics]
2026-02-16 17:22:54.786404 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-02-16 17:22:54.806767 | controller | Using python 3.12 to install setuptools
2026-02-16 17:22:54.843064 | controller | /usr/bin/python3.12: No module named pip
2026-02-16 17:22:54.854375 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-02-16 17:22:55.168744 | controller | ERROR
2026-02-16 17:22:55.169086 | controller | {
2026-02-16 17:22:55.169162 | controller |   "delta": "0:00:00.488510",
2026-02-16 17:22:55.169209 | controller |   "end": "2026-02-16 17:22:54.856845",
2026-02-16 17:22:55.169251 | controller |   "msg": "non-zero return code",
2026-02-16 17:22:55.169301 | controller |   "rc": 127,
2026-02-16 17:22:55.169344 | controller |   "start": "2026-02-16 17:22:54.368335"
2026-02-16 17:22:55.169384 | controller | }
2026-02-16 17:22:55.169438 | controller | ERROR: Ignoring Errors
2026-02-16 17:22:55.181522 | 
2026-02-16 17:22:55.181591 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-02-16 17:22:55.419494 | controller | changed
2026-02-16 17:22:55.425246 | 
2026-02-16 17:22:55.425315 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-02-16 17:22:59.271698 | controller | Output suppressed because no_log was given
2026-02-16 17:22:59.282245 | 
2026-02-16 17:22:59.282338 | LOOP [devstack-project-conf : Copy configuration files]
2026-02-16 17:22:59.313604 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.314264 | 
2026-02-16 17:22:59.316391 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.317985 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.319559 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.321600 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.323964 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.326334 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.328847 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.331120 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.333584 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.335920 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.338214 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.342072 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.344312 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.346631 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.348977 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.351179 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.354508 | controller | skipping: Conditional result was False
2026-02-16 17:22:59.377110 | 
2026-02-16 17:22:59.377243 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-02-16 17:22:59.616715 | controller | ok
2026-02-16 17:22:59.624097 | 
2026-02-16 17:22:59.624165 | TASK [devstack-project-conf : Copy configuration files]
2026-02-16 17:23:00.206721 | controller | skipping: Conditional result was False
2026-02-16 17:23:00.221972 | 
2026-02-16 17:23:00.222074 | TASK [capture-system-logs : Stage various logs and reports]
2026-02-16 17:23:00.501236 | controller | sudo: iptables-save: command not found
2026-02-16 17:23:00.541328 | controller | /usr/bin/python3: No module named pip
2026-02-16 17:23:01.620495 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-02-16 17:23:01.759994 | controller | ok: Runtime: 0:00:01.142218
2026-02-16 17:23:01.770147 | 
2026-02-16 17:23:01.770217 | LOOP [stage-output : Register sources]
2026-02-16 17:23:11.156264 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.197884 | 
2026-02-16 17:23:11.198034 | TASK [stage-output : Check sudo]
2026-02-16 17:23:11.737198 | controller | ok: Runtime: 0:00:00.023668
2026-02-16 17:23:11.745074 | 
2026-02-16 17:23:11.745161 | LOOP [stage-output : Set source and destination for files and folders]
2026-02-16 17:23:11.843027 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.843405 | 
2026-02-16 17:23:11.845208 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.846119 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.848117 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.884165 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.884522 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.884877 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.887318 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.890298 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.892601 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.895166 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.897286 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.899457 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.901716 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.921424 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.921801 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.922134 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.922469 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.922798 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.923636 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.925821 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.928078 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.930390 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.954451 | controller | Output suppressed because no_log was given
2026-02-16 17:23:11.954797 | controller | Output suppressed because no_log was given
2026-02-16 17:23:12.030528 | controller | Output suppressed because no_log was given
2026-02-16 17:23:12.041686 | controller | Output suppressed because no_log was given
2026-02-16 17:23:12.052680 | controller | Output suppressed because no_log was given
2026-02-16 17:23:12.064098 | controller | Output suppressed because no_log was given
2026-02-16 17:23:12.074963 | 
2026-02-16 17:23:12.075046 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-02-16 17:23:12.140046 | controller | ok
2026-02-16 17:23:12.149749 | 
2026-02-16 17:23:12.149815 | LOOP [stage-output : Ensure target folders exist]
2026-02-16 17:23:12.391109 | controller | changed: "docs"
2026-02-16 17:23:12.591152 | controller | changed: "artifacts"
2026-02-16 17:23:12.804872 | controller | ok: "logs"
2026-02-16 17:23:12.821481 | 
2026-02-16 17:23:12.821580 | LOOP [stage-output : Copy files and folders to staging folder]
2026-02-16 17:23:13.102420 | controller | ok: Item: Runtime: 0:00:00.010220
2026-02-16 17:23:13.102705 | controller | changed: All items complete
2026-02-16 17:23:13.102745 | 
2026-02-16 17:23:13.320688 | controller | ok: Item: Runtime: 0:00:00.007410
2026-02-16 17:23:13.540883 | controller | ok: Item: Runtime: 0:00:00.008262
2026-02-16 17:23:13.773920 | controller | ok: Item: Runtime: 0:00:00.008263
2026-02-16 17:23:13.998393 | controller | ok: Item: Runtime: 0:00:00.008480
2026-02-16 17:23:14.230746 | controller | ok: Item: Runtime: 0:00:00.007966
2026-02-16 17:23:14.453219 | controller | ok: Item: Runtime: 0:00:00.008039
2026-02-16 17:23:14.675233 | controller | ok: Item: Runtime: 0:00:00.007625
2026-02-16 17:23:14.912897 | controller | ok: Item: Runtime: 0:00:00.009325
2026-02-16 17:23:15.144401 | controller | ok: Item: Runtime: 0:00:00.009519
2026-02-16 17:23:15.371576 | controller | ok: Item: Runtime: 0:00:00.005194
2026-02-16 17:23:15.655076 | controller | ok: Item: Runtime: 0:00:00.009388
2026-02-16 17:23:15.852059 | controller | ok: Item: Runtime: 0:00:00.009621
2026-02-16 17:23:16.079072 | controller | ok: Item: Runtime: 0:00:00.008019
2026-02-16 17:23:16.310619 | controller | ok: Item: Runtime: 0:00:00.005910
2026-02-16 17:23:16.548551 | controller | ok: Item: Runtime: 0:00:00.009623
2026-02-16 17:23:16.579119 | 
2026-02-16 17:23:16.579325 | TASK [stage-output : Make all log files readable]
2026-02-16 17:23:16.833154 | controller | changed
2026-02-16 17:23:16.839331 | 
2026-02-16 17:23:16.839402 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-02-16 17:23:17.180381 | controller | changed: Renamed files for staging.
2026-02-16 17:23:17.186578 | 
2026-02-16 17:23:17.186653 | TASK [stage-output : Discover log files for compression]
2026-02-16 17:23:17.202102 | controller | skipping: Conditional result was False
2026-02-16 17:23:17.214667 | 
2026-02-16 17:23:17.214781 | LOOP [stage-output : Archive everything from logs]
2026-02-16 17:23:17.259657 | 
2026-02-16 17:23:17.259850 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-02-16 17:23:17.891746 | controller | changed:
2026-02-16 17:23:17.891920 | controller | created directory /var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/work/logs/controller
2026-02-16 17:23:17.891949 | controller | cd+++++++++ logs/
2026-02-16 17:23:17.891970 | controller | >f+++++++++ logs/deprecations_log.txt
2026-02-16 17:23:17.891990 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-02-16 17:23:17.892009 | controller | >f+++++++++ logs/devstack.journal.gz
2026-02-16 17:23:17.892028 | controller | >f+++++++++ logs/df.txt
2026-02-16 17:23:17.892047 | controller | >f+++++++++ logs/dpkg-l.txt
2026-02-16 17:23:17.892065 | controller | >f+++++++++ logs/iptables.txt
2026-02-16 17:23:17.892084 | controller | >f+++++++++ logs/listen53.txt
2026-02-16 17:23:17.892102 | controller | >f+++++++++ logs/local_conf.txt
2026-02-16 17:23:17.892121 | controller | >f+++++++++ logs/mount.txt
2026-02-16 17:23:17.892139 | controller | >f+++++++++ logs/performance.json
2026-02-16 17:23:17.892157 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-02-16 17:23:17.892175 | controller | >f+++++++++ logs/resolv_conf.txt
2026-02-16 17:23:17.892200 | controller | >f+++++++++ logs/services.txt
2026-02-16 17:23:17.892229 | controller | >f+++++++++ logs/sudoers
2026-02-16 17:23:17.892249 | controller | >f+++++++++ logs/syslog.txt
2026-02-16 17:23:17.892268 | controller | cd+++++++++ logs/apache/
2026-02-16 17:23:17.892286 | controller | cd+++++++++ logs/apache_config/
2026-02-16 17:23:17.892304 | controller | cd+++++++++ logs/etc/
2026-02-16 17:23:17.892322 | controller | cd+++++++++ logs/sudoers.d/
2026-02-16 17:23:17.892340 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-02-16 17:23:17.892358 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-02-16 17:23:17.892376 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-02-16 17:23:17.892394 | controller | >f+++++++++ logs/sudoers.d/README
2026-02-16 17:23:17.892412 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-02-16 17:23:17.904492 | 
2026-02-16 17:23:17.904557 | TASK [Check if a tempest log exits]
2026-02-16 17:23:18.152078 | controller | ok
2026-02-16 17:23:18.160239 | 
2026-02-16 17:23:18.160326 | TASK [Link post-devstack tempest.log]
2026-02-16 17:23:18.186287 | controller | skipping: Conditional result was False
2026-02-16 17:23:18.196369 | 
2026-02-16 17:23:18.196433 | TASK [Capture most recent qemu crash dump, if any]
2026-02-16 17:23:18.443133 | controller | /bin/bash: line 1: coredumpctl: command not found
2026-02-16 17:23:18.736537 | controller | ERROR
2026-02-16 17:23:18.736782 | controller | {
2026-02-16 17:23:18.736826 | controller |   "delta": "0:00:00.008285",
2026-02-16 17:23:18.736854 | controller |   "end": "2026-02-16 17:23:18.443901",
2026-02-16 17:23:18.736880 | controller |   "msg": "non-zero return code",
2026-02-16 17:23:18.736905 | controller |   "rc": 127,
2026-02-16 17:23:18.736930 | controller |   "start": "2026-02-16 17:23:18.435616"
2026-02-16 17:23:18.736994 | controller | }
2026-02-16 17:23:18.737037 | controller | ERROR: Ignoring Errors
2026-02-16 17:23:18.739108 | 
2026-02-16 17:23:18.739177 | PLAY RECAP
2026-02-16 17:23:18.739245 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2026-02-16 17:23:18.739274 | 
2026-02-16 17:23:18.877986 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-16 17:23:18.884113 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-02-16 17:23:19.488061 | 
2026-02-16 17:23:19.488231 | PLAY [all]
2026-02-16 17:23:19.500501 | 
2026-02-16 17:23:19.500588 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-16 17:23:19.546592 | controller | skipping: Conditional result was False
2026-02-16 17:23:19.557783 | 
2026-02-16 17:23:19.557891 | TASK [fetch-output : Set log path for single node]
2026-02-16 17:23:19.603829 | controller | ok
2026-02-16 17:23:19.610224 | 
2026-02-16 17:23:19.610298 | LOOP [fetch-output : Ensure local output dirs]
2026-02-16 17:23:20.023880 | controller -> localhost | ok: "/var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/work/logs"
2026-02-16 17:23:20.224038 | controller -> localhost | changed: "/var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/work/artifacts"
2026-02-16 17:23:20.433729 | controller -> localhost | changed: "/var/lib/zuul/builds/d07a2f6c11394cbfbca5a497c788e911/work/docs"
2026-02-16 17:23:20.451535 | 
2026-02-16 17:23:20.451699 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-16 17:23:21.135105 | controller | changed: .d..t...... ./
2026-02-16 17:23:21.135408 | controller | changed: All items complete
2026-02-16 17:23:21.135446 | 
2026-02-16 17:23:21.614170 | controller | changed: .d..t...... ./
2026-02-16 17:23:22.095193 | controller | changed: .d..t...... ./
2026-02-16 17:23:22.120481 | 
2026-02-16 17:23:22.120637 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-16 17:23:22.551128 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007089
2026-02-16 17:23:22.813762 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008856
2026-02-16 17:23:22.835925 | 
2026-02-16 17:23:22.836059 | PLAY [all]
2026-02-16 17:23:22.844055 | 
2026-02-16 17:23:22.844120 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-02-16 17:23:23.324988 | controller | changed
2026-02-16 17:23:23.334126 | 
2026-02-16 17:23:23.334180 | PLAY RECAP
2026-02-16 17:23:23.334231 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-02-16 17:23:23.334253 | 
2026-02-16 17:23:23.457886 | POST-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-02-16 17:23:23.466726 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post-logs.yaml@main]
2026-02-16 17:23:24.048564 | 
2026-02-16 17:23:24.048708 | PLAY [localhost]
2026-02-16 17:23:24.059012 | 
2026-02-16 17:23:24.059084 | TASK [Generate Zuul manifest]
2026-02-16 17:23:24.081032 | localhost | ok
2026-02-16 17:23:24.094975 | 
2026-02-16 17:23:24.095053 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-16 17:23:24.482767 | localhost | changed
2026-02-16 17:23:24.494894 | 
2026-02-16 17:23:24.495012 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-16 17:23:24.527158 | localhost | ok
2026-02-16 17:23:24.536621 | 
2026-02-16 17:23:24.536705 | TASK [Upload logs]
2026-02-16 17:23:24.557932 | localhost | ok
2026-02-16 17:23:24.625222 | 
2026-02-16 17:23:24.625384 | TASK [Set zuul-log-path fact]
2026-02-16 17:23:24.647668 | localhost | ok
2026-02-16 17:23:24.661864 | 
2026-02-16 17:23:24.661931 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-16 17:23:24.694614 | localhost | ok
2026-02-16 17:23:24.701673 | 
2026-02-16 17:23:24.701736 | TASK [upload-logs : Create log directories]
2026-02-16 17:23:25.138768 | localhost | changed
2026-02-16 17:23:25.145334 | 
2026-02-16 17:23:25.145438 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-02-16 17:23:25.622775 | localhost -> localhost | ok: Runtime: 0:00:00.006838
2026-02-16 17:23:25.627476 | 
2026-02-16 17:23:25.627544 | TASK [upload-logs : Upload logs to log server]
2026-02-16 17:23:26.071759 | localhost | Output suppressed because no_log was given
2026-02-16 17:23:26.075473 | 
2026-02-16 17:23:26.075547 | LOOP [upload-logs : Compress console log and json output]
2026-02-16 17:23:26.127406 | localhost | skipping: Conditional result was False
2026-02-16 17:23:26.136330 | localhost | skipping: Conditional result was False
2026-02-16 17:23:26.148665 | 
2026-02-16 17:23:26.148809 | LOOP [upload-logs : Upload compressed console log and json output]
2026-02-16 17:23:26.189412 | localhost | skipping: Conditional result was False
2026-02-16 17:23:26.189839 | 
2026-02-16 17:23:26.192420 | localhost | skipping: Conditional result was False
2026-02-16 17:23:26.200412 | 
2026-02-16 17:23:26.200555 | LOOP [upload-logs : Upload console log and json output]