2026-03-26 00:32:08.226894 | Job console starting
2026-03-26 00:32:08.615912 | Updating git repos
2026-03-26 00:32:12.698730 | Cloning repos into workspace
2026-03-26 00:32:50.521527 | Restoring repo states
2026-03-26 00:32:53.295490 | Merging changes
2026-03-26 00:32:54.343016 | Checking out repos
2026-03-26 00:33:05.374228 | Preparing playbooks
2026-03-26 00:33:25.848598 | Running Ansible setup
2026-03-26 00:33:30.643106 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-03-26 00:33:31.382907 | 
2026-03-26 00:33:31.383073 | PLAY [localhost]
2026-03-26 00:33:31.391611 | 
2026-03-26 00:33:31.391710 | TASK [Gathering Facts]
2026-03-26 00:33:32.520680 | localhost | ok
2026-03-26 00:33:32.527842 | 
2026-03-26 00:33:32.527946 | TASK [Setup log path fact]
2026-03-26 00:33:32.556327 | localhost | ok
2026-03-26 00:33:32.568579 | 
2026-03-26 00:33:32.568712 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-03-26 00:33:32.599058 | localhost | ok
2026-03-26 00:33:32.607692 | 
2026-03-26 00:33:32.607758 | TASK [emit-job-header : Print job information]
2026-03-26 00:33:32.648335 | # Job Information
2026-03-26 00:33:32.648546 | Ansible Version: 2.16.16
2026-03-26 00:33:32.648603 | Job: magnum-cluster-api-hydrophone-v1.34.5-calico
2026-03-26 00:33:32.648634 | Pipeline: check
2026-03-26 00:33:32.648661 | Executor: 0a8996d2b663
2026-03-26 00:33:32.648688 | Triggered by: https://github.com/vexxhost/magnum-cluster-api/pull/854
2026-03-26 00:33:32.648719 | Event ID: 1bb86420-28a5-11f1-8896-3d6f5a40c153
2026-03-26 00:33:32.652311 | 
2026-03-26 00:33:32.652391 | LOOP [emit-job-header : Print node information]
2026-03-26 00:33:32.770454 | localhost | ok:
2026-03-26 00:33:32.771076 | localhost | # Node Information
2026-03-26 00:33:32.771136 | localhost | Inventory Hostname: controller
2026-03-26 00:33:32.771171 | localhost | Hostname: np0000160869
2026-03-26 00:33:32.771200 | localhost | Username: zuul
2026-03-26 00:33:32.771236 | localhost | Distro: Ubuntu 24.04
2026-03-26 00:33:32.771266 | localhost | Provider: yul1
2026-03-26 00:33:32.771295 | localhost | Region: ca-ymq-1
2026-03-26 00:33:32.771322 | localhost | Label: ubuntu-noble-16
2026-03-26 00:33:32.771351 | localhost | Product Name: OpenStack Nova
2026-03-26 00:33:32.771379 | localhost | Interface IP: 199.204.45.157
2026-03-26 00:33:32.791973 | 
2026-03-26 00:33:32.792221 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-03-26 00:33:33.243162 | localhost -> localhost | changed
2026-03-26 00:33:33.249926 | 
2026-03-26 00:33:33.250045 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-03-26 00:33:34.695447 | localhost -> localhost | changed
2026-03-26 00:33:34.703396 | 
2026-03-26 00:33:34.703475 | PLAY [all]
2026-03-26 00:33:34.715129 | 
2026-03-26 00:33:34.715209 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-03-26 00:33:34.959165 | controller -> localhost | ok
2026-03-26 00:33:34.970990 | 
2026-03-26 00:33:34.971081 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-03-26 00:33:35.004698 | controller | ok
2026-03-26 00:33:35.028598 | controller | included: /var/lib/zuul/builds/38c797142f504b09b62ced5449935818/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-03-26 00:33:35.035049 | 
2026-03-26 00:33:35.035115 | TASK [add-build-sshkey : Create Temp SSH key]
2026-03-26 00:33:36.629535 | controller -> localhost | Generating public/private rsa key pair.
2026-03-26 00:33:36.629737 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/38c797142f504b09b62ced5449935818/work/38c797142f504b09b62ced5449935818_id_rsa
2026-03-26 00:33:36.629768 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/38c797142f504b09b62ced5449935818/work/38c797142f504b09b62ced5449935818_id_rsa.pub
2026-03-26 00:33:36.629790 | controller -> localhost | The key fingerprint is:
2026-03-26 00:33:36.629811 | controller -> localhost | SHA256:bn56zDILG2L4V0H+UjH6Wlk+O4hycc3lmUyNRmBf9Q0 zuul-build-sshkey
2026-03-26 00:33:36.629846 | controller -> localhost | The key's randomart image is:
2026-03-26 00:33:36.629866 | controller -> localhost | +---[RSA 3072]----+
2026-03-26 00:33:36.629887 | controller -> localhost | |            o.E +|
2026-03-26 00:33:36.629907 | controller -> localhost | |        . o. ..oo|
2026-03-26 00:33:36.629926 | controller -> localhost | |       o . o ..oo|
2026-03-26 00:33:36.629945 | controller -> localhost | |        + . . = .|
2026-03-26 00:33:36.629963 | controller -> localhost | |        S= * * o |
2026-03-26 00:33:36.629982 | controller -> localhost | |   .   .+ * = =  |
2026-03-26 00:33:36.630001 | controller -> localhost | |  . o o.oX . o   |
2026-03-26 00:33:36.630020 | controller -> localhost | |   o .o** * o    |
2026-03-26 00:33:36.630042 | controller -> localhost | |    ...o+B   .   |
2026-03-26 00:33:36.630061 | controller -> localhost | +----[SHA256]-----+
2026-03-26 00:33:36.630112 | controller -> localhost | ok: Runtime: 0:00:01.053832
2026-03-26 00:33:36.638386 | 
2026-03-26 00:33:36.638453 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-03-26 00:33:36.660392 | controller | ok
2026-03-26 00:33:36.673130 | controller | included: /var/lib/zuul/builds/38c797142f504b09b62ced5449935818/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-03-26 00:33:36.681561 | 
2026-03-26 00:33:36.681626 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-03-26 00:33:36.706218 | controller | skipping: Conditional result was False
2026-03-26 00:33:36.719064 | 
2026-03-26 00:33:36.719135 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-03-26 00:33:37.364379 | controller | changed
2026-03-26 00:33:37.370105 | 
2026-03-26 00:33:37.370169 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-03-26 00:33:37.596439 | controller | ok
2026-03-26 00:33:37.602847 | 
2026-03-26 00:33:37.602916 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-03-26 00:33:38.163554 | controller | changed
2026-03-26 00:33:38.168925 | 
2026-03-26 00:33:38.169003 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-03-26 00:33:38.740390 | controller | changed
2026-03-26 00:33:38.746233 | 
2026-03-26 00:33:38.746379 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-03-26 00:33:38.771392 | controller | skipping: Conditional result was False
2026-03-26 00:33:38.788377 | 
2026-03-26 00:33:38.788571 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-03-26 00:33:39.360838 | controller -> localhost | changed
2026-03-26 00:33:39.425159 | 
2026-03-26 00:33:39.425309 | TASK [add-build-sshkey : Add back temp key]
2026-03-26 00:33:39.717848 | controller -> localhost | Identity added: /var/lib/zuul/builds/38c797142f504b09b62ced5449935818/work/38c797142f504b09b62ced5449935818_id_rsa (zuul-build-sshkey)
2026-03-26 00:33:39.718104 | controller -> localhost | ok: Runtime: 0:00:00.014218
2026-03-26 00:33:39.728007 | 
2026-03-26 00:33:39.728103 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-03-26 00:33:40.067760 | controller | ok
2026-03-26 00:33:40.074164 | 
2026-03-26 00:33:40.074227 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-03-26 00:33:40.100352 | controller | skipping: Conditional result was False
2026-03-26 00:33:40.117559 | 
2026-03-26 00:33:40.117656 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-03-26 00:33:40.457881 | controller | ok
2026-03-26 00:33:40.465555 | 
2026-03-26 00:33:40.465617 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-03-26 00:34:52.308805 | controller | Output suppressed because no_log was given
2026-03-26 00:34:52.323168 | 
2026-03-26 00:34:52.323309 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-03-26 00:34:52.876064 | controller | ok: "logs"
2026-03-26 00:34:52.876334 | controller | ok: All items complete
2026-03-26 00:34:52.876363 | 
2026-03-26 00:34:53.226551 | controller | ok: "artifacts"
2026-03-26 00:34:53.472715 | controller | ok: "docs"
2026-03-26 00:34:53.532173 | 
2026-03-26 00:34:53.555039 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-03-26 00:34:53.794137 | controller | changed: "logs"
2026-03-26 00:34:53.996667 | controller | changed: "artifacts"
2026-03-26 00:34:54.203622 | controller | changed: "docs"
2026-03-26 00:34:54.261141 | 
2026-03-26 00:34:54.261236 | PLAY RECAP
2026-03-26 00:34:54.261282 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-03-26 00:34:54.261310 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-03-26 00:34:54.261333 | 
2026-03-26 00:34:54.386467 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-03-26 00:34:54.423213 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-03-26 00:34:55.055898 | 
2026-03-26 00:34:55.056365 | PLAY [all]
2026-03-26 00:34:55.074155 | 
2026-03-26 00:34:55.074242 | TASK [Fix the permissions of the zuul home directory]
2026-03-26 00:34:55.708732 | controller | changed
2026-03-26 00:34:55.956351 | 
2026-03-26 00:34:55.956475 | TASK [Gather minimum local MTU]
2026-03-26 00:34:56.032293 | controller | ok
2026-03-26 00:34:56.039397 | 
2026-03-26 00:34:56.039466 | TASK [Calculate external_bridge_mtu]
2026-03-26 00:34:56.100963 | controller | ok
2026-03-26 00:34:56.105949 | 
2026-03-26 00:34:56.106018 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-03-26 00:34:56.141909 | controller | skipping: Conditional result was False
2026-03-26 00:34:56.177957 | 
2026-03-26 00:34:56.178136 | TASK [configure-swap : Get ephemeral0 device node]
2026-03-26 00:34:56.721699 | controller | ok: Runtime: 0:00:00.010692
2026-03-26 00:34:56.728131 | 
2026-03-26 00:34:56.728206 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-03-26 00:34:56.763804 | controller | skipping: Conditional result was False
2026-03-26 00:34:56.810566 | 
2026-03-26 00:34:56.810767 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-03-26 00:34:56.836266 | controller | skipping: Conditional result was False
2026-03-26 00:34:56.849323 | 
2026-03-26 00:34:56.849671 | TASK [configure-swap : Setup swap file on root device]
2026-03-26 00:34:56.906513 | controller | ok
2026-03-26 00:34:56.953544 | controller | included: /var/lib/zuul/builds/38c797142f504b09b62ced5449935818/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-03-26 00:34:56.961271 | 
2026-03-26 00:34:56.961515 | TASK [configure-swap : Calculate required swap]
2026-03-26 00:34:57.017669 | controller | ok
2026-03-26 00:34:57.054904 | 
2026-03-26 00:34:57.055259 | TASK [configure-swap : Get root filesystem]
2026-03-26 00:34:57.388381 | controller | ext4
2026-03-26 00:34:57.651505 | controller | ok: Runtime: 0:00:00.012170
2026-03-26 00:34:57.662373 | 
2026-03-26 00:34:57.662619 | TASK [configure-swap : Save root filesystem]
2026-03-26 00:34:57.712791 | controller | ok
2026-03-26 00:34:57.718542 | 
2026-03-26 00:34:57.718619 | TASK [configure-swap : Debug the root_filesystem variable]
2026-03-26 00:34:57.751265 | controller | ok:
2026-03-26 00:34:57.751465 | controller | {
2026-03-26 00:34:57.751502 | controller |   "root_filesystem": "ext4"
2026-03-26 00:34:57.751531 | controller | }
2026-03-26 00:34:57.761789 | 
2026-03-26 00:34:57.761880 | TASK [configure-swap : Create swap backing file]
2026-03-26 00:35:06.974240 | controller | 8192+0 records in
2026-03-26 00:35:06.974960 | controller | 8192+0 records out
2026-03-26 00:35:06.974972 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 8.91423 s, 964 MB/s
2026-03-26 00:35:07.899960 | controller | ok: Runtime: 0:00:08.935618
2026-03-26 00:35:07.909799 | 
2026-03-26 00:35:07.909945 | TASK [configure-swap : Ensure swapfile perms]
2026-03-26 00:35:08.868148 | controller | changed
2026-03-26 00:35:11.713861 | 
2026-03-26 00:35:11.713975 | TASK [configure-swap : Make swapfile]
2026-03-26 00:36:22.084801 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2026-03-26 00:36:22.085391 | controller | no label, UUID=dcf41fb3-dafa-4554-bd47-f42d0380f919
2026-03-26 00:36:22.392920 | controller | ok: Runtime: 0:01:09.703932
2026-03-26 00:36:22.400962 | 
2026-03-26 00:36:22.401093 | TASK [configure-swap : Write swap to fstab]
2026-03-26 00:36:22.797153 | controller | changed
2026-03-26 00:36:22.803824 | 
2026-03-26 00:36:22.803961 | TASK [configure-swap : Add all swap]
2026-03-26 00:36:23.346095 | controller | ok: Runtime: 0:00:00.020133
2026-03-26 00:36:23.352902 | 
2026-03-26 00:36:23.352989 | TASK [configure-swap : Debug the swap_required variable]
2026-03-26 00:36:23.389780 | controller | ok:
2026-03-26 00:36:23.389990 | controller | {
2026-03-26 00:36:23.390019 | controller |   "swap_required": "8192"
2026-03-26 00:36:23.390045 | controller | }
2026-03-26 00:36:23.396560 | 
2026-03-26 00:36:23.396645 | TASK [configure-swap : Set swappiness]
2026-03-26 00:36:23.867369 | controller | changed
2026-03-26 00:36:23.992506 | 
2026-03-26 00:36:23.992647 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-03-26 00:36:24.039092 | controller | ok:
2026-03-26 00:36:24.039364 | controller | {
2026-03-26 00:36:24.039419 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-03-26 00:36:24.039467 | controller | }
2026-03-26 00:36:24.051431 | 
2026-03-26 00:36:24.112507 | TASK [setup-stack-user : Create stack group]
2026-03-26 00:36:24.574568 | controller | changed
2026-03-26 00:36:24.580424 | 
2026-03-26 00:36:24.580510 | TASK [setup-stack-user : Create the stack user home folder]
2026-03-26 00:36:24.827217 | controller | changed
2026-03-26 00:36:24.891254 | 
2026-03-26 00:36:24.891399 | TASK [setup-stack-user : Create stack user]
2026-03-26 00:36:25.494283 | controller | changed
2026-03-26 00:36:25.500791 | 
2026-03-26 00:36:25.500856 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-03-26 00:36:25.756562 | controller | changed
2026-03-26 00:36:25.897341 | 
2026-03-26 00:36:25.897492 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-03-26 00:36:27.110596 | controller | changed
2026-03-26 00:36:27.149956 | 
2026-03-26 00:36:27.150090 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-03-26 00:36:27.425268 | controller | changed
2026-03-26 00:36:27.506905 | 
2026-03-26 00:36:27.562396 | TASK [setup-tempest-user : Create tempest group]
2026-03-26 00:36:27.884081 | controller | changed
2026-03-26 00:36:27.891865 | 
2026-03-26 00:36:27.891992 | TASK [setup-tempest-user : Create tempest user]
2026-03-26 00:36:28.391427 | controller | changed
2026-03-26 00:36:28.525029 | 
2026-03-26 00:36:28.525169 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-03-26 00:36:29.353111 | controller | changed
2026-03-26 00:36:29.366676 | 
2026-03-26 00:36:29.366772 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-03-26 00:36:29.717180 | controller | ok: Not all paths examined, check warnings for details
2026-03-26 00:36:29.731518 | 
2026-03-26 00:36:29.731669 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-03-26 00:36:30.218915 | controller | ok: Item: Runtime: 0:00:00.197903
2026-03-26 00:36:31.045579 | controller | ok: Item: Runtime: 0:00:00.586448
2026-03-26 00:36:31.392771 | controller | ok: Item: Runtime: 0:00:00.118091
2026-03-26 00:36:33.026800 | controller | ok: Item: Runtime: 0:00:01.393856
2026-03-26 00:36:33.976594 | controller | ok: Item: Runtime: 0:00:00.714470
2026-03-26 00:36:34.322889 | controller | ok: Item: Runtime: 0:00:00.059922
2026-03-26 00:36:35.104060 | controller | ok: Item: Runtime: 0:00:00.555952
2026-03-26 00:36:35.613863 | controller | ok: Item: Runtime: 0:00:00.295260
2026-03-26 00:36:36.143230 | controller | ok: Item: Runtime: 0:00:00.301563
2026-03-26 00:36:37.588747 | controller | ok: Item: Runtime: 0:00:01.217425
2026-03-26 00:36:38.067742 | controller | ok: Item: Runtime: 0:00:00.260038
2026-03-26 00:36:41.702366 | controller | ok: Item: Runtime: 0:00:03.395842
2026-03-26 00:36:42.251224 | controller | ok: Item: Runtime: 0:00:00.333652
2026-03-26 00:36:42.639489 | controller | ok: Item: Runtime: 0:00:00.143337
2026-03-26 00:36:43.072560 | controller | ok: Item: Runtime: 0:00:00.188218
2026-03-26 00:36:43.451132 | controller | ok: Item: Runtime: 0:00:00.156359
2026-03-26 00:36:43.515233 | 
2026-03-26 00:36:43.515393 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-03-26 00:36:43.735790 | controller | ok: All paths examined
2026-03-26 00:36:43.959005 | 
2026-03-26 00:36:43.959168 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-03-26 00:36:44.230972 | controller | ok: All paths examined
2026-03-26 00:36:44.298372 | 
2026-03-26 00:36:44.298547 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-03-26 00:36:44.752324 | controller | ok: Item: Runtime: 0:00:00.143211
2026-03-26 00:36:44.871277 | controller | changed: All items complete
2026-03-26 00:36:44.871500 | 
2026-03-26 00:36:45.225709 | controller | ok: Item: Runtime: 0:00:00.231631
2026-03-26 00:36:45.246225 | 
2026-03-26 00:36:45.246369 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-03-26 00:36:45.293727 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.397556 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.398610 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.399760 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.401081 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.402071 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.403023 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.404106 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.405161 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.406034 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.406785 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.407459 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.408184 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.408903 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.409671 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.411954 | controller | skipping: Conditional result was False
2026-03-26 00:36:45.438939 | 
2026-03-26 00:36:45.523021 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-03-26 00:36:48.154353 | controller | changed
2026-03-26 00:36:48.173711 | 
2026-03-26 00:36:48.257231 | TASK [setup-devstack-log-dir : Create logs directory]
2026-03-26 00:36:48.563959 | controller | changed
2026-03-26 00:36:48.681600 | 
2026-03-26 00:36:48.681758 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-03-26 00:36:48.962917 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-03-26 00:36:49.251537 | controller | ERROR
2026-03-26 00:36:49.251825 | controller | {
2026-03-26 00:36:49.251872 | controller |   "delta": "0:00:00.011955",
2026-03-26 00:36:49.251903 | controller |   "end": "2026-03-26 00:36:48.964016",
2026-03-26 00:36:49.251932 | controller |   "msg": "non-zero return code",
2026-03-26 00:36:49.251960 | controller |   "rc": 1,
2026-03-26 00:36:49.251988 | controller |   "start": "2026-03-26 00:36:48.952061"
2026-03-26 00:36:49.252013 | controller | }
2026-03-26 00:36:49.252056 | controller | ERROR: Ignoring Errors
2026-03-26 00:36:49.264510 | 
2026-03-26 00:36:49.264648 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-03-26 00:36:49.525286 | controller | ok
2026-03-26 00:36:49.682019 | 
2026-03-26 00:36:49.683469 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-03-26 00:36:49.963525 | controller | /usr/bin/journalctl
2026-03-26 00:36:50.240788 | controller | ok: Runtime: 0:00:00.006897
2026-03-26 00:36:50.249051 | 
2026-03-26 00:36:50.249119 | TASK [start-fresh-logging : Get current date]
2026-03-26 00:36:50.516660 | controller | 2026-03-26 00:36:50
2026-03-26 00:36:50.784604 | controller | ok: Runtime: 0:00:00.011858
2026-03-26 00:36:50.791178 | 
2026-03-26 00:36:50.791319 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-03-26 00:36:51.395737 | controller | changed
2026-03-26 00:36:51.477771 | 
2026-03-26 00:36:51.485396 | TASK [start-fresh-logging : Stop rsyslog]
2026-03-26 00:36:51.525404 | controller | skipping: Conditional result was False
2026-03-26 00:36:51.541990 | 
2026-03-26 00:36:51.556615 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-03-26 00:36:52.091669 | controller | skipping: Conditional result was False
2026-03-26 00:36:52.105971 | 
2026-03-26 00:36:52.106139 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-03-26 00:36:52.663686 | controller | skipping: Conditional result was False
2026-03-26 00:36:52.706318 | 
2026-03-26 00:36:52.706440 | TASK [start-fresh-logging : Recreate syslog file]
2026-03-26 00:36:52.735491 | controller | skipping: Conditional result was False
2026-03-26 00:36:52.750727 | 
2026-03-26 00:36:52.750888 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-03-26 00:36:53.290576 | controller | skipping: Conditional result was False
2026-03-26 00:36:53.301203 | 
2026-03-26 00:36:53.344101 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-03-26 00:36:53.881936 | controller | skipping: Conditional result was False
2026-03-26 00:36:53.888637 | 
2026-03-26 00:36:53.888757 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-03-26 00:36:53.914942 | controller | skipping: Conditional result was False
2026-03-26 00:36:53.923244 | 
2026-03-26 00:36:53.976882 | TASK [start-fresh-logging : Recreate kern.log file]
2026-03-26 00:36:53.993298 | controller | skipping: Conditional result was False
2026-03-26 00:36:54.065277 | 
2026-03-26 00:36:54.065421 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-03-26 00:36:54.603087 | controller | skipping: Conditional result was False
2026-03-26 00:36:54.631228 | 
2026-03-26 00:36:54.631367 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-03-26 00:36:55.174541 | controller | skipping: Conditional result was False
2026-03-26 00:36:55.208513 | 
2026-03-26 00:36:55.208705 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-03-26 00:36:55.253379 | controller | skipping: Conditional result was False
2026-03-26 00:36:55.279763 | 
2026-03-26 00:36:55.299103 | TASK [start-fresh-logging : Start rsyslog]
2026-03-26 00:36:55.340335 | controller | skipping: Conditional result was False
2026-03-26 00:36:55.396477 | 
2026-03-26 00:36:55.396619 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-03-26 00:36:55.850556 | controller | ok
2026-03-26 00:36:55.868898 | 
2026-03-26 00:36:55.901059 | PLAY RECAP
2026-03-26 00:36:55.901994 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-03-26 00:36:55.902042 | 
2026-03-26 00:36:56.263979 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-03-26 00:36:56.270830 | PRE-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-03-26 00:36:57.043246 | 
2026-03-26 00:36:57.043415 | PLAY [all]
2026-03-26 00:36:57.056081 | 
2026-03-26 00:36:57.056174 | TASK [Install curl]
2026-03-26 02:33:36.469377 | PRE-RUN END RESULT_TIMED_OUT: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-03-26 02:33:36.476811 | POST-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-03-26 02:33:37.064000 | 
2026-03-26 02:33:37.064140 | PLAY [all]
2026-03-26 02:33:37.076176 | 
2026-03-26 02:33:37.076258 | LOOP [Copy individual Hydrophone result files]
2026-03-26 02:33:37.697614 | controller | ERROR: Item: e2e.log
2026-03-26 02:33:37.697985 | controller | {
2026-03-26 02:33:37.698025 | controller |   "ansible_loop_var": "item",
2026-03-26 02:33:37.698055 | controller |   "item": "e2e.log",
2026-03-26 02:33:37.698115 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/e2e.log not found"
2026-03-26 02:33:37.698142 | controller | }
2026-03-26 02:33:37.956507 | controller | ERROR: Item: junit_01.xml
2026-03-26 02:33:37.956669 | controller | {
2026-03-26 02:33:37.956703 | controller |   "ansible_loop_var": "item",
2026-03-26 02:33:37.956725 | controller |   "item": "junit_01.xml",
2026-03-26 02:33:37.956744 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/junit_01.xml not found"
2026-03-26 02:33:37.956763 | controller | }
2026-03-26 02:33:37.974883 | controller | ERROR: Ignoring Errors
2026-03-26 02:33:37.982485 | 
2026-03-26 02:33:37.982550 | TASK [Copy Hydrophone results tarball to output folder]
2026-03-26 02:33:38.271346 | controller | ERROR
2026-03-26 02:33:38.271654 | controller | {
2026-03-26 02:33:38.271684 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results.tar.gz not found"
2026-03-26 02:33:38.271706 | controller | }
2026-03-26 02:33:38.271732 | controller | ERROR: Ignoring Errors
2026-03-26 02:33:38.284249 | 
2026-03-26 02:33:38.284328 | TASK [Return built artifacts to Zuul]
2026-03-26 02:33:38.317282 | controller | ok
2026-03-26 02:33:38.322722 | 
2026-03-26 02:33:38.322782 | TASK [Get the Docker volume ID]
2026-03-26 02:33:38.862093 | controller | ERROR
2026-03-26 02:33:38.862516 | controller | {
2026-03-26 02:33:38.862555 | controller |   "msg": "[Errno 2] No such file or directory: b'docker'",
2026-03-26 02:33:38.862581 | controller |   "rc": 2
2026-03-26 02:33:38.862601 | controller | }
2026-03-26 02:33:38.862629 | controller | ERROR: Ignoring Errors
2026-03-26 02:33:38.868233 | 
2026-03-26 02:33:38.868312 | TASK [Copy all of the pod logs]
2026-03-26 02:33:38.903218 | controller | ERROR
2026-03-26 02:33:38.903389 | controller | {
2026-03-26 02:33:38.903420 | 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/38c797142f504b09b62ced5449935818/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-03-26 02:33:38.903445 | controller | }
2026-03-26 02:33:38.903470 | controller | ERROR: Ignoring Errors
2026-03-26 02:33:38.904641 | 
2026-03-26 02:33:38.904690 | PLAY RECAP
2026-03-26 02:33:38.904734 | controller | ok: 5 changed: 0 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 4
2026-03-26 02:33:38.904755 | 
2026-03-26 02:33:39.047322 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-03-26 02:33:39.058285 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-03-26 02:33:39.660006 | 
2026-03-26 02:33:39.660139 | PLAY [all]
2026-03-26 02:33:39.678699 | 
2026-03-26 02:33:39.678783 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-03-26 02:33:40.244120 | controller | changed
2026-03-26 02:33:40.251873 | 
2026-03-26 02:33:40.251965 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-03-26 02:33:41.291590 | controller | ok: Runtime: 0:00:00.454225
2026-03-26 02:33:41.297570 | 
2026-03-26 02:33:41.297641 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-03-26 02:33:41.836432 | controller | ok: Runtime: 0:00:00.019321
2026-03-26 02:33:41.842331 | 
2026-03-26 02:33:41.842403 | TASK [export-devstack-journal : Export journal]
2026-03-26 02:33:42.380274 | controller | ok: Runtime: 0:00:00.048923
2026-03-26 02:33:42.388848 | 
2026-03-26 02:33:42.388941 | TASK [export-devstack-journal : Save journal README]
2026-03-26 02:33:43.255620 | controller | changed
2026-03-26 02:33:43.266933 | 
2026-03-26 02:33:43.267014 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-03-26 02:33:43.504222 | controller | changed
2026-03-26 02:33:43.510805 | 
2026-03-26 02:33:43.510873 | TASK [apache-logs-conf : Find logs]
2026-03-26 02:33:43.831062 | controller | Output suppressed because no_log was given
2026-03-26 02:33:43.836522 | 
2026-03-26 02:33:43.836596 | LOOP [apache-logs-conf : Dereference files]
2026-03-26 02:33:43.872408 | 
2026-03-26 02:33:43.872537 | LOOP [apache-logs-conf : Create hard links]
2026-03-26 02:33:43.910104 | 
2026-03-26 02:33:43.910343 | TASK [apache-logs-conf : Find logs]
2026-03-26 02:33:43.941509 | 
2026-03-26 02:33:43.941638 | LOOP [apache-logs-conf : Dereference files]
2026-03-26 02:33:43.976896 | 
2026-03-26 02:33:43.977069 | LOOP [apache-logs-conf : Create hard links]
2026-03-26 02:33:44.013273 | 
2026-03-26 02:33:44.013410 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-03-26 02:33:44.250240 | controller | changed
2026-03-26 02:33:44.256089 | 
2026-03-26 02:33:44.256153 | TASK [apache-logs-conf : Define config paths]
2026-03-26 02:33:44.291994 | controller | ok
2026-03-26 02:33:44.299250 | 
2026-03-26 02:33:44.299313 | TASK [apache-logs-conf : Discover configurations]
2026-03-26 02:33:44.529107 | controller | Output suppressed because no_log was given
2026-03-26 02:33:44.534754 | 
2026-03-26 02:33:44.534822 | LOOP [apache-logs-conf : Dereference configurations]
2026-03-26 02:33:44.563110 | 
2026-03-26 02:33:44.563283 | LOOP [apache-logs-conf : Link configurations]
2026-03-26 02:33:44.609003 | 
2026-03-26 02:33:44.609148 | TASK [capture-performance-data : Generate statistics]
2026-03-26 02:33:45.229047 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-03-26 02:33:45.246647 | controller | Using python 3.12 to install setuptools
2026-03-26 02:33:45.285741 | controller | /usr/bin/python3.12: No module named pip
2026-03-26 02:33:45.294102 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-03-26 02:33:45.648855 | controller | ERROR
2026-03-26 02:33:45.649159 | controller | {
2026-03-26 02:33:45.649204 | controller |   "delta": "0:00:00.448120",
2026-03-26 02:33:45.649233 | controller |   "end": "2026-03-26 02:33:45.296093",
2026-03-26 02:33:45.649259 | controller |   "msg": "non-zero return code",
2026-03-26 02:33:45.649287 | controller |   "rc": 127,
2026-03-26 02:33:45.649312 | controller |   "start": "2026-03-26 02:33:44.847973"
2026-03-26 02:33:45.649338 | controller | }
2026-03-26 02:33:45.649373 | controller | ERROR: Ignoring Errors
2026-03-26 02:33:45.662937 | 
2026-03-26 02:33:45.663011 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-03-26 02:33:45.900034 | controller | changed
2026-03-26 02:33:45.909225 | 
2026-03-26 02:33:45.909294 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-03-26 02:33:49.474628 | controller | Output suppressed because no_log was given
2026-03-26 02:33:49.486939 | 
2026-03-26 02:33:49.487029 | LOOP [devstack-project-conf : Copy configuration files]
2026-03-26 02:33:49.523823 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.524452 | 
2026-03-26 02:33:49.526528 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.528186 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.530910 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.533575 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.536331 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.539089 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.542556 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.545021 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.547817 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.550210 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.552839 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.555529 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.558251 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.560881 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.563659 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.566973 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.569900 | controller | skipping: Conditional result was False
2026-03-26 02:33:49.597771 | 
2026-03-26 02:33:49.597909 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-03-26 02:33:49.826815 | controller | ok
2026-03-26 02:33:49.832738 | 
2026-03-26 02:33:49.832809 | TASK [devstack-project-conf : Copy configuration files]
2026-03-26 02:33:50.418735 | controller | skipping: Conditional result was False
2026-03-26 02:33:50.436154 | 
2026-03-26 02:33:50.436267 | TASK [capture-system-logs : Stage various logs and reports]
2026-03-26 02:33:50.777116 | controller | /usr/bin/python3: No module named pip
2026-03-26 02:33:51.896064 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-03-26 02:33:51.973116 | controller | ok: Runtime: 0:00:01.222021
2026-03-26 02:33:51.985733 | 
2026-03-26 02:33:51.985803 | LOOP [stage-output : Register sources]
2026-03-26 02:34:00.994863 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.006244 | 
2026-03-26 02:34:01.006325 | TASK [stage-output : Check sudo]
2026-03-26 02:34:01.580065 | controller | ok: Runtime: 0:00:00.019549
2026-03-26 02:34:01.586568 | 
2026-03-26 02:34:01.586635 | LOOP [stage-output : Set source and destination for files and folders]
2026-03-26 02:34:01.680432 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.680847 | 
2026-03-26 02:34:01.682541 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.684160 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.686868 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.721561 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.721904 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.724494 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.726935 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.729406 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.731839 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.734545 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.736998 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.739442 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.741876 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.760712 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.761221 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.761672 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.762122 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.763974 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.766495 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.769133 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.771671 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.774420 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.799756 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.800148 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.880873 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.892665 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.904495 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.912371 | controller | Output suppressed because no_log was given
2026-03-26 02:34:01.925507 | 
2026-03-26 02:34:01.925569 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-03-26 02:34:01.991908 | controller | ok
2026-03-26 02:34:01.999349 | 
2026-03-26 02:34:01.999413 | LOOP [stage-output : Ensure target folders exist]
2026-03-26 02:34:02.239894 | controller | changed: "docs"
2026-03-26 02:34:02.440492 | controller | changed: "artifacts"
2026-03-26 02:34:02.651539 | controller | ok: "logs"
2026-03-26 02:34:02.673144 | 
2026-03-26 02:34:02.673299 | LOOP [stage-output : Copy files and folders to staging folder]
2026-03-26 02:34:02.941761 | controller | ok: Item: Runtime: 0:00:00.011003
2026-03-26 02:34:02.941989 | controller | changed: All items complete
2026-03-26 02:34:02.942018 | 
2026-03-26 02:34:03.159458 | controller | ok: Item: Runtime: 0:00:00.007550
2026-03-26 02:34:03.380375 | controller | ok: Item: Runtime: 0:00:00.007998
2026-03-26 02:34:03.595629 | controller | ok: Item: Runtime: 0:00:00.005761
2026-03-26 02:34:03.812587 | controller | ok: Item: Runtime: 0:00:00.007131
2026-03-26 02:34:04.017993 | controller | ok: Item: Runtime: 0:00:00.006922
2026-03-26 02:34:04.230279 | controller | ok: Item: Runtime: 0:00:00.007523
2026-03-26 02:34:04.443304 | controller | ok: Item: Runtime: 0:00:00.007135
2026-03-26 02:34:04.656889 | controller | ok: Item: Runtime: 0:00:00.004623
2026-03-26 02:34:04.871405 | controller | ok: Item: Runtime: 0:00:00.007317
2026-03-26 02:34:05.097887 | controller | ok: Item: Runtime: 0:00:00.006897
2026-03-26 02:34:05.321749 | controller | ok: Item: Runtime: 0:00:00.007036
2026-03-26 02:34:05.541682 | controller | ok: Item: Runtime: 0:00:00.007363
2026-03-26 02:34:05.807581 | controller | ok: Item: Runtime: 0:00:00.007424
2026-03-26 02:34:05.984914 | controller | ok: Item: Runtime: 0:00:00.006897
2026-03-26 02:34:06.201658 | controller | ok: Item: Runtime: 0:00:00.008273
2026-03-26 02:34:06.223152 | 
2026-03-26 02:34:06.223304 | TASK [stage-output : Make all log files readable]
2026-03-26 02:34:06.461391 | controller | changed
2026-03-26 02:34:06.468579 | 
2026-03-26 02:34:06.468647 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-03-26 02:34:06.780017 | controller | changed: Renamed files for staging.
2026-03-26 02:34:06.785454 | 
2026-03-26 02:34:06.785519 | TASK [stage-output : Discover log files for compression]
2026-03-26 02:34:06.808608 | controller | skipping: Conditional result was False
2026-03-26 02:34:06.820192 | 
2026-03-26 02:34:06.820255 | LOOP [stage-output : Archive everything from logs]
2026-03-26 02:34:06.865029 | 
2026-03-26 02:34:06.865155 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-03-26 02:34:07.460063 | controller | changed:
2026-03-26 02:34:07.460278 | controller | created directory /var/lib/zuul/builds/38c797142f504b09b62ced5449935818/work/logs/controller
2026-03-26 02:34:07.460320 | controller | cd+++++++++ logs/
2026-03-26 02:34:07.460352 | controller | >f+++++++++ logs/deprecations_log.txt
2026-03-26 02:34:07.460383 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-03-26 02:34:07.460412 | controller | >f+++++++++ logs/devstack.journal.gz
2026-03-26 02:34:07.460440 | controller | >f+++++++++ logs/df.txt
2026-03-26 02:34:07.460468 | controller | >f+++++++++ logs/dpkg-l.txt
2026-03-26 02:34:07.460495 | controller | >f+++++++++ logs/iptables.txt
2026-03-26 02:34:07.460521 | controller | >f+++++++++ logs/listen53.txt
2026-03-26 02:34:07.460547 | controller | >f+++++++++ logs/local_conf.txt
2026-03-26 02:34:07.460574 | controller | >f+++++++++ logs/mount.txt
2026-03-26 02:34:07.460616 | controller | >f+++++++++ logs/performance.json
2026-03-26 02:34:07.460644 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-03-26 02:34:07.460671 | controller | >f+++++++++ logs/resolv_conf.txt
2026-03-26 02:34:07.460697 | controller | >f+++++++++ logs/services.txt
2026-03-26 02:34:07.460725 | controller | >f+++++++++ logs/sudoers
2026-03-26 02:34:07.460752 | controller | >f+++++++++ logs/syslog.txt
2026-03-26 02:34:07.460778 | controller | cd+++++++++ logs/apache/
2026-03-26 02:34:07.460806 | controller | cd+++++++++ logs/apache_config/
2026-03-26 02:34:07.460833 | controller | cd+++++++++ logs/etc/
2026-03-26 02:34:07.460860 | controller | cd+++++++++ logs/sudoers.d/
2026-03-26 02:34:07.460888 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-03-26 02:34:07.460915 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-03-26 02:34:07.460943 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-03-26 02:34:07.460991 | controller | >f+++++++++ logs/sudoers.d/README
2026-03-26 02:34:07.461021 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-03-26 02:34:07.472100 | 
2026-03-26 02:34:07.472168 | TASK [Check if a tempest log exits]
2026-03-26 02:34:07.710651 | controller | ok
2026-03-26 02:34:07.717072 | 
2026-03-26 02:34:07.717136 | TASK [Link post-devstack tempest.log]
2026-03-26 02:34:07.742400 | controller | skipping: Conditional result was False
2026-03-26 02:34:07.754699 | 
2026-03-26 02:34:07.754764 | TASK [Capture most recent qemu crash dump, if any]
2026-03-26 02:34:07.992491 | controller | /bin/bash: line 1: coredumpctl: command not found
2026-03-26 02:34:08.294473 | controller | ERROR
2026-03-26 02:34:08.294717 | controller | {
2026-03-26 02:34:08.294759 | controller |   "delta": "0:00:00.008225",
2026-03-26 02:34:08.294787 | controller |   "end": "2026-03-26 02:34:07.993146",
2026-03-26 02:34:08.294812 | controller |   "msg": "non-zero return code",
2026-03-26 02:34:08.294837 | controller |   "rc": 127,
2026-03-26 02:34:08.294862 | controller |   "start": "2026-03-26 02:34:07.984921"
2026-03-26 02:34:08.294885 | controller | }
2026-03-26 02:34:08.294918 | controller | ERROR: Ignoring Errors
2026-03-26 02:34:08.296951 | 
2026-03-26 02:34:08.297033 | PLAY RECAP
2026-03-26 02:34:08.297097 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2026-03-26 02:34:08.297128 | 
2026-03-26 02:34:08.473897 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-03-26 02:34:08.484349 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-03-26 02:34:09.158967 | 
2026-03-26 02:34:09.159126 | PLAY [all]
2026-03-26 02:34:09.171048 | 
2026-03-26 02:34:09.171130 | TASK [fetch-output : Set log path for multiple nodes]
2026-03-26 02:34:09.205354 | controller | skipping: Conditional result was False
2026-03-26 02:34:09.211207 | 
2026-03-26 02:34:09.211283 | TASK [fetch-output : Set log path for single node]
2026-03-26 02:34:09.259197 | controller | ok
2026-03-26 02:34:09.267658 | 
2026-03-26 02:34:09.267734 | LOOP [fetch-output : Ensure local output dirs]
2026-03-26 02:34:09.655887 | controller -> localhost | ok: "/var/lib/zuul/builds/38c797142f504b09b62ced5449935818/work/logs"
2026-03-26 02:34:09.855342 | controller -> localhost | changed: "/var/lib/zuul/builds/38c797142f504b09b62ced5449935818/work/artifacts"
2026-03-26 02:34:10.063686 | controller -> localhost | changed: "/var/lib/zuul/builds/38c797142f504b09b62ced5449935818/work/docs"
2026-03-26 02:34:10.084049 | 
2026-03-26 02:34:10.084198 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-03-26 02:34:10.716211 | controller | changed: .d..t...... ./
2026-03-26 02:34:10.716470 | controller | changed: All items complete
2026-03-26 02:34:10.716510 | 
2026-03-26 02:34:11.147043 | controller | changed: .d..t...... ./
2026-03-26 02:34:11.601977 | controller | changed: .d..t...... ./
2026-03-26 02:34:11.627585 | 
2026-03-26 02:34:11.627749 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-03-26 02:34:12.050985 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006903
2026-03-26 02:34:12.281994 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008094
2026-03-26 02:34:12.306734 | 
2026-03-26 02:34:12.306867 | PLAY [all]
2026-03-26 02:34:12.313457 | 
2026-03-26 02:34:12.313524 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-03-26 02:34:13.000247 | controller | changed
2026-03-26 02:34:13.006714 | 
2026-03-26 02:34:13.006762 | PLAY RECAP
2026-03-26 02:34:13.006840 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-03-26 02:34:13.006875 | 
2026-03-26 02:34:13.131625 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-03-26 02:34:13.141367 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-03-26 02:34:13.864996 | 
2026-03-26 02:34:13.865125 | PLAY [localhost]
2026-03-26 02:34:13.874777 | 
2026-03-26 02:34:13.874844 | TASK [Generate Zuul manifest]
2026-03-26 02:34:13.894872 | localhost | ok
2026-03-26 02:34:14.162916 | 
2026-03-26 02:34:14.163095 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-03-26 02:34:14.560825 | localhost | changed
2026-03-26 02:34:14.572822 | 
2026-03-26 02:34:14.572897 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-03-26 02:34:14.909108 | localhost | ok
2026-03-26 02:34:14.917130 | 
2026-03-26 02:34:14.917194 | TASK [Upload logs]
2026-03-26 02:34:14.935975 | localhost | ok
2026-03-26 02:34:15.206076 | 
2026-03-26 02:34:15.206223 | TASK [Set zuul-log-path fact]
2026-03-26 02:34:15.226815 | localhost | ok
2026-03-26 02:34:15.321882 | 
2026-03-26 02:34:15.382535 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-03-26 02:34:15.501143 | localhost | ok
2026-03-26 02:34:15.507828 | 
2026-03-26 02:34:15.507893 | TASK [upload-logs : Create log directories]
2026-03-26 02:34:15.865768 | localhost | changed
2026-03-26 02:34:15.871972 | 
2026-03-26 02:34:15.872050 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-03-26 02:34:16.218611 | localhost -> localhost | ok: Runtime: 0:00:00.005666
2026-03-26 02:34:16.225310 | 
2026-03-26 02:34:16.225378 | TASK [upload-logs : Upload logs to log server]
2026-03-26 02:34:17.010224 | localhost | Output suppressed because no_log was given
2026-03-26 02:34:17.014444 | 
2026-03-26 02:34:17.014511 | LOOP [upload-logs : Compress console log and json output]
2026-03-26 02:34:17.055807 | localhost | skipping: Conditional result was False
2026-03-26 02:34:17.062863 | localhost | skipping: Conditional result was False
2026-03-26 02:34:17.078832 | 
2026-03-26 02:34:17.079059 | LOOP [upload-logs : Upload compressed console log and json output]
2026-03-26 02:34:17.117943 | localhost | skipping: Conditional result was False
2026-03-26 02:34:17.118325 | 
2026-03-26 02:34:17.122025 | localhost | skipping: Conditional result was False
2026-03-26 02:34:17.130943 | 
2026-03-26 02:34:17.131119 | LOOP [upload-logs : Upload console log and json output]