2026-08-26 20:19:25.708387 | Job console starting
2026-08-26 20:19:25.728265 | Updating git repos
2026-08-26 20:19:27.796017 | Cloning repos into workspace
2026-08-26 20:19:53.255396 | Restoring repo states
2026-08-26 20:19:53.955195 | Merging changes
2026-08-26 20:19:57.014026 | Checking out repos
2026-08-26 20:20:10.685367 | Preparing playbooks
2026-08-26 20:20:30.325474 | Running Ansible setup
2026-08-26 20:20:36.359572 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-08-26 20:20:37.126791 | 
2026-08-26 20:20:37.126927 | PLAY [localhost]
2026-08-26 20:20:37.134435 | 
2026-08-26 20:20:37.134504 | TASK [Gathering Facts]
2026-08-26 20:20:38.546427 | localhost | ok
2026-08-26 20:20:38.557101 | 
2026-08-26 20:20:38.557237 | TASK [Setup log path fact]
2026-08-26 20:20:38.607292 | localhost | ok
2026-08-26 20:20:38.631873 | 
2026-08-26 20:20:38.632039 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-08-26 20:20:38.669193 | localhost | ok
2026-08-26 20:20:38.677160 | 
2026-08-26 20:20:38.677232 | TASK [emit-job-header : Print job information]
2026-08-26 20:20:38.729453 | # Job Information
2026-08-26 20:20:38.729709 | Ansible Version: 2.16.18
2026-08-26 20:20:38.729756 | Job: magnum-cluster-api-hydrophone-v1.35.5-calico
2026-08-26 20:20:38.729788 | Pipeline: check
2026-08-26 20:20:38.729816 | Executor: 2d72f0692154
2026-08-26 20:20:38.729843 | Triggered by: https://github.com/vexxhost/magnum-cluster-api/pull/1129
2026-08-26 20:20:38.729875 | Event ID: 5d57c260-a189-11f1-8bf6-0818591114bd
2026-08-26 20:20:38.734249 | 
2026-08-26 20:20:38.734347 | LOOP [emit-job-header : Print node information]
2026-08-26 20:20:38.915268 | localhost | ok:
2026-08-26 20:20:38.915455 | localhost | # Node Information
2026-08-26 20:20:38.915485 | localhost | Inventory Hostname: controller
2026-08-26 20:20:38.915507 | localhost | Hostname: np0000191249
2026-08-26 20:20:38.915526 | localhost | Username: zuul
2026-08-26 20:20:38.915548 | localhost | Distro: Ubuntu 24.04
2026-08-26 20:20:38.915568 | localhost | Provider: yul1
2026-08-26 20:20:38.915650 | localhost | Region: ca-ymq-1
2026-08-26 20:20:38.915693 | localhost | Label: ubuntu-noble-16
2026-08-26 20:20:38.915715 | localhost | Product Name: OpenStack Nova
2026-08-26 20:20:38.915735 | localhost | Interface IP: 162.253.55.138
2026-08-26 20:20:38.925107 | 
2026-08-26 20:20:38.925269 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-08-26 20:20:39.521975 | localhost -> localhost | changed
2026-08-26 20:20:39.528914 | 
2026-08-26 20:20:39.529052 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-08-26 20:20:40.990681 | localhost -> localhost | changed
2026-08-26 20:20:41.001108 | 
2026-08-26 20:20:41.001181 | PLAY [all]
2026-08-26 20:20:41.014466 | 
2026-08-26 20:20:41.014626 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-08-26 20:20:41.285056 | controller -> localhost | ok
2026-08-26 20:20:41.299622 | 
2026-08-26 20:20:41.299719 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-08-26 20:20:41.339524 | controller | ok
2026-08-26 20:20:41.355077 | controller | included: /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-08-26 20:20:41.361949 | 
2026-08-26 20:20:41.362011 | TASK [add-build-sshkey : Create Temp SSH key]
2026-08-26 20:20:42.613953 | controller -> localhost | Generating public/private rsa key pair.
2026-08-26 20:20:42.616329 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/work/efa6f9b3ccfd46c8aec7692f2daa04bf_id_rsa
2026-08-26 20:20:42.616431 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/work/efa6f9b3ccfd46c8aec7692f2daa04bf_id_rsa.pub
2026-08-26 20:20:42.616479 | controller -> localhost | The key fingerprint is:
2026-08-26 20:20:42.616527 | controller -> localhost | SHA256:UueAqJPWY8sYdSGW4p0eoZ9cUSXLaj1oeDFbyUP0xd0 zuul-build-sshkey
2026-08-26 20:20:42.616841 | controller -> localhost | The key's randomart image is:
2026-08-26 20:20:42.616910 | controller -> localhost | +---[RSA 3072]----+
2026-08-26 20:20:42.617066 | controller -> localhost | |    o..o=..... . |
2026-08-26 20:20:42.617128 | controller -> localhost | |  ..oo.* = .. . E|
2026-08-26 20:20:42.617190 | controller -> localhost | | . +oo=.X o      |
2026-08-26 20:20:42.617273 | controller -> localhost | |  o=+o.X =       |
2026-08-26 20:20:42.617322 | controller -> localhost | |  *+=+O S .      |
2026-08-26 20:20:42.617366 | controller -> localhost | | . *=* . .       |
2026-08-26 20:20:42.617411 | controller -> localhost | |  . o            |
2026-08-26 20:20:42.617453 | controller -> localhost | |                 |
2026-08-26 20:20:42.617502 | controller -> localhost | |                 |
2026-08-26 20:20:42.617596 | controller -> localhost | +----[SHA256]-----+
2026-08-26 20:20:42.617734 | controller -> localhost | ok: Runtime: 0:00:00.652035
2026-08-26 20:20:42.629648 | 
2026-08-26 20:20:42.629788 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-08-26 20:20:42.661968 | controller | ok
2026-08-26 20:20:42.675073 | controller | included: /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-08-26 20:20:42.691577 | 
2026-08-26 20:20:42.691881 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-08-26 20:20:42.717367 | controller | skipping: Conditional result was False
2026-08-26 20:20:42.743609 | 
2026-08-26 20:20:42.744315 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-08-26 20:20:43.426681 | controller | changed
2026-08-26 20:20:43.446199 | 
2026-08-26 20:20:43.446370 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-08-26 20:20:43.702755 | controller | ok
2026-08-26 20:20:43.710520 | 
2026-08-26 20:20:43.710596 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-08-26 20:20:44.492332 | controller | changed
2026-08-26 20:20:44.505999 | 
2026-08-26 20:20:44.506147 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-08-26 20:20:45.459919 | controller | changed
2026-08-26 20:20:45.465827 | 
2026-08-26 20:20:45.465900 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-08-26 20:20:45.503836 | controller | skipping: Conditional result was False
2026-08-26 20:20:45.513684 | 
2026-08-26 20:20:45.513769 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-08-26 20:20:46.022166 | controller -> localhost | changed
2026-08-26 20:20:46.036807 | 
2026-08-26 20:20:46.036872 | TASK [add-build-sshkey : Add back temp key]
2026-08-26 20:20:46.386941 | controller -> localhost | Identity added: /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/work/efa6f9b3ccfd46c8aec7692f2daa04bf_id_rsa (zuul-build-sshkey)
2026-08-26 20:20:46.387156 | controller -> localhost | ok: Runtime: 0:00:00.020885
2026-08-26 20:20:46.402658 | 
2026-08-26 20:20:46.402739 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-08-26 20:20:46.775696 | controller | ok
2026-08-26 20:20:46.780946 | 
2026-08-26 20:20:46.781027 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-08-26 20:20:46.805887 | controller | skipping: Conditional result was False
2026-08-26 20:20:46.818185 | 
2026-08-26 20:20:46.818256 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-08-26 20:20:47.298026 | controller | ok
2026-08-26 20:20:47.304505 | 
2026-08-26 20:20:47.304585 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-08-26 20:22:25.473389 | controller | Output suppressed because no_log was given
2026-08-26 20:22:25.496510 | 
2026-08-26 20:22:25.497020 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-08-26 20:22:25.982092 | controller | ok: "logs"
2026-08-26 20:22:25.982377 | controller | ok: All items complete
2026-08-26 20:22:25.982409 | 
2026-08-26 20:22:26.180029 | controller | ok: "artifacts"
2026-08-26 20:22:26.395774 | controller | ok: "docs"
2026-08-26 20:22:26.530394 | 
2026-08-26 20:22:26.530570 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-08-26 20:22:26.789731 | controller | changed: "logs"
2026-08-26 20:22:26.974849 | controller | changed: "artifacts"
2026-08-26 20:22:27.160411 | controller | changed: "docs"
2026-08-26 20:22:27.182900 | 
2026-08-26 20:22:27.183025 | PLAY RECAP
2026-08-26 20:22:27.183075 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-08-26 20:22:27.183103 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-08-26 20:22:27.183157 | 
2026-08-26 20:22:27.433574 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-08-26 20:22:27.444578 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-08-26 20:22:28.183609 | 
2026-08-26 20:22:28.183762 | PLAY [all]
2026-08-26 20:22:28.208658 | 
2026-08-26 20:22:28.208744 | TASK [Fix the permissions of the zuul home directory]
2026-08-26 20:22:28.989368 | controller | changed
2026-08-26 20:22:29.000626 | 
2026-08-26 20:22:29.000782 | TASK [Gather minimum local MTU]
2026-08-26 20:22:29.194928 | controller | ok
2026-08-26 20:22:29.210670 | 
2026-08-26 20:22:29.210787 | TASK [Calculate external_bridge_mtu]
2026-08-26 20:22:29.303553 | controller | ok
2026-08-26 20:22:29.310173 | 
2026-08-26 20:22:29.310249 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-08-26 20:22:29.336305 | controller | skipping: Conditional result was False
2026-08-26 20:22:29.344881 | 
2026-08-26 20:22:29.345039 | TASK [configure-swap : Get ephemeral0 device node]
2026-08-26 20:22:29.908993 | controller | ok: Runtime: 0:00:00.017271
2026-08-26 20:22:29.916517 | 
2026-08-26 20:22:29.916607 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-08-26 20:22:29.955775 | controller | skipping: Conditional result was False
2026-08-26 20:22:29.968816 | 
2026-08-26 20:22:29.968903 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-08-26 20:22:30.006866 | controller | skipping: Conditional result was False
2026-08-26 20:22:30.022226 | 
2026-08-26 20:22:30.022342 | TASK [configure-swap : Setup swap file on root device]
2026-08-26 20:22:30.082629 | controller | ok
2026-08-26 20:22:30.094346 | controller | included: /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-08-26 20:22:30.103404 | 
2026-08-26 20:22:30.103467 | TASK [configure-swap : Calculate required swap]
2026-08-26 20:22:30.281440 | controller | ok
2026-08-26 20:22:30.392167 | 
2026-08-26 20:22:30.392313 | TASK [configure-swap : Get root filesystem]
2026-08-26 20:22:30.679550 | controller | ext4
2026-08-26 20:22:30.955504 | controller | ok: Runtime: 0:00:00.012377
2026-08-26 20:22:30.962320 | 
2026-08-26 20:22:30.962387 | TASK [configure-swap : Save root filesystem]
2026-08-26 20:22:31.006519 | controller | ok
2026-08-26 20:22:31.022985 | 
2026-08-26 20:22:31.023143 | TASK [configure-swap : Debug the root_filesystem variable]
2026-08-26 20:22:31.076304 | controller | ok:
2026-08-26 20:22:31.076528 | controller | {
2026-08-26 20:22:31.076567 | controller |   "root_filesystem": "ext4"
2026-08-26 20:22:31.076597 | controller | }
2026-08-26 20:22:31.084146 | 
2026-08-26 20:22:31.084232 | TASK [configure-swap : Create swap backing file]
2026-08-26 20:22:40.871127 | controller | 8192+0 records in
2026-08-26 20:22:40.871258 | controller | 8192+0 records out
2026-08-26 20:22:40.871278 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 9.44121 s, 910 MB/s
2026-08-26 20:22:41.138352 | controller | ok: Runtime: 0:00:09.455980
2026-08-26 20:22:41.144849 | 
2026-08-26 20:22:41.144921 | TASK [configure-swap : Ensure swapfile perms]
2026-08-26 20:22:41.413623 | controller | changed
2026-08-26 20:22:41.420511 | 
2026-08-26 20:22:41.420603 | TASK [configure-swap : Make swapfile]
2026-08-26 20:23:00.124995 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2026-08-26 20:23:00.125183 | controller | no label, UUID=07e4b553-4f48-45b0-980c-09231bb59de3
2026-08-26 20:23:00.500656 | controller | ok: Runtime: 0:00:18.392887
2026-08-26 20:23:00.506562 | 
2026-08-26 20:23:00.506631 | TASK [configure-swap : Write swap to fstab]
2026-08-26 20:23:00.951317 | controller | changed
2026-08-26 20:23:00.956594 | 
2026-08-26 20:23:00.956665 | TASK [configure-swap : Add all swap]
2026-08-26 20:23:01.500557 | controller | ok: Runtime: 0:00:00.032535
2026-08-26 20:23:01.507629 | 
2026-08-26 20:23:01.507696 | TASK [configure-swap : Debug the swap_required variable]
2026-08-26 20:23:01.541665 | controller | ok:
2026-08-26 20:23:01.542005 | controller | {
2026-08-26 20:23:01.542041 | controller |   "swap_required": "8192"
2026-08-26 20:23:01.542068 | controller | }
2026-08-26 20:23:01.548960 | 
2026-08-26 20:23:01.549038 | TASK [configure-swap : Set swappiness]
2026-08-26 20:23:01.990073 | controller | changed
2026-08-26 20:23:01.996031 | 
2026-08-26 20:23:01.996143 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-08-26 20:23:02.039202 | controller | ok:
2026-08-26 20:23:02.039388 | controller | {
2026-08-26 20:23:02.039425 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-08-26 20:23:02.039459 | controller | }
2026-08-26 20:23:02.051010 | 
2026-08-26 20:23:02.051107 | TASK [setup-stack-user : Create stack group]
2026-08-26 20:23:02.501536 | controller | changed
2026-08-26 20:23:02.507322 | 
2026-08-26 20:23:02.507470 | TASK [setup-stack-user : Create the stack user home folder]
2026-08-26 20:23:02.770358 | controller | changed
2026-08-26 20:23:02.777049 | 
2026-08-26 20:23:02.777123 | TASK [setup-stack-user : Create stack user]
2026-08-26 20:23:03.403430 | controller | changed
2026-08-26 20:23:03.409428 | 
2026-08-26 20:23:03.409506 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-08-26 20:23:03.672772 | controller | changed
2026-08-26 20:23:03.680026 | 
2026-08-26 20:23:03.680095 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-08-26 20:23:04.913733 | controller | changed
2026-08-26 20:23:04.931969 | 
2026-08-26 20:23:04.932116 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-08-26 20:23:05.283308 | controller | changed
2026-08-26 20:23:05.293960 | 
2026-08-26 20:23:05.294035 | TASK [setup-tempest-user : Create tempest group]
2026-08-26 20:23:05.688502 | controller | changed
2026-08-26 20:23:05.694640 | 
2026-08-26 20:23:05.694709 | TASK [setup-tempest-user : Create tempest user]
2026-08-26 20:23:06.102634 | controller | changed
2026-08-26 20:23:06.111635 | 
2026-08-26 20:23:06.111740 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-08-26 20:23:06.956233 | controller | changed
2026-08-26 20:23:06.966940 | 
2026-08-26 20:23:06.967030 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-08-26 20:23:07.311142 | controller | ok: Not all paths examined, check warnings for details
2026-08-26 20:23:07.324510 | 
2026-08-26 20:23:07.324586 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-08-26 20:23:08.597834 | controller | ok: Item: Runtime: 0:00:00.962772
2026-08-26 20:23:09.940889 | controller | ok: Item: Runtime: 0:00:00.408114
2026-08-26 20:23:10.730965 | controller | ok: Item: Runtime: 0:00:00.538508
2026-08-26 20:23:11.314297 | controller | ok: Item: Runtime: 0:00:00.350955
2026-08-26 20:23:11.744052 | controller | ok: Item: Runtime: 0:00:00.178048
2026-08-26 20:23:12.060769 | controller | ok: Item: Runtime: 0:00:00.064428
2026-08-26 20:23:13.459482 | controller | ok: Item: Runtime: 0:00:01.150400
2026-08-26 20:23:17.074406 | controller | ok: Item: Runtime: 0:00:03.360561
2026-08-26 20:23:17.596067 | controller | ok: Item: Runtime: 0:00:00.265195
2026-08-26 20:23:18.157579 | controller | ok: Item: Runtime: 0:00:00.303809
2026-08-26 20:23:18.660986 | controller | ok: Item: Runtime: 0:00:00.249778
2026-08-26 20:23:19.137264 | controller | ok: Item: Runtime: 0:00:00.229010
2026-08-26 20:23:20.035486 | controller | ok: Item: Runtime: 0:00:00.646935
2026-08-26 20:23:20.868046 | controller | ok: Item: Runtime: 0:00:00.598365
2026-08-26 20:23:21.584277 | controller | ok: Item: Runtime: 0:00:00.464387
2026-08-26 20:23:22.031808 | controller | ok: Item: Runtime: 0:00:00.189745
2026-08-26 20:23:22.057952 | 
2026-08-26 20:23:22.058097 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-08-26 20:23:22.305079 | controller | ok: All paths examined
2026-08-26 20:23:22.312782 | 
2026-08-26 20:23:22.312865 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-08-26 20:23:22.571964 | controller | ok: All paths examined
2026-08-26 20:23:22.580495 | 
2026-08-26 20:23:22.580565 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-08-26 20:23:23.067003 | controller | ok: Item: Runtime: 0:00:00.186692
2026-08-26 20:23:23.067443 | controller | changed: All items complete
2026-08-26 20:23:23.067474 | 
2026-08-26 20:23:23.564873 | controller | ok: Item: Runtime: 0:00:00.246712
2026-08-26 20:23:23.573976 | 
2026-08-26 20:23:23.574050 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-08-26 20:23:23.674296 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.676532 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.680122 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.683539 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.687074 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.690681 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.694301 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.698616 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.701744 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.705100 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.708749 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.712325 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.716524 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.719996 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.723236 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.727364 | controller | skipping: Conditional result was False
2026-08-26 20:23:23.791219 | 
2026-08-26 20:23:23.791363 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-08-26 20:23:26.719009 | controller | changed
2026-08-26 20:23:26.733357 | 
2026-08-26 20:23:26.733580 | TASK [setup-devstack-log-dir : Create logs directory]
2026-08-26 20:23:26.964943 | controller | changed
2026-08-26 20:23:26.976799 | 
2026-08-26 20:23:26.976867 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-08-26 20:23:27.259904 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-08-26 20:23:27.521061 | controller | ERROR
2026-08-26 20:23:27.521310 | controller | {
2026-08-26 20:23:27.521353 | controller |   "delta": "0:00:00.009901",
2026-08-26 20:23:27.521383 | controller |   "end": "2026-08-26 20:23:27.260504",
2026-08-26 20:23:27.521409 | controller |   "msg": "non-zero return code",
2026-08-26 20:23:27.521436 | controller |   "rc": 1,
2026-08-26 20:23:27.521461 | controller |   "start": "2026-08-26 20:23:27.250603"
2026-08-26 20:23:27.521485 | controller | }
2026-08-26 20:23:27.521518 | controller | ERROR: Ignoring Errors
2026-08-26 20:23:27.528557 | 
2026-08-26 20:23:27.528634 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-08-26 20:23:27.778006 | controller | ok
2026-08-26 20:23:27.789681 | 
2026-08-26 20:23:27.789753 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-08-26 20:23:28.060517 | controller | /usr/bin/journalctl
2026-08-26 20:23:28.344588 | controller | ok: Runtime: 0:00:00.007610
2026-08-26 20:23:28.352588 | 
2026-08-26 20:23:28.352658 | TASK [start-fresh-logging : Get current date]
2026-08-26 20:23:28.623391 | controller | 2026-08-26 20:23:28
2026-08-26 20:23:28.890900 | controller | ok: Runtime: 0:00:00.008574
2026-08-26 20:23:28.898469 | 
2026-08-26 20:23:28.898537 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-08-26 20:23:29.531684 | controller | changed
2026-08-26 20:23:29.548359 | 
2026-08-26 20:23:29.548433 | TASK [start-fresh-logging : Stop rsyslog]
2026-08-26 20:23:29.576159 | controller | skipping: Conditional result was False
2026-08-26 20:23:29.583831 | 
2026-08-26 20:23:29.583902 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-08-26 20:23:30.118990 | controller | skipping: Conditional result was False
2026-08-26 20:23:30.130946 | 
2026-08-26 20:23:30.131103 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-08-26 20:23:30.671196 | controller | skipping: Conditional result was False
2026-08-26 20:23:30.683953 | 
2026-08-26 20:23:30.684026 | TASK [start-fresh-logging : Recreate syslog file]
2026-08-26 20:23:30.710997 | controller | skipping: Conditional result was False
2026-08-26 20:23:30.721997 | 
2026-08-26 20:23:30.722098 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-08-26 20:23:31.263752 | controller | skipping: Conditional result was False
2026-08-26 20:23:31.276137 | 
2026-08-26 20:23:31.276276 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-08-26 20:23:31.863715 | controller | skipping: Conditional result was False
2026-08-26 20:23:31.873244 | 
2026-08-26 20:23:31.873340 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-08-26 20:23:31.898376 | controller | skipping: Conditional result was False
2026-08-26 20:23:31.905733 | 
2026-08-26 20:23:31.905804 | TASK [start-fresh-logging : Recreate kern.log file]
2026-08-26 20:23:31.931630 | controller | skipping: Conditional result was False
2026-08-26 20:23:31.943736 | 
2026-08-26 20:23:31.943810 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-08-26 20:23:32.484743 | controller | skipping: Conditional result was False
2026-08-26 20:23:32.495166 | 
2026-08-26 20:23:32.495281 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-08-26 20:23:33.029196 | controller | skipping: Conditional result was False
2026-08-26 20:23:33.042391 | 
2026-08-26 20:23:33.042484 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-08-26 20:23:33.068545 | controller | skipping: Conditional result was False
2026-08-26 20:23:33.078385 | 
2026-08-26 20:23:33.078463 | TASK [start-fresh-logging : Start rsyslog]
2026-08-26 20:23:33.104498 | controller | skipping: Conditional result was False
2026-08-26 20:23:33.122128 | 
2026-08-26 20:23:33.122217 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-08-26 20:23:33.615667 | controller | ok
2026-08-26 20:23:33.625671 | 
2026-08-26 20:23:33.625723 | PLAY RECAP
2026-08-26 20:23:33.625769 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-08-26 20:23:33.625790 | 
2026-08-26 20:23:33.817135 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-08-26 20:23:33.825451 | PRE-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-08-26 20:23:34.481362 | 
2026-08-26 20:23:34.481485 | PLAY [all]
2026-08-26 20:23:34.492851 | 
2026-08-26 20:23:34.492926 | TASK [Install curl]
2026-08-26 20:24:04.057671 | controller | ok
2026-08-26 20:24:04.063769 | 
2026-08-26 20:24:04.064031 | TASK [ensure-rust : Use rustup]
2026-08-26 20:24:04.101519 | controller | ok
2026-08-26 20:24:04.110145 | controller | included: /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/ensure-rust/tasks/rustup.yaml
2026-08-26 20:24:04.117213 | 
2026-08-26 20:24:04.117280 | TASK [ensure-rust : Install Rust]
2026-08-26 20:24:52.568441 | controller | curl: (35) Recv failure: Connection reset by peer
2026-08-26 20:24:52.684537 | controller | ERROR
2026-08-26 20:24:52.684725 | controller | {
2026-08-26 20:24:52.684766 | controller |   "delta": "0:00:48.051140",
2026-08-26 20:24:52.684795 | controller |   "end": "2026-08-26 20:24:52.577205",
2026-08-26 20:24:52.684823 | controller |   "msg": "non-zero return code",
2026-08-26 20:24:52.684848 | controller |   "rc": 35,
2026-08-26 20:24:52.684878 | controller |   "start": "2026-08-26 20:24:04.526065"
2026-08-26 20:24:52.684908 | controller | }
failure
2026-08-26 20:24:52.686875 | 
2026-08-26 20:24:52.686940 | PLAY RECAP
2026-08-26 20:24:52.687003 | controller | ok: 2 changed: 0 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-08-26 20:24:52.687033 | 
2026-08-26 20:24:52.870427 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-08-26 20:24:52.918976 | POST-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-08-26 20:24:53.633964 | 
2026-08-26 20:24:53.634101 | PLAY [all]
2026-08-26 20:24:53.650595 | 
2026-08-26 20:24:53.650740 | LOOP [Copy individual Hydrophone result files]
2026-08-26 20:24:54.363711 | controller | ERROR: Item: e2e.log
2026-08-26 20:24:54.364061 | controller | {
2026-08-26 20:24:54.364117 | controller |   "ansible_loop_var": "item",
2026-08-26 20:24:54.364157 | controller |   "item": "e2e.log",
2026-08-26 20:24:54.364232 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/e2e.log not found"
2026-08-26 20:24:54.364266 | controller | }
2026-08-26 20:24:54.657782 | controller | ERROR: Item: junit_01.xml
2026-08-26 20:24:54.658112 | controller | {
2026-08-26 20:24:54.658150 | controller |   "ansible_loop_var": "item",
2026-08-26 20:24:54.658173 | controller |   "item": "junit_01.xml",
2026-08-26 20:24:54.658192 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/junit_01.xml not found"
2026-08-26 20:24:54.658210 | controller | }
2026-08-26 20:24:54.675374 | controller | ERROR: Ignoring Errors
2026-08-26 20:24:54.682720 | 
2026-08-26 20:24:54.683017 | TASK [Copy Hydrophone results tarball to output folder]
2026-08-26 20:24:55.008912 | controller | ERROR
2026-08-26 20:24:55.009226 | controller | {
2026-08-26 20:24:55.009270 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results.tar.gz not found"
2026-08-26 20:24:55.009301 | controller | }
2026-08-26 20:24:55.009335 | controller | ERROR: Ignoring Errors
2026-08-26 20:24:55.023022 | 
2026-08-26 20:24:55.023097 | TASK [Return built artifacts to Zuul]
2026-08-26 20:24:55.058692 | controller | ok
2026-08-26 20:24:55.066217 | 
2026-08-26 20:24:55.066306 | TASK [Get the Docker volume ID]
2026-08-26 20:24:55.615928 | controller | ERROR
2026-08-26 20:24:55.616182 | controller | {
2026-08-26 20:24:55.616231 | controller |   "msg": "[Errno 2] No such file or directory: b'docker'",
2026-08-26 20:24:55.616261 | controller |   "rc": 2
2026-08-26 20:24:55.616289 | controller | }
2026-08-26 20:24:55.616369 | controller | ERROR: Ignoring Errors
2026-08-26 20:24:55.623935 | 
2026-08-26 20:24:55.624028 | TASK [Copy all of the pod logs]
2026-08-26 20:24:55.659468 | controller | ERROR
2026-08-26 20:24:55.659677 | controller | {
2026-08-26 20:24:55.659717 | 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/efa6f9b3ccfd46c8aec7692f2daa04bf/untrusted/project_5/github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml': line 42, column 11, but may\nbe elsewhere in the file depending on the exact syntax problem.\n\nThe offending line appears to be:\n\n\n        - name: Copy all of the pod logs\n          ^ here\n"
2026-08-26 20:24:55.659759 | controller | }
2026-08-26 20:24:55.659793 | controller | ERROR: Ignoring Errors
2026-08-26 20:24:55.660971 | 
2026-08-26 20:24:55.661030 | PLAY RECAP
2026-08-26 20:24:55.661087 | controller | ok: 5 changed: 0 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 4
2026-08-26 20:24:55.661116 | 
2026-08-26 20:24:55.814919 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-08-26 20:24:55.884216 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-08-26 20:24:56.596513 | 
2026-08-26 20:24:56.596651 | PLAY [all]
2026-08-26 20:24:56.617075 | 
2026-08-26 20:24:56.617173 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-08-26 20:24:57.267826 | controller | changed
2026-08-26 20:24:57.275981 | 
2026-08-26 20:24:57.276095 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-08-26 20:24:58.321015 | controller | ok: Runtime: 0:00:00.459015
2026-08-26 20:24:58.327426 | 
2026-08-26 20:24:58.327557 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-08-26 20:24:58.870328 | controller | ok: Runtime: 0:00:00.022530
2026-08-26 20:24:58.878305 | 
2026-08-26 20:24:58.878404 | TASK [export-devstack-journal : Export journal]
2026-08-26 20:24:59.454369 | controller | ok: Runtime: 0:00:00.018908
2026-08-26 20:24:59.462942 | 
2026-08-26 20:24:59.463039 | TASK [export-devstack-journal : Save journal README]
2026-08-26 20:25:00.356179 | controller | changed
2026-08-26 20:25:00.453719 | 
2026-08-26 20:25:00.453833 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-08-26 20:25:00.715442 | controller | changed
2026-08-26 20:25:00.721215 | 
2026-08-26 20:25:00.721282 | TASK [apache-logs-conf : Find logs]
2026-08-26 20:25:01.091248 | controller | Output suppressed because no_log was given
2026-08-26 20:25:01.098764 | 
2026-08-26 20:25:01.098831 | LOOP [apache-logs-conf : Dereference files]
2026-08-26 20:25:01.135537 | 
2026-08-26 20:25:01.135765 | LOOP [apache-logs-conf : Create hard links]
2026-08-26 20:25:01.162464 | 
2026-08-26 20:25:01.162628 | TASK [apache-logs-conf : Find logs]
2026-08-26 20:25:01.185908 | 
2026-08-26 20:25:01.186126 | LOOP [apache-logs-conf : Dereference files]
2026-08-26 20:25:01.221070 | 
2026-08-26 20:25:01.221247 | LOOP [apache-logs-conf : Create hard links]
2026-08-26 20:25:01.260081 | 
2026-08-26 20:25:01.260216 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-08-26 20:25:01.527040 | controller | changed
2026-08-26 20:25:01.535441 | 
2026-08-26 20:25:01.535507 | TASK [apache-logs-conf : Define config paths]
2026-08-26 20:25:01.568216 | controller | ok
2026-08-26 20:25:01.574446 | 
2026-08-26 20:25:01.574511 | TASK [apache-logs-conf : Discover configurations]
2026-08-26 20:25:01.853356 | controller | Output suppressed because no_log was given
2026-08-26 20:25:01.859581 | 
2026-08-26 20:25:01.859663 | LOOP [apache-logs-conf : Dereference configurations]
2026-08-26 20:25:01.897731 | 
2026-08-26 20:25:01.897916 | LOOP [apache-logs-conf : Link configurations]
2026-08-26 20:25:01.932201 | 
2026-08-26 20:25:01.932323 | TASK [capture-performance-data : Generate statistics]
2026-08-26 20:25:02.639963 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-08-26 20:25:02.660053 | controller | Using python 3.12 to install setuptools
2026-08-26 20:25:02.713609 | controller | /usr/bin/python3.12: No module named pip
2026-08-26 20:25:02.730139 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-08-26 20:25:02.976129 | controller | ERROR
2026-08-26 20:25:02.976385 | controller | {
2026-08-26 20:25:02.976435 | controller |   "delta": "0:00:00.527092",
2026-08-26 20:25:02.976465 | controller |   "end": "2026-08-26 20:25:02.732310",
2026-08-26 20:25:02.976491 | controller |   "msg": "non-zero return code",
2026-08-26 20:25:02.976521 | controller |   "rc": 127,
2026-08-26 20:25:02.976565 | controller |   "start": "2026-08-26 20:25:02.205218"
2026-08-26 20:25:02.976591 | controller | }
2026-08-26 20:25:02.976625 | controller | ERROR: Ignoring Errors
2026-08-26 20:25:02.989580 | 
2026-08-26 20:25:02.989655 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-08-26 20:25:03.267790 | controller | changed
2026-08-26 20:25:03.275041 | 
2026-08-26 20:25:03.275112 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-08-26 20:25:07.400440 | controller | Output suppressed because no_log was given
2026-08-26 20:25:07.413420 | 
2026-08-26 20:25:07.413501 | LOOP [devstack-project-conf : Copy configuration files]
2026-08-26 20:25:07.494268 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.494666 | 
2026-08-26 20:25:07.496502 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.498804 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.501663 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.504092 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.507038 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.509830 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.512716 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.515416 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.518460 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.521281 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.524258 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.526985 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.529909 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.532759 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.535523 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.538323 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.541117 | controller | skipping: Conditional result was False
2026-08-26 20:25:07.654861 | 
2026-08-26 20:25:07.655048 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-08-26 20:25:07.918280 | controller | ok
2026-08-26 20:25:07.924204 | 
2026-08-26 20:25:07.924271 | TASK [devstack-project-conf : Copy configuration files]
2026-08-26 20:25:08.459294 | controller | skipping: Conditional result was False
2026-08-26 20:25:08.476513 | 
2026-08-26 20:25:08.476595 | TASK [capture-system-logs : Stage various logs and reports]
2026-08-26 20:25:08.865430 | controller | /usr/bin/python3: No module named pip
2026-08-26 20:25:10.031589 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-08-26 20:25:10.520099 | controller | ok: Runtime: 0:00:01.293773
2026-08-26 20:25:10.531981 | 
2026-08-26 20:25:10.532044 | LOOP [stage-output : Register sources]
2026-08-26 20:25:21.525178 | controller | Output suppressed because no_log was given
2026-08-26 20:25:21.539433 | 
2026-08-26 20:25:21.539558 | TASK [stage-output : Check sudo]
2026-08-26 20:25:22.086350 | controller | ok: Runtime: 0:00:00.023807
2026-08-26 20:25:22.093478 | 
2026-08-26 20:25:22.093545 | LOOP [stage-output : Set source and destination for files and folders]
2026-08-26 20:25:22.186444 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.243436 | 
2026-08-26 20:25:22.245456 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.246376 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.247180 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.268999 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.269475 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.269864 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.270261 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.270641 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.270986 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.271340 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.271693 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.272022 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.272370 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.277855 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.278508 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.279819 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.282452 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.285574 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.288411 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.290877 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.293628 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.296346 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.323678 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.324023 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.409181 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.422613 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.436172 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.443366 | controller | Output suppressed because no_log was given
2026-08-26 20:25:22.453527 | 
2026-08-26 20:25:22.453591 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-08-26 20:25:22.519124 | controller | ok
2026-08-26 20:25:22.526843 | 
2026-08-26 20:25:22.526909 | LOOP [stage-output : Ensure target folders exist]
2026-08-26 20:25:22.794361 | controller | changed: "docs"
2026-08-26 20:25:23.036402 | controller | changed: "artifacts"
2026-08-26 20:25:23.281947 | controller | ok: "logs"
2026-08-26 20:25:23.300634 | 
2026-08-26 20:25:23.300806 | LOOP [stage-output : Copy files and folders to staging folder]
2026-08-26 20:25:23.599886 | controller | ok: Item: Runtime: 0:00:00.009393
2026-08-26 20:25:23.600101 | controller | changed: All items complete
2026-08-26 20:25:23.600129 | 
2026-08-26 20:25:23.823182 | controller | ok: Item: Runtime: 0:00:00.007565
2026-08-26 20:25:24.067336 | controller | ok: Item: Runtime: 0:00:00.004768
2026-08-26 20:25:24.300409 | controller | ok: Item: Runtime: 0:00:00.007635
2026-08-26 20:25:24.587260 | controller | ok: Item: Runtime: 0:00:00.006705
2026-08-26 20:25:24.819860 | controller | ok: Item: Runtime: 0:00:00.004114
2026-08-26 20:25:25.183001 | controller | ok: Item: Runtime: 0:00:00.007001
2026-08-26 20:25:25.431701 | controller | ok: Item: Runtime: 0:00:00.006925
2026-08-26 20:25:25.684257 | controller | ok: Item: Runtime: 0:00:00.007242
2026-08-26 20:25:25.827503 | controller | ok: Item: Runtime: 0:00:00.004744
2026-08-26 20:25:26.054300 | controller | ok: Item: Runtime: 0:00:00.004179
2026-08-26 20:25:26.299082 | controller | ok: Item: Runtime: 0:00:00.004048
2026-08-26 20:25:26.541477 | controller | ok: Item: Runtime: 0:00:00.003938
2026-08-26 20:25:26.777082 | controller | ok: Item: Runtime: 0:00:00.009152
2026-08-26 20:25:27.017888 | controller | ok: Item: Runtime: 0:00:00.010115
2026-08-26 20:25:27.258408 | controller | ok: Item: Runtime: 0:00:00.007395
2026-08-26 20:25:27.288806 | 
2026-08-26 20:25:27.289003 | TASK [stage-output : Make all log files readable]
2026-08-26 20:25:27.541831 | controller | changed
2026-08-26 20:25:27.594560 | 
2026-08-26 20:25:27.594636 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-08-26 20:25:27.964977 | controller | changed: Renamed files for staging.
2026-08-26 20:25:27.970865 | 
2026-08-26 20:25:27.970940 | TASK [stage-output : Discover log files for compression]
2026-08-26 20:25:27.997089 | controller | skipping: Conditional result was False
2026-08-26 20:25:28.010582 | 
2026-08-26 20:25:28.010668 | LOOP [stage-output : Archive everything from logs]
2026-08-26 20:25:28.050586 | 
2026-08-26 20:25:28.050734 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-08-26 20:25:28.835959 | controller | changed:
2026-08-26 20:25:28.836182 | controller | created directory /var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/work/logs/controller
2026-08-26 20:25:28.836222 | controller | cd+++++++++ logs/
2026-08-26 20:25:28.836251 | controller | >f+++++++++ logs/deprecations_log.txt
2026-08-26 20:25:28.836279 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-08-26 20:25:28.836305 | controller | >f+++++++++ logs/devstack.journal.gz
2026-08-26 20:25:28.836558 | controller | >f+++++++++ logs/df.txt
2026-08-26 20:25:28.836600 | controller | >f+++++++++ logs/dpkg-l.txt
2026-08-26 20:25:28.836629 | controller | >f+++++++++ logs/iptables.txt
2026-08-26 20:25:28.836656 | controller | >f+++++++++ logs/listen53.txt
2026-08-26 20:25:28.836682 | controller | >f+++++++++ logs/local_conf.txt
2026-08-26 20:25:28.836708 | controller | >f+++++++++ logs/mount.txt
2026-08-26 20:25:28.836733 | controller | >f+++++++++ logs/performance.json
2026-08-26 20:25:28.836758 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-08-26 20:25:28.836784 | controller | >f+++++++++ logs/resolv_conf.txt
2026-08-26 20:25:28.836809 | controller | >f+++++++++ logs/services.txt
2026-08-26 20:25:28.836841 | controller | >f+++++++++ logs/sudoers
2026-08-26 20:25:28.836867 | controller | >f+++++++++ logs/syslog.txt
2026-08-26 20:25:28.836892 | controller | cd+++++++++ logs/apache/
2026-08-26 20:25:28.836917 | controller | cd+++++++++ logs/apache_config/
2026-08-26 20:25:28.836942 | controller | cd+++++++++ logs/etc/
2026-08-26 20:25:28.837006 | controller | cd+++++++++ logs/sudoers.d/
2026-08-26 20:25:28.837038 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-08-26 20:25:28.837065 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-08-26 20:25:28.837090 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-08-26 20:25:28.837115 | controller | >f+++++++++ logs/sudoers.d/README
2026-08-26 20:25:28.837140 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-08-26 20:25:28.854759 | 
2026-08-26 20:25:28.860161 | TASK [Check if a tempest log exits]
2026-08-26 20:25:29.135965 | controller | ok
2026-08-26 20:25:29.142149 | 
2026-08-26 20:25:29.142216 | TASK [Link post-devstack tempest.log]
2026-08-26 20:25:29.166598 | controller | skipping: Conditional result was False
2026-08-26 20:25:29.177368 | 
2026-08-26 20:25:29.177463 | TASK [Capture most recent qemu crash dump, if any]
2026-08-26 20:25:29.469657 | controller | /bin/bash: line 1: coredumpctl: command not found
2026-08-26 20:25:29.727606 | controller | ERROR
2026-08-26 20:25:29.727991 | controller | {
2026-08-26 20:25:29.728059 | controller |   "delta": "0:00:00.009414",
2026-08-26 20:25:29.728104 | controller |   "end": "2026-08-26 20:25:29.470390",
2026-08-26 20:25:29.728147 | controller |   "msg": "non-zero return code",
2026-08-26 20:25:29.728187 | controller |   "rc": 127,
2026-08-26 20:25:29.728226 | controller |   "start": "2026-08-26 20:25:29.460976"
2026-08-26 20:25:29.728264 | controller | }
2026-08-26 20:25:29.728316 | controller | ERROR: Ignoring Errors
2026-08-26 20:25:29.739350 | 
2026-08-26 20:25:29.739446 | TASK [Collect Guru Meditation Reports from OpenStack services]
2026-08-26 20:25:30.281664 | controller | ERROR
2026-08-26 20:25:30.281972 | controller | {
2026-08-26 20:25:30.282026 | controller |   "delta": "0:00:00.084893",
2026-08-26 20:25:30.282055 | controller |   "end": "2026-08-26 20:25:30.105863",
2026-08-26 20:25:30.282080 | controller |   "msg": "non-zero return code",
2026-08-26 20:25:30.282105 | controller |   "rc": -12,
2026-08-26 20:25:30.282129 | controller |   "start": "2026-08-26 20:25:30.020970"
2026-08-26 20:25:30.282166 | controller | }
2026-08-26 20:25:30.282199 | controller | ERROR: Ignoring Errors
2026-08-26 20:25:30.284140 | 
2026-08-26 20:25:30.284206 | PLAY RECAP
2026-08-26 20:25:30.284270 | controller | ok: 27 changed: 18 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 3
2026-08-26 20:25:30.284299 | 
2026-08-26 20:25:30.455039 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-08-26 20:25:30.479188 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-08-26 20:25:31.461607 | 
2026-08-26 20:25:31.461759 | PLAY [all]
2026-08-26 20:25:31.483144 | 
2026-08-26 20:25:31.483268 | TASK [fetch-output : Set log path for multiple nodes]
2026-08-26 20:25:31.530518 | controller | skipping: Conditional result was False
2026-08-26 20:25:31.555859 | 
2026-08-26 20:25:31.555953 | TASK [fetch-output : Set log path for single node]
2026-08-26 20:25:31.601984 | controller | ok
2026-08-26 20:25:31.607530 | 
2026-08-26 20:25:31.607610 | LOOP [fetch-output : Ensure local output dirs]
2026-08-26 20:25:32.147413 | controller -> localhost | ok: "/var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/work/logs"
2026-08-26 20:25:32.397195 | controller -> localhost | changed: "/var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/work/artifacts"
2026-08-26 20:25:32.674368 | controller -> localhost | changed: "/var/lib/zuul/builds/efa6f9b3ccfd46c8aec7692f2daa04bf/work/docs"
2026-08-26 20:25:32.691702 | 
2026-08-26 20:25:32.691858 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-08-26 20:25:33.520772 | controller | changed: .d..t...... ./
2026-08-26 20:25:33.521051 | controller | changed: All items complete
2026-08-26 20:25:33.521091 | 
2026-08-26 20:25:34.013334 | controller | changed: .d..t...... ./
2026-08-26 20:25:34.533195 | controller | changed: .d..t...... ./
2026-08-26 20:25:34.567626 | 
2026-08-26 20:25:34.567767 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-08-26 20:25:35.029794 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.027258
2026-08-26 20:25:35.267407 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009458
2026-08-26 20:25:35.290135 | 
2026-08-26 20:25:35.290259 | PLAY [all]
2026-08-26 20:25:35.297093 | 
2026-08-26 20:25:35.297159 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-08-26 20:25:36.235162 | controller | changed
2026-08-26 20:25:36.243505 | 
2026-08-26 20:25:36.244755 | PLAY RECAP
2026-08-26 20:25:36.244810 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-08-26 20:25:36.244832 | 
2026-08-26 20:25:36.439123 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-08-26 20:25:36.452264 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-08-26 20:25:37.113100 | 
2026-08-26 20:25:37.113271 | PLAY [localhost]
2026-08-26 20:25:37.125936 | 
2026-08-26 20:25:37.129404 | TASK [Generate Zuul manifest]
2026-08-26 20:25:37.151964 | localhost | ok
2026-08-26 20:25:37.200063 | 
2026-08-26 20:25:37.200312 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-08-26 20:25:37.589309 | localhost | changed
2026-08-26 20:25:37.601219 | 
2026-08-26 20:25:37.601300 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-08-26 20:25:37.635073 | localhost | ok
2026-08-26 20:25:37.643983 | 
2026-08-26 20:25:37.644053 | TASK [Upload logs]
2026-08-26 20:25:37.666771 | localhost | ok
2026-08-26 20:25:37.793918 | 
2026-08-26 20:25:37.889666 | TASK [Set zuul-log-path fact]
2026-08-26 20:25:37.916749 | localhost | ok
2026-08-26 20:25:37.940361 | 
2026-08-26 20:25:37.940464 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-08-26 20:25:37.971511 | localhost | ok
2026-08-26 20:25:37.980018 | 
2026-08-26 20:25:37.980085 | TASK [upload-logs : Create log directories]
2026-08-26 20:25:38.380743 | localhost | changed
2026-08-26 20:25:38.386642 | 
2026-08-26 20:25:38.386715 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-08-26 20:25:38.805389 | localhost -> localhost | ok: Runtime: 0:00:00.004678
2026-08-26 20:25:38.811798 | 
2026-08-26 20:25:38.811867 | TASK [upload-logs : Upload logs to log server]
2026-08-26 20:25:39.254735 | localhost | Output suppressed because no_log was given
2026-08-26 20:25:39.260918 | 
2026-08-26 20:25:39.261040 | LOOP [upload-logs : Compress console log and json output]
2026-08-26 20:25:39.312180 | localhost | skipping: Conditional result was False
2026-08-26 20:25:39.319640 | localhost | skipping: Conditional result was False
2026-08-26 20:25:39.331701 | 
2026-08-26 20:25:39.331889 | LOOP [upload-logs : Upload compressed console log and json output]
2026-08-26 20:25:39.378822 | localhost | skipping: Conditional result was False
2026-08-26 20:25:39.379719 | 
2026-08-26 20:25:39.382790 | localhost | skipping: Conditional result was False
2026-08-26 20:25:39.402003 | 
2026-08-26 20:25:39.402157 | LOOP [upload-logs : Upload console log and json output]