2026-10-11 00:56:04.465022 | Job console starting
2026-10-11 00:56:04.476430 | Updating git repos
2026-10-11 00:56:07.330427 | Cloning repos into workspace
2026-10-11 00:56:14.083014 | Restoring repo states
2026-10-11 00:56:15.109891 | Merging changes
2026-10-11 00:56:16.022999 | Checking out repos
2026-10-11 00:56:24.093938 | Preparing playbooks
2026-10-11 00:56:27.327948 | Running Ansible setup
2026-10-11 00:56:33.850051 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-10-11 00:56:34.403840 | 
2026-10-11 00:56:34.403976 | PLAY [localhost]
2026-10-11 00:56:34.410849 | 
2026-10-11 00:56:34.410916 | TASK [Gathering Facts]
2026-10-11 00:56:35.288423 | localhost | ok
2026-10-11 00:56:35.303191 | 
2026-10-11 00:56:35.303760 | TASK [Setup log path fact]
2026-10-11 00:56:35.336382 | localhost | ok
2026-10-11 00:56:35.356019 | 
2026-10-11 00:56:35.356104 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-10-11 00:56:35.385523 | localhost | ok
2026-10-11 00:56:35.396401 | 
2026-10-11 00:56:35.396587 | TASK [emit-job-header : Print job information]
2026-10-11 00:56:35.449051 | # Job Information
2026-10-11 00:56:35.449337 | Ansible Version: 2.16.18
2026-10-11 00:56:35.449540 | Job: magnum-cluster-api-hydrophone-v1.33.12-calico
2026-10-11 00:56:35.449607 | Pipeline: check
2026-10-11 00:56:35.449677 | Executor: 2d72f0692154
2026-10-11 00:56:35.449736 | Triggered by: https://github.com/vexxhost/magnum-cluster-api/pull/1130
2026-10-11 00:56:35.449801 | Event ID: d9ede7d0-c50d-11f1-809e-d0eeaebf697c
2026-10-11 00:56:35.455940 | 
2026-10-11 00:56:35.456077 | LOOP [emit-job-header : Print node information]
2026-10-11 00:56:35.570623 | localhost | ok:
2026-10-11 00:56:35.570918 | localhost | # Node Information
2026-10-11 00:56:35.570979 | localhost | Inventory Hostname: controller
2026-10-11 00:56:35.571117 | localhost | Hostname: np0000195157
2026-10-11 00:56:35.571179 | localhost | Username: zuul
2026-10-11 00:56:35.571247 | localhost | Distro: Ubuntu 24.04
2026-10-11 00:56:35.571302 | localhost | Provider: yul1
2026-10-11 00:56:35.571340 | localhost | Region: ca-ymq-1
2026-10-11 00:56:35.571393 | localhost | Label: ubuntu-noble-16
2026-10-11 00:56:35.571428 | localhost | Product Name: OpenStack Nova
2026-10-11 00:56:35.571463 | localhost | Interface IP: 162.253.55.212
2026-10-11 00:56:35.586749 | 
2026-10-11 00:56:35.586897 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-10-11 00:56:35.991557 | localhost -> localhost | changed
2026-10-11 00:56:36.000462 | 
2026-10-11 00:56:36.000626 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-10-11 00:56:37.016371 | localhost -> localhost | changed
2026-10-11 00:56:37.029029 | 
2026-10-11 00:56:37.029161 | PLAY [all]
2026-10-11 00:56:37.046936 | 
2026-10-11 00:56:37.047065 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-10-11 00:56:37.287391 | controller -> localhost | ok
2026-10-11 00:56:37.298805 | 
2026-10-11 00:56:37.299699 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-10-11 00:56:37.337263 | controller | ok
2026-10-11 00:56:37.362322 | controller | included: /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-10-11 00:56:37.384379 | 
2026-10-11 00:56:37.384468 | TASK [add-build-sshkey : Create Temp SSH key]
2026-10-11 00:56:39.047958 | controller -> localhost | Generating public/private rsa key pair.
2026-10-11 00:56:39.048203 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/work/de5bf56667bd40ed86bd48d488b2b61f_id_rsa
2026-10-11 00:56:39.048261 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/work/de5bf56667bd40ed86bd48d488b2b61f_id_rsa.pub
2026-10-11 00:56:39.048324 | controller -> localhost | The key fingerprint is:
2026-10-11 00:56:39.048366 | controller -> localhost | SHA256:Wj40x33ClYtZl0wA8iqvbwEi/B47jE9/LtCyaO/ImCE zuul-build-sshkey
2026-10-11 00:56:39.048424 | controller -> localhost | The key's randomart image is:
2026-10-11 00:56:39.048465 | controller -> localhost | +---[RSA 3072]----+
2026-10-11 00:56:39.048564 | controller -> localhost | |         . ..... |
2026-10-11 00:56:39.048752 | controller -> localhost | |          o   o..|
2026-10-11 00:56:39.048811 | controller -> localhost | |  .        .  +o.|
2026-10-11 00:56:39.048851 | controller -> localhost | |   o . . ..o = o |
2026-10-11 00:56:39.048889 | controller -> localhost | |    o o.S.o * o  |
2026-10-11 00:56:39.048925 | controller -> localhost | |     = *o+   o   |
2026-10-11 00:56:39.048962 | controller -> localhost | |E.  =.B o..      |
2026-10-11 00:56:39.048998 | controller -> localhost | |. =+o*...+       |
2026-10-11 00:56:39.049042 | controller -> localhost | | o.o++.o*o       |
2026-10-11 00:56:39.049080 | controller -> localhost | +----[SHA256]-----+
2026-10-11 00:56:39.049167 | controller -> localhost | ok: Runtime: 0:00:01.193147
2026-10-11 00:56:39.060445 | 
2026-10-11 00:56:39.060744 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-10-11 00:56:39.113710 | controller | ok
2026-10-11 00:56:39.137612 | controller | included: /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-10-11 00:56:39.150043 | 
2026-10-11 00:56:39.150131 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-10-11 00:56:39.173923 | controller | skipping: Conditional result was False
2026-10-11 00:56:39.184351 | 
2026-10-11 00:56:39.184478 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-10-11 00:56:39.740616 | controller | changed
2026-10-11 00:56:39.745261 | 
2026-10-11 00:56:39.745329 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-10-11 00:56:39.960295 | controller | ok
2026-10-11 00:56:39.971528 | 
2026-10-11 00:56:39.971682 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-10-11 00:56:40.621959 | controller | changed
2026-10-11 00:56:40.633027 | 
2026-10-11 00:56:40.633145 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-10-11 00:56:41.334813 | controller | changed
2026-10-11 00:56:41.340953 | 
2026-10-11 00:56:41.341028 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-10-11 00:56:41.364557 | controller | skipping: Conditional result was False
2026-10-11 00:56:41.375181 | 
2026-10-11 00:56:41.375356 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-10-11 00:56:41.728556 | controller -> localhost | changed
2026-10-11 00:56:41.749421 | 
2026-10-11 00:56:41.749565 | TASK [add-build-sshkey : Add back temp key]
2026-10-11 00:56:42.066254 | controller -> localhost | Identity added: /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/work/de5bf56667bd40ed86bd48d488b2b61f_id_rsa (zuul-build-sshkey)
2026-10-11 00:56:42.066628 | controller -> localhost | ok: Runtime: 0:00:00.014837
2026-10-11 00:56:42.074178 | 
2026-10-11 00:56:42.074242 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-10-11 00:56:42.391609 | controller | ok
2026-10-11 00:56:42.401503 | 
2026-10-11 00:56:42.401680 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-10-11 00:56:42.436405 | controller | skipping: Conditional result was False
2026-10-11 00:56:42.458735 | 
2026-10-11 00:56:42.458925 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-10-11 00:56:42.808912 | controller | ok
2026-10-11 00:56:42.820936 | 
2026-10-11 00:56:42.821057 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-10-11 00:57:16.020177 | controller | Output suppressed because no_log was given
2026-10-11 00:57:16.040629 | 
2026-10-11 00:57:16.040845 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-10-11 00:57:16.312412 | controller | ok: "logs"
2026-10-11 00:57:16.312934 | controller | ok: All items complete
2026-10-11 00:57:16.313014 | 
2026-10-11 00:57:16.508911 | controller | ok: "artifacts"
2026-10-11 00:57:16.727436 | controller | ok: "docs"
2026-10-11 00:57:16.753172 | 
2026-10-11 00:57:16.753693 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-10-11 00:57:17.017103 | controller | changed: "logs"
2026-10-11 00:57:17.243584 | controller | changed: "artifacts"
2026-10-11 00:57:17.457533 | controller | changed: "docs"
2026-10-11 00:57:17.478170 | 
2026-10-11 00:57:17.478369 | PLAY RECAP
2026-10-11 00:57:17.478460 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-10-11 00:57:17.478514 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-10-11 00:57:17.478557 | 
2026-10-11 00:57:17.617511 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-10-11 00:57:17.627302 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-10-11 00:57:18.305935 | 
2026-10-11 00:57:18.306067 | PLAY [all]
2026-10-11 00:57:18.321894 | 
2026-10-11 00:57:18.322028 | TASK [Fix the permissions of the zuul home directory]
2026-10-11 00:57:18.733511 | controller | changed
2026-10-11 00:57:18.744487 | 
2026-10-11 00:57:18.744673 | TASK [Gather minimum local MTU]
2026-10-11 00:57:18.832812 | controller | ok
2026-10-11 00:57:18.842234 | 
2026-10-11 00:57:18.842382 | TASK [Calculate external_bridge_mtu]
2026-10-11 00:57:18.899582 | controller | ok
2026-10-11 00:57:18.911578 | 
2026-10-11 00:57:18.911709 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-10-11 00:57:18.937552 | controller | skipping: Conditional result was False
2026-10-11 00:57:18.951338 | 
2026-10-11 00:57:18.951513 | TASK [configure-swap : Get ephemeral0 device node]
2026-10-11 00:57:24.001168 | controller | ok: Runtime: 0:00:00.010953
2026-10-11 00:57:24.013299 | 
2026-10-11 00:57:24.013517 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-10-11 00:57:24.040095 | controller | skipping: Conditional result was False
2026-10-11 00:57:24.056655 | 
2026-10-11 00:57:24.056909 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-10-11 00:57:24.093295 | controller | skipping: Conditional result was False
2026-10-11 00:57:24.108355 | 
2026-10-11 00:57:24.108534 | TASK [configure-swap : Setup swap file on root device]
2026-10-11 00:57:24.176808 | controller | ok
2026-10-11 00:57:24.202937 | controller | included: /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-10-11 00:57:24.214142 | 
2026-10-11 00:57:24.214276 | TASK [configure-swap : Calculate required swap]
2026-10-11 00:57:24.305478 | controller | ok
2026-10-11 00:57:24.342806 | 
2026-10-11 00:57:24.342928 | TASK [configure-swap : Get root filesystem]
2026-10-11 00:57:29.394517 | controller | ok: Runtime: 0:00:00.025591
2026-10-11 00:57:29.405381 | 
2026-10-11 00:57:29.405507 | TASK [configure-swap : Save root filesystem]
2026-10-11 00:57:29.439824 | controller | ok
2026-10-11 00:57:29.451299 | 
2026-10-11 00:57:29.451418 | TASK [configure-swap : Debug the root_filesystem variable]
2026-10-11 00:57:29.485353 | controller | ok:
2026-10-11 00:57:29.485570 | controller | {
2026-10-11 00:57:29.485620 | controller |   "root_filesystem": "ext4"
2026-10-11 00:57:29.485658 | controller | }
2026-10-11 00:57:29.495360 | 
2026-10-11 00:57:29.495481 | TASK [configure-swap : Create swap backing file]
2026-10-11 00:57:34.528713 | localhost | Timeout exception waiting for the logger. Please check connectivity to [162.253.55.212:19885]
2026-10-11 00:57:39.284319 | controller | ok: Runtime: 0:00:09.293164
2026-10-11 00:57:39.292916 | 
2026-10-11 00:57:39.293025 | TASK [configure-swap : Ensure swapfile perms]
2026-10-11 00:57:39.558898 | controller | changed
2026-10-11 00:57:39.673955 | 
2026-10-11 00:57:39.674084 | TASK [configure-swap : Make swapfile]
2026-10-11 00:57:44.712734 | localhost | Timeout exception waiting for the logger. Please check connectivity to [162.253.55.212:19885]
2026-10-11 00:58:25.578163 | controller | ok: Runtime: 0:00:45.563822
2026-10-11 00:58:25.588427 | 
2026-10-11 00:58:25.588576 | TASK [configure-swap : Write swap to fstab]
2026-10-11 00:58:26.009162 | controller | changed
2026-10-11 00:58:26.019744 | 
2026-10-11 00:58:26.019904 | TASK [configure-swap : Add all swap]
2026-10-11 00:58:31.071594 | controller | ok: Runtime: 0:00:00.014472
2026-10-11 00:58:31.081921 | 
2026-10-11 00:58:31.082044 | TASK [configure-swap : Debug the swap_required variable]
2026-10-11 00:58:31.128718 | controller | ok:
2026-10-11 00:58:31.129141 | controller | {
2026-10-11 00:58:31.129279 | controller |   "swap_required": "8192"
2026-10-11 00:58:31.129334 | controller | }
2026-10-11 00:58:31.142546 | 
2026-10-11 00:58:31.142683 | TASK [configure-swap : Set swappiness]
2026-10-11 00:58:31.605293 | controller | changed
2026-10-11 00:58:31.615195 | 
2026-10-11 00:58:31.615319 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-10-11 00:58:31.649358 | controller | ok:
2026-10-11 00:58:31.649563 | controller | {
2026-10-11 00:58:31.649612 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-10-11 00:58:31.649654 | controller | }
2026-10-11 00:58:31.669105 | 
2026-10-11 00:58:31.669245 | TASK [setup-stack-user : Create stack group]
2026-10-11 00:58:32.137449 | controller | changed
2026-10-11 00:58:32.147810 | 
2026-10-11 00:58:32.147982 | TASK [setup-stack-user : Create the stack user home folder]
2026-10-11 00:58:32.429278 | controller | changed
2026-10-11 00:58:32.439783 | 
2026-10-11 00:58:32.439908 | TASK [setup-stack-user : Create stack user]
2026-10-11 00:58:32.991931 | controller | changed
2026-10-11 00:58:33.002198 | 
2026-10-11 00:58:33.002318 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-10-11 00:58:33.281939 | controller | changed
2026-10-11 00:58:33.293039 | 
2026-10-11 00:58:33.293164 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-10-11 00:58:34.492991 | controller | changed
2026-10-11 00:58:34.502010 | 
2026-10-11 00:58:34.502089 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-10-11 00:58:34.831698 | controller | changed
2026-10-11 00:58:34.842157 | 
2026-10-11 00:58:34.842236 | TASK [setup-tempest-user : Create tempest group]
2026-10-11 00:58:35.161488 | controller | changed
2026-10-11 00:58:35.176418 | 
2026-10-11 00:58:35.176617 | TASK [setup-tempest-user : Create tempest user]
2026-10-11 00:58:35.574876 | controller | changed
2026-10-11 00:58:35.585299 | 
2026-10-11 00:58:35.585426 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-10-11 00:58:36.461434 | controller | changed
2026-10-11 00:58:36.482222 | 
2026-10-11 00:58:36.482349 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-10-11 00:58:36.848203 | controller | ok: Not all paths examined, check warnings for details
2026-10-11 00:58:36.863899 | 
2026-10-11 00:58:36.863984 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-10-11 00:58:37.507346 | controller | ok: Item: Runtime: 0:00:00.322704
2026-10-11 00:58:38.130952 | controller | ok: Item: Runtime: 0:00:00.366301
2026-10-11 00:58:38.708438 | controller | ok: Item: Runtime: 0:00:00.319964
2026-10-11 00:58:39.017146 | controller | ok: Item: Runtime: 0:00:00.066514
2026-10-11 00:58:39.632847 | controller | ok: Item: Runtime: 0:00:00.375635
2026-10-11 00:58:42.766689 | controller | ok: Item: Runtime: 0:00:02.883511
2026-10-11 00:58:43.181343 | controller | ok: Item: Runtime: 0:00:00.163802
2026-10-11 00:58:43.666497 | controller | ok: Item: Runtime: 0:00:00.245590
2026-10-11 00:58:44.138740 | controller | ok: Item: Runtime: 0:00:00.210624
2026-10-11 00:58:44.628055 | controller | ok: Item: Runtime: 0:00:00.246729
2026-10-11 00:58:45.354132 | controller | ok: Item: Runtime: 0:00:00.504519
2026-10-11 00:58:46.353988 | controller | ok: Item: Runtime: 0:00:00.746780
2026-10-11 00:58:47.187737 | controller | ok: Item: Runtime: 0:00:00.600099
2026-10-11 00:58:47.940110 | controller | ok: Item: Runtime: 0:00:00.508397
2026-10-11 00:58:49.574016 | controller | ok: Item: Runtime: 0:00:01.378707
2026-10-11 00:58:50.872687 | controller | ok: Item: Runtime: 0:00:01.071335
2026-10-11 00:58:50.911301 | 
2026-10-11 00:58:50.911456 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-10-11 00:58:51.154560 | controller | ok: All paths examined
2026-10-11 00:58:51.166995 | 
2026-10-11 00:58:51.167120 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-10-11 00:58:51.431593 | controller | ok: All paths examined
2026-10-11 00:58:51.440418 | 
2026-10-11 00:58:51.440527 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-10-11 00:58:51.960271 | controller | ok: Item: Runtime: 0:00:00.206048
2026-10-11 00:58:51.960693 | controller | changed: All items complete
2026-10-11 00:58:51.960768 | 
2026-10-11 00:58:52.424978 | controller | ok: Item: Runtime: 0:00:00.223553
2026-10-11 00:58:52.448435 | 
2026-10-11 00:58:52.448643 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-10-11 00:58:52.538840 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.555195 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.555829 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.560557 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.567641 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.575417 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.582005 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.586932 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.592205 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.596365 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.600579 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.604929 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.608648 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.611605 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.614587 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.617548 | controller | skipping: Conditional result was False
2026-10-11 00:58:52.691076 | 
2026-10-11 00:58:52.691217 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-10-11 00:58:55.362337 | controller | changed
2026-10-11 00:58:55.372171 | 
2026-10-11 00:58:55.372236 | TASK [setup-devstack-log-dir : Create logs directory]
2026-10-11 00:58:55.606085 | controller | changed
2026-10-11 00:58:55.618633 | 
2026-10-11 00:58:55.618694 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-10-11 00:59:00.659799 | controller | ERROR
2026-10-11 00:59:00.660075 | controller | {
2026-10-11 00:59:00.660121 | controller |   "delta": "0:00:00.026424",
2026-10-11 00:59:00.660163 | controller |   "end": "2026-10-11 00:58:55.931985",
2026-10-11 00:59:00.660195 | controller |   "msg": "non-zero return code",
2026-10-11 00:59:00.660221 | controller |   "rc": 1,
2026-10-11 00:59:00.660250 | controller |   "start": "2026-10-11 00:58:55.905561"
2026-10-11 00:59:00.660275 | controller | }
2026-10-11 00:59:00.660313 | controller | ERROR: Ignoring Errors
2026-10-11 00:59:00.667971 | 
2026-10-11 00:59:00.668123 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-10-11 00:59:00.952211 | controller | ok
2026-10-11 00:59:00.970905 | 
2026-10-11 00:59:00.971065 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-10-11 00:59:06.013486 | controller | ok: Runtime: 0:00:00.014546
2026-10-11 00:59:06.025405 | 
2026-10-11 00:59:06.025548 | TASK [start-fresh-logging : Get current date]
2026-10-11 00:59:11.082407 | controller | ok: Runtime: 0:00:00.010962
2026-10-11 00:59:11.093046 | 
2026-10-11 00:59:11.093181 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-10-11 00:59:11.713671 | controller | changed
2026-10-11 00:59:11.725811 | 
2026-10-11 00:59:11.725934 | TASK [start-fresh-logging : Stop rsyslog]
2026-10-11 00:59:11.752558 | controller | skipping: Conditional result was False
2026-10-11 00:59:11.764022 | 
2026-10-11 00:59:11.764172 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-10-11 00:59:11.818942 | controller | skipping: Conditional result was False
2026-10-11 00:59:11.830175 | 
2026-10-11 00:59:11.830311 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-10-11 00:59:11.880468 | controller | skipping: Conditional result was False
2026-10-11 00:59:11.887637 | 
2026-10-11 00:59:11.887720 | TASK [start-fresh-logging : Recreate syslog file]
2026-10-11 00:59:11.911291 | controller | skipping: Conditional result was False
2026-10-11 00:59:11.922006 | 
2026-10-11 00:59:11.922153 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-10-11 00:59:11.973474 | controller | skipping: Conditional result was False
2026-10-11 00:59:11.980453 | 
2026-10-11 00:59:11.980551 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-10-11 00:59:12.074119 | controller | skipping: Conditional result was False
2026-10-11 00:59:12.080404 | 
2026-10-11 00:59:12.080471 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-10-11 00:59:12.105263 | controller | skipping: Conditional result was False
2026-10-11 00:59:12.112870 | 
2026-10-11 00:59:12.112955 | TASK [start-fresh-logging : Recreate kern.log file]
2026-10-11 00:59:12.137160 | controller | skipping: Conditional result was False
2026-10-11 00:59:12.145363 | 
2026-10-11 00:59:12.145447 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-10-11 00:59:12.185320 | controller | skipping: Conditional result was False
2026-10-11 00:59:12.192577 | 
2026-10-11 00:59:12.192667 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-10-11 00:59:12.236657 | controller | skipping: Conditional result was False
2026-10-11 00:59:12.243741 | 
2026-10-11 00:59:12.243818 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-10-11 00:59:12.267355 | controller | skipping: Conditional result was False
2026-10-11 00:59:12.274402 | 
2026-10-11 00:59:12.274483 | TASK [start-fresh-logging : Start rsyslog]
2026-10-11 00:59:12.298291 | controller | skipping: Conditional result was False
2026-10-11 00:59:12.316845 | 
2026-10-11 00:59:12.316929 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-10-11 00:59:12.777850 | controller | ok
2026-10-11 00:59:12.795548 | 
2026-10-11 00:59:12.795676 | PLAY RECAP
2026-10-11 00:59:12.795762 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-10-11 00:59:12.795802 | 
2026-10-11 00:59:13.053966 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-10-11 00:59:13.063099 | PRE-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-10-11 00:59:13.700680 | 
2026-10-11 00:59:13.700809 | PLAY [all]
2026-10-11 00:59:13.711934 | 
2026-10-11 00:59:13.712006 | TASK [Install curl]
2026-10-11 00:59:20.800459 | controller | ok
2026-10-11 00:59:20.810744 | 
2026-10-11 00:59:20.810898 | TASK [ensure-rust : Use rustup]
2026-10-11 00:59:20.848136 | controller | ok
2026-10-11 00:59:20.862459 | controller | included: /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/ensure-rust/tasks/rustup.yaml
2026-10-11 00:59:20.872740 | 
2026-10-11 00:59:20.872866 | TASK [ensure-rust : Install Rust]
2026-10-11 00:59:25.907053 | localhost | Timeout exception waiting for the logger. Please check connectivity to [162.253.55.212:19885]
2026-10-11 00:59:35.783497 | controller | ok: Runtime: 0:00:14.404930
2026-10-11 00:59:35.794904 | 
2026-10-11 00:59:35.794982 | TASK [ensure-rust : Install wrapper helper script]
2026-10-11 00:59:36.800909 | controller | changed
2026-10-11 00:59:36.811205 | 
2026-10-11 00:59:36.811336 | TASK [ensure-rust : Run wrapper installation]
2026-10-11 00:59:41.857334 | controller | ok: Runtime: 0:00:00.113565
2026-10-11 00:59:41.867711 | 
2026-10-11 00:59:41.867838 | TASK [ensure-rust : Install packages]
2026-10-11 00:59:41.892796 | controller | skipping: Conditional result was False
2026-10-11 00:59:41.941680 | 
2026-10-11 00:59:41.941794 | PLAY RECAP
2026-10-11 00:59:41.941842 | controller | ok: 5 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-10-11 00:59:41.941868 | 
2026-10-11 00:59:42.044998 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-10-11 00:59:42.078953 | RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/run.yml@main]
2026-10-11 00:59:42.675923 | 
2026-10-11 00:59:42.676041 | PLAY [all]
2026-10-11 00:59:42.686367 | 
2026-10-11 00:59:42.686437 | TASK [Install DevStack]
2026-10-11 00:59:42.705626 | controller | ok
2026-10-11 00:59:42.731384 | 
2026-10-11 00:59:42.731455 | TASK [Run devstack on the controller]
2026-10-11 00:59:42.760565 | controller | ok
2026-10-11 00:59:42.778094 | 
2026-10-11 00:59:42.778167 | TASK [run-devstack : Run devstack]
2026-10-11 00:59:47.802824 | localhost | Timeout exception waiting for the logger. Please check connectivity to [162.253.55.212:19885]
2026-10-11 01:01:53.284107 | controller | ERROR
2026-10-11 01:01:53.284404 | controller | {
2026-10-11 01:01:53.284460 | controller |   "delta": "0:00:10.290307",
2026-10-11 01:01:53.284513 | controller |   "end": "2026-10-11 01:01:53.203943",
2026-10-11 01:01:53.284570 | controller |   "msg": "non-zero return code",
2026-10-11 01:01:53.284621 | controller |   "rc": 100,
2026-10-11 01:01:53.284674 | controller |   "start": "2026-10-11 01:01:42.913636"
2026-10-11 01:01:53.284711 | controller | }
failure
2026-10-11 01:01:53.300075 | 
2026-10-11 01:01:53.300196 | PLAY RECAP
2026-10-11 01:01:53.300257 | controller | ok: 0 changed: 0 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-10-11 01:01:53.300288 | 
2026-10-11 01:01:53.461991 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/run.yml@main]
2026-10-11 01:01:53.471489 | POST-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-10-11 01:01:54.047810 | 
2026-10-11 01:01:54.048448 | PLAY [all]
2026-10-11 01:01:54.059084 | 
2026-10-11 01:01:54.059173 | LOOP [Copy individual Hydrophone result files]
2026-10-11 01:01:54.755613 | controller | ERROR: Item: e2e.log
2026-10-11 01:01:54.756977 | controller | {
2026-10-11 01:01:54.757132 | controller |   "ansible_loop_var": "item",
2026-10-11 01:01:54.757218 | controller |   "item": "e2e.log",
2026-10-11 01:01:54.757362 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/e2e.log not found"
2026-10-11 01:01:54.757430 | controller | }
2026-10-11 01:01:55.048060 | controller | ERROR: Item: junit_01.xml
2026-10-11 01:01:55.048281 | controller | {
2026-10-11 01:01:55.048353 | controller |   "ansible_loop_var": "item",
2026-10-11 01:01:55.048398 | controller |   "item": "junit_01.xml",
2026-10-11 01:01:55.048438 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/junit_01.xml not found"
2026-10-11 01:01:55.048477 | controller | }
2026-10-11 01:01:55.065984 | controller | ERROR: Ignoring Errors
2026-10-11 01:01:55.077483 | 
2026-10-11 01:01:55.077635 | TASK [Copy Hydrophone results tarball to output folder]
2026-10-11 01:01:55.401902 | controller | ERROR
2026-10-11 01:01:55.402135 | controller | {
2026-10-11 01:01:55.402171 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results.tar.gz not found"
2026-10-11 01:01:55.402196 | controller | }
2026-10-11 01:01:55.402226 | controller | ERROR: Ignoring Errors
2026-10-11 01:01:55.412900 | 
2026-10-11 01:01:55.412966 | TASK [Return built artifacts to Zuul]
2026-10-11 01:01:55.442539 | controller | ok
2026-10-11 01:01:55.449603 | 
2026-10-11 01:01:55.449683 | TASK [Get the Docker volume ID]
2026-10-11 01:01:55.994521 | controller | ERROR
2026-10-11 01:01:55.994891 | controller | {
2026-10-11 01:01:55.994950 | controller |   "msg": "[Errno 2] No such file or directory: b'docker'",
2026-10-11 01:01:55.995011 | controller |   "rc": 2
2026-10-11 01:01:55.995065 | controller | }
2026-10-11 01:01:55.995137 | controller | ERROR: Ignoring Errors
2026-10-11 01:01:56.006762 | 
2026-10-11 01:01:56.006909 | TASK [Copy all of the pod logs]
2026-10-11 01:01:56.043963 | controller | ERROR
2026-10-11 01:01:56.044382 | controller | {
2026-10-11 01:01:56.044468 | 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/de5bf56667bd40ed86bd48d488b2b61f/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-10-11 01:01:56.044578 | controller | }
2026-10-11 01:01:56.044649 | controller | ERROR: Ignoring Errors
2026-10-11 01:01:56.046369 | 
2026-10-11 01:01:56.046466 | PLAY RECAP
2026-10-11 01:01:56.046552 | controller | ok: 5 changed: 0 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 4
2026-10-11 01:01:56.046603 | 
2026-10-11 01:01:56.189667 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-10-11 01:01:56.198308 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-10-11 01:01:56.822609 | 
2026-10-11 01:01:56.822817 | PLAY [all]
2026-10-11 01:01:56.844155 | 
2026-10-11 01:01:56.844270 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-10-11 01:01:57.466874 | controller | changed
2026-10-11 01:01:57.479114 | 
2026-10-11 01:01:57.479363 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-10-11 01:01:58.537265 | controller | ok: Runtime: 0:00:00.538145
2026-10-11 01:01:58.548213 | 
2026-10-11 01:01:58.548427 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-10-11 01:01:59.098413 | controller | ok: Runtime: 0:00:00.026592
2026-10-11 01:01:59.108901 | 
2026-10-11 01:01:59.109142 | TASK [export-devstack-journal : Export journal]
2026-10-11 01:01:59.711245 | controller | ok: Runtime: 0:00:00.042767
2026-10-11 01:01:59.719099 | 
2026-10-11 01:01:59.719208 | TASK [export-devstack-journal : Save journal README]
2026-10-11 01:02:00.615276 | controller | changed
2026-10-11 01:02:00.636317 | 
2026-10-11 01:02:00.636468 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-10-11 01:02:00.899588 | controller | changed
2026-10-11 01:02:00.909921 | 
2026-10-11 01:02:00.910074 | TASK [apache-logs-conf : Find logs]
2026-10-11 01:02:01.256264 | controller | Output suppressed because no_log was given
2026-10-11 01:02:01.266120 | 
2026-10-11 01:02:01.266250 | LOOP [apache-logs-conf : Dereference files]
2026-10-11 01:02:02.067895 | controller | Output suppressed because no_log was given
2026-10-11 01:02:02.075486 | 
2026-10-11 01:02:02.075575 | LOOP [apache-logs-conf : Create hard links]
2026-10-11 01:02:02.905092 | controller | Output suppressed because no_log was given
2026-10-11 01:02:02.909653 | 
2026-10-11 01:02:02.909710 | TASK [apache-logs-conf : Find logs]
2026-10-11 01:02:02.938179 | 
2026-10-11 01:02:02.938290 | LOOP [apache-logs-conf : Dereference files]
2026-10-11 01:02:02.967530 | 
2026-10-11 01:02:02.967846 | LOOP [apache-logs-conf : Create hard links]
2026-10-11 01:02:02.990217 | 
2026-10-11 01:02:02.990362 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-10-11 01:02:03.275530 | controller | changed
2026-10-11 01:02:03.286214 | 
2026-10-11 01:02:03.286341 | TASK [apache-logs-conf : Define config paths]
2026-10-11 01:02:03.322283 | controller | ok
2026-10-11 01:02:03.331785 | 
2026-10-11 01:02:03.331906 | TASK [apache-logs-conf : Discover configurations]
2026-10-11 01:02:03.599016 | controller | Output suppressed because no_log was given
2026-10-11 01:02:03.608693 | 
2026-10-11 01:02:03.608817 | LOOP [apache-logs-conf : Dereference configurations]
2026-10-11 01:02:03.907332 | controller | Output suppressed because no_log was given
2026-10-11 01:02:03.918425 | 
2026-10-11 01:02:03.918548 | LOOP [apache-logs-conf : Link configurations]
2026-10-11 01:02:04.231823 | controller | Output suppressed because no_log was given
2026-10-11 01:02:04.251428 | 
2026-10-11 01:02:04.251557 | TASK [capture-performance-data : Generate statistics]
2026-10-11 01:02:06.969906 | controller | No psutil, process information will not be included
2026-10-11 01:02:06.970039 | controller | No pymysql, database information will not be included
2026-10-11 01:02:07.298864 | controller | ok: Runtime: 0:00:02.454824
2026-10-11 01:02:07.315777 | 
2026-10-11 01:02:07.315866 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-10-11 01:02:07.591064 | controller | changed
2026-10-11 01:02:07.603326 | 
2026-10-11 01:02:07.603427 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-10-11 01:02:11.817303 | controller | Output suppressed because no_log was given
2026-10-11 01:02:11.830283 | 
2026-10-11 01:02:11.830423 | LOOP [devstack-project-conf : Copy configuration files]
2026-10-11 01:02:11.873692 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.874134 | 
2026-10-11 01:02:11.878204 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.881745 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.885300 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.889146 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.891910 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.895487 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.898926 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.902241 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.905444 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.907802 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.910304 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.912637 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.914937 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.917331 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.919852 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.922277 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.924661 | controller | skipping: Conditional result was False
2026-10-11 01:02:11.960261 | 
2026-10-11 01:02:11.960450 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-10-11 01:02:12.223445 | controller | ok
2026-10-11 01:02:12.232799 | 
2026-10-11 01:02:12.232969 | TASK [devstack-project-conf : Copy configuration files]
2026-10-11 01:02:12.769790 | controller | skipping: Conditional result was False
2026-10-11 01:02:12.779495 | 
2026-10-11 01:02:12.779679 | TASK [capture-system-logs : Stage various logs and reports]
2026-10-11 01:02:15.316061 | controller | ok: Runtime: 0:00:01.832609
2026-10-11 01:02:15.336402 | 
2026-10-11 01:02:15.336759 | LOOP [stage-output : Register sources]
2026-10-11 01:02:25.815111 | controller | Output suppressed because no_log was given
2026-10-11 01:02:25.829597 | 
2026-10-11 01:02:25.829759 | TASK [stage-output : Check sudo]
2026-10-11 01:02:26.382237 | controller | ok: Runtime: 0:00:00.021707
2026-10-11 01:02:26.393081 | 
2026-10-11 01:02:26.393216 | LOOP [stage-output : Set source and destination for files and folders]
2026-10-11 01:02:26.507587 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.508085 | 
2026-10-11 01:02:26.510574 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.511705 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.567436 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.568269 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.569056 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.569512 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.569919 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.577062 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.577511 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.597209 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.603247 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.603689 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.604118 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.622826 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.623599 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.624458 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.656436 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.657305 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.722249 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.732801 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.743675 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.753681 | controller | Output suppressed because no_log was given
2026-10-11 01:02:26.763329 | 
2026-10-11 01:02:26.763405 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-10-11 01:02:26.849536 | controller | ok
2026-10-11 01:02:26.864031 | 
2026-10-11 01:02:26.864172 | LOOP [stage-output : Ensure target folders exist]
2026-10-11 01:02:27.151149 | controller | changed: "docs"
2026-10-11 01:02:27.424209 | controller | changed: "artifacts"
2026-10-11 01:02:27.677749 | controller | ok: "logs"
2026-10-11 01:02:27.691601 | 
2026-10-11 01:02:27.691734 | LOOP [stage-output : Copy files and folders to staging folder]
2026-10-11 01:02:28.084472 | controller | ok: Item: Runtime: 0:00:00.006190
2026-10-11 01:02:28.084694 | controller | changed: All items complete
2026-10-11 01:02:28.084728 | 
2026-10-11 01:02:28.304358 | controller | ok: Item: Runtime: 0:00:00.008167
2026-10-11 01:02:28.568282 | controller | ok: Item: Runtime: 0:00:00.008403
2026-10-11 01:02:28.823714 | controller | ok: Item: Runtime: 0:00:00.005773
2026-10-11 01:02:29.072802 | controller | ok: Item: Runtime: 0:00:00.008592
2026-10-11 01:02:29.335727 | controller | ok: Item: Runtime: 0:00:00.008821
2026-10-11 01:02:29.616405 | controller | ok: Item: Runtime: 0:00:00.007561
2026-10-11 01:02:29.850498 | controller | ok: Item: Runtime: 0:00:00.008303
2026-10-11 01:02:30.096411 | controller | ok: Item: Runtime: 0:00:00.008398
2026-10-11 01:02:30.361812 | controller | ok: Item: Runtime: 0:00:00.008437
2026-10-11 01:02:30.589769 | controller | ok: Item: Runtime: 0:00:00.006450
2026-10-11 01:02:30.825611 | controller | ok: Item: Runtime: 0:00:00.008094
2026-10-11 01:02:31.083432 | controller | ok: Item: Runtime: 0:00:00.008616
2026-10-11 01:02:31.348056 | controller | ok: Item: Runtime: 0:00:00.008550
2026-10-11 01:02:31.608003 | controller | ok: Item: Runtime: 0:00:00.008409
2026-10-11 01:02:31.860784 | controller | ok: Item: Runtime: 0:00:00.008639
2026-10-11 01:02:32.118281 | controller | ok: Item: Runtime: 0:00:00.008097
2026-10-11 01:02:32.372318 | controller | ok: Item: Runtime: 0:00:00.009984
2026-10-11 01:02:32.605814 | controller | ok: Item: Runtime: 0:00:00.008606
2026-10-11 01:02:32.865246 | controller | ok: Item: Runtime: 0:00:00.008299
2026-10-11 01:02:33.124458 | controller | ok: Item: Runtime: 0:00:00.009300
2026-10-11 01:02:33.381762 | controller | ok: Item: Runtime: 0:00:00.008753
2026-10-11 01:02:33.423198 | 
2026-10-11 01:02:33.423425 | TASK [stage-output : Make all log files readable]
2026-10-11 01:02:33.701454 | controller | changed
2026-10-11 01:02:33.716101 | 
2026-10-11 01:02:33.716229 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-10-11 01:02:34.117438 | controller | changed: Renamed files for staging.
2026-10-11 01:02:34.128470 | 
2026-10-11 01:02:34.128663 | TASK [stage-output : Discover log files for compression]
2026-10-11 01:02:34.156186 | controller | skipping: Conditional result was False
2026-10-11 01:02:34.168677 | 
2026-10-11 01:02:34.168810 | LOOP [stage-output : Archive everything from logs]
2026-10-11 01:02:34.217780 | 
2026-10-11 01:02:34.218010 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-10-11 01:02:34.876858 | controller | changed:
2026-10-11 01:02:34.877088 | controller | created directory /var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/work/logs/controller
2026-10-11 01:02:34.877135 | controller | cd+++++++++ logs/
2026-10-11 01:02:34.877160 | controller | >f+++++++++ logs/_.localrc_auto.txt
2026-10-11 01:02:34.877178 | controller | >f+++++++++ logs/deprecations_log.txt
2026-10-11 01:02:34.877214 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-10-11 01:02:34.877235 | controller | >f+++++++++ logs/devstack.journal.gz
2026-10-11 01:02:34.877252 | controller | >f+++++++++ logs/devstacklog.txt
2026-10-11 01:02:34.877268 | controller | >f+++++++++ logs/devstacklog.txt.summary
2026-10-11 01:02:34.877308 | controller | >f+++++++++ logs/df.txt
2026-10-11 01:02:34.877325 | controller | >f+++++++++ logs/dpkg-l.txt
2026-10-11 01:02:34.877341 | controller | >f+++++++++ logs/iptables.txt
2026-10-11 01:02:34.877378 | controller | >f+++++++++ logs/listen53.txt
2026-10-11 01:02:34.877584 | controller | >f+++++++++ logs/local_conf.txt
2026-10-11 01:02:34.877613 | controller | >f+++++++++ logs/mount.txt
2026-10-11 01:02:34.877630 | controller | >f+++++++++ logs/performance.json
2026-10-11 01:02:34.877667 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-10-11 01:02:34.877686 | controller | >f+++++++++ logs/resolv_conf.txt
2026-10-11 01:02:34.877702 | controller | >f+++++++++ logs/services.txt
2026-10-11 01:02:34.877735 | controller | >f+++++++++ logs/sudoers
2026-10-11 01:02:34.877756 | controller | >f+++++++++ logs/syslog.txt
2026-10-11 01:02:34.877772 | controller | >f+++++++++ logs/worlddump-latest.txt
2026-10-11 01:02:34.877788 | controller | cd+++++++++ logs/apache/
2026-10-11 01:02:34.877837 | controller | >f+++++++++ logs/apache/access_log.txt
2026-10-11 01:02:34.877861 | controller | >f+++++++++ logs/apache/error_log.txt
2026-10-11 01:02:34.877898 | controller | >f+++++++++ logs/apache/other_vhosts_access_log.txt
2026-10-11 01:02:34.877918 | controller | cd+++++++++ logs/apache_config/
2026-10-11 01:02:34.877935 | controller | >f+++++++++ logs/apache_config/000-default_conf.txt
2026-10-11 01:02:34.877982 | controller | cd+++++++++ logs/etc/
2026-10-11 01:02:34.878003 | controller | cd+++++++++ logs/lvm/
2026-10-11 01:02:34.878020 | controller | >f+++++++++ logs/lvm/lvm_conf.txt
2026-10-11 01:02:34.878036 | controller | >f+++++++++ logs/lvm/lvmlocal_conf.txt
2026-10-11 01:02:34.878051 | controller | cd+++++++++ logs/lvm/profile/
2026-10-11 01:02:34.878067 | controller | >f+++++++++ logs/lvm/profile/cache-mq.profile
2026-10-11 01:02:34.878083 | controller | >f+++++++++ logs/lvm/profile/cache-smq.profile
2026-10-11 01:02:34.878099 | controller | >f+++++++++ logs/lvm/profile/command_profile_template.profile
2026-10-11 01:02:34.878114 | controller | >f+++++++++ logs/lvm/profile/lvmdbusd.profile
2026-10-11 01:02:34.878130 | controller | >f+++++++++ logs/lvm/profile/metadata_profile_template.profile
2026-10-11 01:02:34.878146 | controller | >f+++++++++ logs/lvm/profile/thin-generic.profile
2026-10-11 01:02:34.878177 | controller | >f+++++++++ logs/lvm/profile/thin-performance.profile
2026-10-11 01:02:34.878195 | controller | >f+++++++++ logs/lvm/profile/vdo-small.profile
2026-10-11 01:02:34.878211 | controller | cd+++++++++ logs/postgresql/
2026-10-11 01:02:34.878226 | controller | cd+++++++++ logs/sudoers.d/
2026-10-11 01:02:34.878242 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-10-11 01:02:34.878258 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-10-11 01:02:34.878274 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-10-11 01:02:34.878289 | controller | >f+++++++++ logs/sudoers.d/README
2026-10-11 01:02:34.878305 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-10-11 01:02:34.887205 | 
2026-10-11 01:02:34.887264 | TASK [Check if a tempest log exits]
2026-10-11 01:02:35.170746 | controller | ok
2026-10-11 01:02:35.178567 | 
2026-10-11 01:02:35.178648 | TASK [Link post-devstack tempest.log]
2026-10-11 01:02:35.202298 | controller | skipping: Conditional result was False
2026-10-11 01:02:35.253426 | 
2026-10-11 01:02:35.253556 | TASK [Capture most recent qemu crash dump, if any]
2026-10-11 01:02:35.535516 | controller | /bin/bash: line 1: coredumpctl: command not found
2026-10-11 01:02:35.793483 | controller | ERROR
2026-10-11 01:02:35.793818 | controller | {
2026-10-11 01:02:35.793860 | controller |   "delta": "0:00:00.007977",
2026-10-11 01:02:35.793887 | controller |   "end": "2026-10-11 01:02:35.536432",
2026-10-11 01:02:35.793911 | controller |   "msg": "non-zero return code",
2026-10-11 01:02:35.793934 | controller |   "rc": 127,
2026-10-11 01:02:35.793958 | controller |   "start": "2026-10-11 01:02:35.528455"
2026-10-11 01:02:35.793996 | controller | }
2026-10-11 01:02:35.794027 | controller | ERROR: Ignoring Errors
2026-10-11 01:02:35.800520 | 
2026-10-11 01:02:35.800613 | TASK [Collect Guru Meditation Reports from OpenStack services]
2026-10-11 01:02:36.341179 | controller | ERROR
2026-10-11 01:02:36.341689 | controller | {
2026-10-11 01:02:36.341733 | controller |   "delta": "0:00:00.095058",
2026-10-11 01:02:36.341761 | controller |   "end": "2026-10-11 01:02:36.186879",
2026-10-11 01:02:36.341785 | controller |   "msg": "non-zero return code",
2026-10-11 01:02:36.341808 | controller |   "rc": -12,
2026-10-11 01:02:36.341831 | controller |   "start": "2026-10-11 01:02:36.091821"
2026-10-11 01:02:36.341854 | controller | }
2026-10-11 01:02:36.341887 | controller | ERROR: Ignoring Errors
2026-10-11 01:02:36.352183 | 
2026-10-11 01:02:36.352669 | PLAY RECAP
2026-10-11 01:02:36.353164 | controller | ok: 31 changed: 20 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 2
2026-10-11 01:02:36.353330 | 
2026-10-11 01:02:36.531443 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-10-11 01:02:36.541978 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-10-11 01:02:37.132792 | 
2026-10-11 01:02:37.132912 | PLAY [all]
2026-10-11 01:02:37.143126 | 
2026-10-11 01:02:37.143200 | TASK [fetch-output : Set log path for multiple nodes]
2026-10-11 01:02:37.206926 | controller | skipping: Conditional result was False
2026-10-11 01:02:37.214689 | 
2026-10-11 01:02:37.214789 | TASK [fetch-output : Set log path for single node]
2026-10-11 01:02:37.277780 | controller | ok
2026-10-11 01:02:37.287190 | 
2026-10-11 01:02:37.287323 | LOOP [fetch-output : Ensure local output dirs]
2026-10-11 01:02:37.667517 | controller -> localhost | ok: "/var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/work/logs"
2026-10-11 01:02:37.900996 | controller -> localhost | changed: "/var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/work/artifacts"
2026-10-11 01:02:38.155801 | controller -> localhost | changed: "/var/lib/zuul/builds/de5bf56667bd40ed86bd48d488b2b61f/work/docs"
2026-10-11 01:02:38.179166 | 
2026-10-11 01:02:38.179360 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-10-11 01:02:38.897209 | controller | changed: .d..t...... ./
2026-10-11 01:02:38.897557 | controller | changed: All items complete
2026-10-11 01:02:38.897610 | 
2026-10-11 01:02:39.404661 | controller | changed: .d..t...... ./
2026-10-11 01:02:39.946691 | controller | changed: .d..t...... ./
2026-10-11 01:02:39.973938 | 
2026-10-11 01:02:39.974089 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-10-11 01:02:40.448405 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006553
2026-10-11 01:02:40.685440 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008413
2026-10-11 01:02:40.705464 | 
2026-10-11 01:02:40.705573 | PLAY [all]
2026-10-11 01:02:40.717400 | 
2026-10-11 01:02:40.717530 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-10-11 01:02:41.411121 | controller | changed
2026-10-11 01:02:41.421536 | 
2026-10-11 01:02:41.421629 | PLAY RECAP
2026-10-11 01:02:41.421710 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-10-11 01:02:41.421750 | 
2026-10-11 01:02:41.541225 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-10-11 01:02:41.551276 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-10-11 01:02:42.175761 | 
2026-10-11 01:02:42.175877 | PLAY [localhost]
2026-10-11 01:02:42.184735 | 
2026-10-11 01:02:42.184801 | TASK [Generate Zuul manifest]
2026-10-11 01:02:42.201219 | localhost | ok
2026-10-11 01:02:42.215126 | 
2026-10-11 01:02:42.215198 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-10-11 01:02:42.601132 | localhost | changed
2026-10-11 01:02:42.621763 | 
2026-10-11 01:02:42.621910 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-10-11 01:02:42.652347 | localhost | ok
2026-10-11 01:02:42.664644 | 
2026-10-11 01:02:42.664774 | TASK [Upload logs]
2026-10-11 01:02:42.684860 | localhost | ok
2026-10-11 01:02:42.790742 | 
2026-10-11 01:02:42.790857 | TASK [Set zuul-log-path fact]
2026-10-11 01:02:42.807406 | localhost | ok
2026-10-11 01:02:42.817008 | 
2026-10-11 01:02:42.817069 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-10-11 01:02:42.843734 | localhost | ok
2026-10-11 01:02:42.852124 | 
2026-10-11 01:02:42.852204 | TASK [upload-logs : Create log directories]
2026-10-11 01:02:43.226106 | localhost | changed
2026-10-11 01:02:43.234351 | 
2026-10-11 01:02:43.234492 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-10-11 01:02:43.620766 | localhost -> localhost | ok: Runtime: 0:00:00.004800
2026-10-11 01:02:43.629505 | 
2026-10-11 01:02:43.629631 | TASK [upload-logs : Upload logs to log server]
2026-10-11 01:02:44.096778 | localhost | Output suppressed because no_log was given
2026-10-11 01:02:44.103530 | 
2026-10-11 01:02:44.103662 | LOOP [upload-logs : Compress console log and json output]
2026-10-11 01:02:44.175549 | localhost | skipping: Conditional result was False
2026-10-11 01:02:44.184696 | localhost | skipping: Conditional result was False
2026-10-11 01:02:44.197598 | 
2026-10-11 01:02:44.197775 | LOOP [upload-logs : Upload compressed console log and json output]
2026-10-11 01:02:44.256387 | localhost | skipping: Conditional result was False
2026-10-11 01:02:44.256746 | 
2026-10-11 01:02:44.261939 | localhost | skipping: Conditional result was False
2026-10-11 01:02:44.270428 | 
2026-10-11 01:02:44.270626 | LOOP [upload-logs : Upload console log and json output]