2026-05-20 01:19:46.921493 | Job console starting
2026-05-20 01:19:46.932195 | Updating git repos
2026-05-20 01:19:48.875431 | Cloning repos into workspace
2026-05-20 01:20:02.781587 | Restoring repo states
2026-05-20 01:20:04.510142 | Merging changes
2026-05-20 01:20:05.670897 | Checking out repos
2026-05-20 01:20:16.948889 | Preparing playbooks
2026-05-20 01:20:24.396156 | Running Ansible setup
2026-05-20 01:20:28.908566 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-05-20 01:20:29.679122 | 
2026-05-20 01:20:29.679232 | PLAY [localhost]
2026-05-20 01:20:29.686439 | 
2026-05-20 01:20:29.686515 | TASK [Gathering Facts]
2026-05-20 01:20:30.618856 | localhost | ok
2026-05-20 01:20:30.627581 | 
2026-05-20 01:20:30.627687 | TASK [Setup log path fact]
2026-05-20 01:20:30.659754 | localhost | ok
2026-05-20 01:20:30.675512 | 
2026-05-20 01:20:30.675704 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-05-20 01:20:30.716136 | localhost | ok
2026-05-20 01:20:30.723060 | 
2026-05-20 01:20:30.723286 | TASK [emit-job-header : Print job information]
2026-05-20 01:20:30.762455 | # Job Information
2026-05-20 01:20:30.762611 | Ansible Version: 2.16.18
2026-05-20 01:20:30.762645 | Job: magnum-cluster-api-hydrophone-v1.33.11-calico
2026-05-20 01:20:30.762668 | Pipeline: check
2026-05-20 01:20:30.762688 | Executor: 2d72f0692154
2026-05-20 01:20:30.762708 | Triggered by: https://github.com/vexxhost/magnum-cluster-api/pull/1008
2026-05-20 01:20:30.762731 | Event ID: 5fad6300-53e9-11f1-8440-22fd55813055
2026-05-20 01:20:30.766482 | 
2026-05-20 01:20:30.766595 | LOOP [emit-job-header : Print node information]
2026-05-20 01:20:30.914831 | localhost | ok:
2026-05-20 01:20:30.914984 | localhost | # Node Information
2026-05-20 01:20:30.915014 | localhost | Inventory Hostname: controller
2026-05-20 01:20:30.915036 | localhost | Hostname: np0000175180
2026-05-20 01:20:30.915057 | localhost | Username: zuul
2026-05-20 01:20:30.915079 | localhost | Distro: Ubuntu 24.04
2026-05-20 01:20:30.915137 | localhost | Provider: yul1
2026-05-20 01:20:30.915158 | localhost | Region: ca-ymq-1
2026-05-20 01:20:30.915197 | localhost | Label: ubuntu-noble-16
2026-05-20 01:20:30.915217 | localhost | Product Name: OpenStack Nova
2026-05-20 01:20:30.915236 | localhost | Interface IP: 199.19.213.235
2026-05-20 01:20:30.924464 | 
2026-05-20 01:20:30.924584 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-05-20 01:20:31.692089 | localhost -> localhost | changed
2026-05-20 01:20:31.703280 | 
2026-05-20 01:20:31.703361 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-05-20 01:20:36.316262 | localhost -> localhost | changed
2026-05-20 01:20:36.325954 | 
2026-05-20 01:20:36.326109 | PLAY [all]
2026-05-20 01:20:36.338898 | 
2026-05-20 01:20:36.339111 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-05-20 01:20:36.560701 | controller -> localhost | ok
2026-05-20 01:20:36.574884 | 
2026-05-20 01:20:36.575178 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-05-20 01:20:36.629512 | controller | ok
2026-05-20 01:20:36.645286 | controller | included: /var/lib/zuul/builds/6af18001df64406f9615458d2093a257/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-05-20 01:20:36.655834 | 
2026-05-20 01:20:36.655903 | TASK [add-build-sshkey : Create Temp SSH key]
2026-05-20 01:20:41.031102 | controller -> localhost | Generating public/private rsa key pair.
2026-05-20 01:20:41.031269 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/6af18001df64406f9615458d2093a257/work/6af18001df64406f9615458d2093a257_id_rsa
2026-05-20 01:20:41.031301 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/6af18001df64406f9615458d2093a257/work/6af18001df64406f9615458d2093a257_id_rsa.pub
2026-05-20 01:20:41.031324 | controller -> localhost | The key fingerprint is:
2026-05-20 01:20:41.031346 | controller -> localhost | SHA256:S3K2SKMkcQytER5yvzekagI9kXSZGnKKDdXsh1npn80 zuul-build-sshkey
2026-05-20 01:20:41.031379 | controller -> localhost | The key's randomart image is:
2026-05-20 01:20:41.031402 | controller -> localhost | +---[RSA 3072]----+
2026-05-20 01:20:41.031427 | controller -> localhost | |..B=.o .         |
2026-05-20 01:20:41.031450 | controller -> localhost | |o=+B* o          |
2026-05-20 01:20:41.031472 | controller -> localhost | |.*=*+=.          |
2026-05-20 01:20:41.031494 | controller -> localhost | |o.++++o          |
2026-05-20 01:20:41.031514 | controller -> localhost | |. + +.*.S+       |
2026-05-20 01:20:41.031534 | controller -> localhost | |.  = + OooE      |
2026-05-20 01:20:41.031554 | controller -> localhost | |. o . . o        |
2026-05-20 01:20:41.031574 | controller -> localhost | | o               |
2026-05-20 01:20:41.031598 | controller -> localhost | |                 |
2026-05-20 01:20:41.031619 | controller -> localhost | +----[SHA256]-----+
2026-05-20 01:20:41.031673 | controller -> localhost | ok: Runtime: 0:00:01.199083
2026-05-20 01:20:41.044968 | 
2026-05-20 01:20:41.045150 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-05-20 01:20:41.084252 | controller | ok
2026-05-20 01:20:41.095482 | controller | included: /var/lib/zuul/builds/6af18001df64406f9615458d2093a257/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-05-20 01:20:41.109057 | 
2026-05-20 01:20:41.109197 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-05-20 01:20:41.135254 | controller | skipping: Conditional result was False
2026-05-20 01:20:41.146375 | 
2026-05-20 01:20:41.146537 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-05-20 01:20:41.760385 | controller | changed
2026-05-20 01:20:41.767044 | 
2026-05-20 01:20:41.767112 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-05-20 01:20:41.990537 | controller | ok
2026-05-20 01:20:42.029219 | 
2026-05-20 01:20:42.029363 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-05-20 01:20:42.638440 | controller | changed
2026-05-20 01:20:42.646622 | 
2026-05-20 01:20:42.646726 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-05-20 01:20:43.368740 | controller | changed
2026-05-20 01:20:43.375483 | 
2026-05-20 01:20:43.559380 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-05-20 01:20:43.585076 | controller | skipping: Conditional result was False
2026-05-20 01:20:43.592541 | 
2026-05-20 01:20:43.592708 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-05-20 01:20:43.960075 | controller -> localhost | changed
2026-05-20 01:20:43.976683 | 
2026-05-20 01:20:43.976775 | TASK [add-build-sshkey : Add back temp key]
2026-05-20 01:20:44.318945 | controller -> localhost | Identity added: /var/lib/zuul/builds/6af18001df64406f9615458d2093a257/work/6af18001df64406f9615458d2093a257_id_rsa (zuul-build-sshkey)
2026-05-20 01:20:44.319159 | controller -> localhost | ok: Runtime: 0:00:00.031701
2026-05-20 01:20:44.325077 | 
2026-05-20 01:20:44.325147 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-05-20 01:20:44.660693 | controller | ok
2026-05-20 01:20:44.665825 | 
2026-05-20 01:20:44.665890 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-05-20 01:20:44.689813 | controller | skipping: Conditional result was False
2026-05-20 01:20:44.704725 | 
2026-05-20 01:20:44.704791 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-05-20 01:20:45.053049 | controller | ok
2026-05-20 01:20:45.064779 | 
2026-05-20 01:20:45.064890 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-05-20 01:22:06.462396 | controller | Output suppressed because no_log was given
2026-05-20 01:22:06.524556 | 
2026-05-20 01:22:06.524726 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-05-20 01:22:07.093215 | controller | ok: "logs"
2026-05-20 01:22:07.200937 | controller | ok: All items complete
2026-05-20 01:22:07.201290 | 
2026-05-20 01:22:07.389172 | controller | ok: "artifacts"
2026-05-20 01:22:07.579826 | controller | ok: "docs"
2026-05-20 01:22:07.601974 | 
2026-05-20 01:22:07.602141 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-05-20 01:22:07.821466 | controller | changed: "logs"
2026-05-20 01:22:08.012599 | controller | changed: "artifacts"
2026-05-20 01:22:08.202442 | controller | changed: "docs"
2026-05-20 01:22:08.222233 | 
2026-05-20 01:22:08.222322 | PLAY RECAP
2026-05-20 01:22:08.222366 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-05-20 01:22:08.222393 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-05-20 01:22:08.222414 | 
2026-05-20 01:22:08.339581 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-05-20 01:22:08.349115 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-05-20 01:22:10.114627 | 
2026-05-20 01:22:10.114743 | PLAY [all]
2026-05-20 01:22:10.135328 | 
2026-05-20 01:22:10.135523 | TASK [Fix the permissions of the zuul home directory]
2026-05-20 01:22:10.743958 | controller | changed
2026-05-20 01:22:10.752231 | 
2026-05-20 01:22:10.752345 | TASK [Gather minimum local MTU]
2026-05-20 01:22:10.826951 | controller | ok
2026-05-20 01:22:10.834206 | 
2026-05-20 01:22:10.834299 | TASK [Calculate external_bridge_mtu]
2026-05-20 01:22:10.898000 | controller | ok
2026-05-20 01:22:10.906033 | 
2026-05-20 01:22:10.906107 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-05-20 01:22:10.930756 | controller | skipping: Conditional result was False
2026-05-20 01:22:10.942413 | 
2026-05-20 01:22:10.942481 | TASK [configure-swap : Get ephemeral0 device node]
2026-05-20 01:22:11.482038 | controller | ok: Runtime: 0:00:00.008378
2026-05-20 01:22:11.490621 | 
2026-05-20 01:22:11.490904 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-05-20 01:22:11.516205 | controller | skipping: Conditional result was False
2026-05-20 01:22:11.527193 | 
2026-05-20 01:22:11.527289 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-05-20 01:22:11.562769 | controller | skipping: Conditional result was False
2026-05-20 01:22:11.575249 | 
2026-05-20 01:22:11.575348 | TASK [configure-swap : Setup swap file on root device]
2026-05-20 01:22:11.629732 | controller | ok
2026-05-20 01:22:11.664498 | controller | included: /var/lib/zuul/builds/6af18001df64406f9615458d2093a257/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-05-20 01:22:11.670817 | 
2026-05-20 01:22:11.670907 | TASK [configure-swap : Calculate required swap]
2026-05-20 01:22:11.768111 | controller | ok
2026-05-20 01:22:11.807474 | 
2026-05-20 01:22:11.807714 | TASK [configure-swap : Get root filesystem]
2026-05-20 01:22:12.049910 | controller | ext4
2026-05-20 01:22:12.348574 | controller | ok: Runtime: 0:00:00.010407
2026-05-20 01:22:12.358574 | 
2026-05-20 01:22:12.358730 | TASK [configure-swap : Save root filesystem]
2026-05-20 01:22:12.395878 | controller | ok
2026-05-20 01:22:12.409394 | 
2026-05-20 01:22:12.409549 | TASK [configure-swap : Debug the root_filesystem variable]
2026-05-20 01:22:12.466163 | controller | ok:
2026-05-20 01:22:12.466397 | controller | {
2026-05-20 01:22:12.466509 | controller |   "root_filesystem": "ext4"
2026-05-20 01:22:12.466559 | controller | }
2026-05-20 01:22:12.478695 | 
2026-05-20 01:22:12.478873 | TASK [configure-swap : Create swap backing file]
2026-05-20 01:22:21.669800 | controller | 8192+0 records in
2026-05-20 01:22:21.669866 | controller | 8192+0 records out
2026-05-20 01:22:21.669876 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 8.93062 s, 962 MB/s
2026-05-20 01:22:22.024715 | controller | ok: Runtime: 0:00:08.939269
2026-05-20 01:22:22.032848 | 
2026-05-20 01:22:22.032939 | TASK [configure-swap : Ensure swapfile perms]
2026-05-20 01:22:22.285057 | controller | changed
2026-05-20 01:22:22.293397 | 
2026-05-20 01:22:22.293480 | TASK [configure-swap : Make swapfile]
2026-05-20 01:23:12.298156 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2026-05-20 01:23:12.298311 | controller | no label, UUID=342a1929-6ea1-4f3b-8523-07e82881a354
2026-05-20 01:23:12.416593 | controller | ok: Runtime: 0:00:49.774653
2026-05-20 01:23:12.422268 | 
2026-05-20 01:23:12.422338 | TASK [configure-swap : Write swap to fstab]
2026-05-20 01:23:12.800527 | controller | changed
2026-05-20 01:23:12.806329 | 
2026-05-20 01:23:12.806404 | TASK [configure-swap : Add all swap]
2026-05-20 01:23:13.358205 | controller | ok: Runtime: 0:00:00.041030
2026-05-20 01:23:13.364139 | 
2026-05-20 01:23:13.364211 | TASK [configure-swap : Debug the swap_required variable]
2026-05-20 01:23:13.400544 | controller | ok:
2026-05-20 01:23:13.400675 | controller | {
2026-05-20 01:23:13.400701 | controller |   "swap_required": "8192"
2026-05-20 01:23:13.400721 | controller | }
2026-05-20 01:23:13.406629 | 
2026-05-20 01:23:13.406707 | TASK [configure-swap : Set swappiness]
2026-05-20 01:23:13.783775 | controller | changed
2026-05-20 01:23:13.790400 | 
2026-05-20 01:23:13.790466 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-05-20 01:23:13.823816 | controller | ok:
2026-05-20 01:23:13.823974 | controller | {
2026-05-20 01:23:13.824015 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-05-20 01:23:13.824048 | controller | }
2026-05-20 01:23:13.836022 | 
2026-05-20 01:23:13.836085 | TASK [setup-stack-user : Create stack group]
2026-05-20 01:23:14.262399 | controller | changed
2026-05-20 01:23:14.267926 | 
2026-05-20 01:23:14.267990 | TASK [setup-stack-user : Create the stack user home folder]
2026-05-20 01:23:14.503741 | controller | changed
2026-05-20 01:23:14.510309 | 
2026-05-20 01:23:14.510374 | TASK [setup-stack-user : Create stack user]
2026-05-20 01:23:15.034687 | controller | changed
2026-05-20 01:23:15.041347 | 
2026-05-20 01:23:15.041414 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-05-20 01:23:15.275480 | controller | changed
2026-05-20 01:23:15.282114 | 
2026-05-20 01:23:15.282179 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-05-20 01:23:16.392380 | controller | changed
2026-05-20 01:23:16.399304 | 
2026-05-20 01:23:16.399397 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-05-20 01:23:16.726552 | controller | changed
2026-05-20 01:23:16.736897 | 
2026-05-20 01:23:16.736976 | TASK [setup-tempest-user : Create tempest group]
2026-05-20 01:23:17.018381 | controller | changed
2026-05-20 01:23:18.763031 | 
2026-05-20 01:23:18.763196 | TASK [setup-tempest-user : Create tempest user]
2026-05-20 01:23:19.110766 | controller | changed
2026-05-20 01:23:19.117830 | 
2026-05-20 01:23:19.117895 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-05-20 01:23:20.642610 | controller | changed
2026-05-20 01:23:20.654093 | 
2026-05-20 01:23:20.654158 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-05-20 01:23:20.973136 | controller | ok: Not all paths examined, check warnings for details
2026-05-20 01:23:20.983736 | 
2026-05-20 01:23:20.983806 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-05-20 01:23:21.434742 | controller | ok: Item: Runtime: 0:00:00.181551
2026-05-20 01:23:21.796594 | controller | ok: Item: Runtime: 0:00:00.134951
2026-05-20 01:23:22.074588 | controller | ok: Item: Runtime: 0:00:00.063666
2026-05-20 01:23:22.535482 | controller | ok: Item: Runtime: 0:00:00.247769
2026-05-20 01:23:22.889294 | controller | ok: Item: Runtime: 0:00:00.138175
2026-05-20 01:23:23.396158 | controller | ok: Item: Runtime: 0:00:00.291797
2026-05-20 01:23:24.096131 | controller | ok: Item: Runtime: 0:00:00.482685
2026-05-20 01:23:24.856271 | controller | ok: Item: Runtime: 0:00:00.545062
2026-05-20 01:23:25.642757 | controller | ok: Item: Runtime: 0:00:00.561625
2026-05-20 01:23:26.964231 | controller | ok: Item: Runtime: 0:00:01.093593
2026-05-20 01:23:27.280872 | controller | ok: Item: Runtime: 0:00:00.105496
2026-05-20 01:23:27.699669 | controller | ok: Item: Runtime: 0:00:00.211645
2026-05-20 01:23:28.271487 | controller | ok: Item: Runtime: 0:00:00.341388
2026-05-20 01:23:31.533800 | controller | ok: Item: Runtime: 0:00:03.046482
2026-05-20 01:23:32.920993 | controller | ok: Item: Runtime: 0:00:01.169446
2026-05-20 01:23:33.414392 | controller | ok: Item: Runtime: 0:00:00.284430
2026-05-20 01:23:33.446973 | 
2026-05-20 01:23:33.447098 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-05-20 01:23:33.665619 | controller | ok: All paths examined
2026-05-20 01:23:33.671860 | 
2026-05-20 01:23:33.671951 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-05-20 01:23:33.908187 | controller | ok: All paths examined
2026-05-20 01:23:33.915789 | 
2026-05-20 01:23:33.915864 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-05-20 01:23:34.335344 | controller | ok: Item: Runtime: 0:00:00.152891
2026-05-20 01:23:34.335574 | controller | changed: All items complete
2026-05-20 01:23:34.335603 | 
2026-05-20 01:23:34.773683 | controller | ok: Item: Runtime: 0:00:00.224508
2026-05-20 01:23:34.787629 | 
2026-05-20 01:23:34.787825 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-05-20 01:23:34.870093 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.872317 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.876097 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.879650 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.882861 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.886575 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.890027 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.893882 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.897493 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.900499 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.903922 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.907874 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.911297 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.914704 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.917786 | controller | skipping: Conditional result was False
2026-05-20 01:23:34.921186 | controller | skipping: Conditional result was False
2026-05-20 01:23:35.010092 | 
2026-05-20 01:23:35.171967 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-05-20 01:23:37.563336 | controller | changed
2026-05-20 01:23:37.575478 | 
2026-05-20 01:23:37.575591 | TASK [setup-devstack-log-dir : Create logs directory]
2026-05-20 01:23:37.797914 | controller | changed
2026-05-20 01:23:37.809978 | 
2026-05-20 01:23:37.810050 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-05-20 01:23:38.056210 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-05-20 01:23:38.352304 | controller | ERROR
2026-05-20 01:23:38.352504 | controller | {
2026-05-20 01:23:38.352548 | controller |   "delta": "0:00:00.009983",
2026-05-20 01:23:38.352599 | controller |   "end": "2026-05-20 01:23:38.056638",
2026-05-20 01:23:38.352627 | controller |   "msg": "non-zero return code",
2026-05-20 01:23:38.352698 | controller |   "rc": 1,
2026-05-20 01:23:38.352740 | controller |   "start": "2026-05-20 01:23:38.046655"
2026-05-20 01:23:38.352767 | controller | }
2026-05-20 01:23:38.352800 | controller | ERROR: Ignoring Errors
2026-05-20 01:23:38.359792 | 
2026-05-20 01:23:38.359861 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-05-20 01:23:38.592112 | controller | ok
2026-05-20 01:23:38.602992 | 
2026-05-20 01:23:38.603060 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-05-20 01:23:38.848953 | controller | /usr/bin/journalctl
2026-05-20 01:23:39.154407 | controller | ok: Runtime: 0:00:00.006940
2026-05-20 01:23:39.161669 | 
2026-05-20 01:23:39.161748 | TASK [start-fresh-logging : Get current date]
2026-05-20 01:23:39.405366 | controller | 2026-05-20 01:23:39
2026-05-20 01:23:39.698320 | controller | ok: Runtime: 0:00:00.009044
2026-05-20 01:23:39.705102 | 
2026-05-20 01:23:39.705170 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-05-20 01:23:40.283915 | controller | changed
2026-05-20 01:23:40.291347 | 
2026-05-20 01:23:40.291413 | TASK [start-fresh-logging : Stop rsyslog]
2026-05-20 01:23:40.314271 | controller | skipping: Conditional result was False
2026-05-20 01:23:40.324667 | 
2026-05-20 01:23:40.324764 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-05-20 01:23:40.856648 | controller | skipping: Conditional result was False
2026-05-20 01:23:40.866271 | 
2026-05-20 01:23:40.866363 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-05-20 01:23:41.395821 | controller | skipping: Conditional result was False
2026-05-20 01:23:41.409121 | 
2026-05-20 01:23:41.409263 | TASK [start-fresh-logging : Recreate syslog file]
2026-05-20 01:23:41.433327 | controller | skipping: Conditional result was False
2026-05-20 01:23:41.443438 | 
2026-05-20 01:23:41.443506 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-05-20 01:23:41.972083 | controller | skipping: Conditional result was False
2026-05-20 01:23:41.978848 | 
2026-05-20 01:23:41.978916 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-05-20 01:23:42.537952 | controller | skipping: Conditional result was False
2026-05-20 01:23:42.547837 | 
2026-05-20 01:23:42.547930 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-05-20 01:23:42.572770 | controller | skipping: Conditional result was False
2026-05-20 01:23:42.582714 | 
2026-05-20 01:23:42.582800 | TASK [start-fresh-logging : Recreate kern.log file]
2026-05-20 01:23:42.609193 | controller | skipping: Conditional result was False
2026-05-20 01:23:42.620627 | 
2026-05-20 01:23:42.620719 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-05-20 01:23:43.152702 | controller | skipping: Conditional result was False
2026-05-20 01:23:43.163904 | 
2026-05-20 01:23:43.164006 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-05-20 01:23:43.697545 | controller | skipping: Conditional result was False
2026-05-20 01:23:43.708641 | 
2026-05-20 01:23:43.708713 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-05-20 01:23:43.732922 | controller | skipping: Conditional result was False
2026-05-20 01:23:43.745511 | 
2026-05-20 01:23:43.745609 | TASK [start-fresh-logging : Start rsyslog]
2026-05-20 01:23:43.771637 | controller | skipping: Conditional result was False
2026-05-20 01:23:43.790987 | 
2026-05-20 01:23:43.791076 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-05-20 01:23:44.483477 | controller | ok
2026-05-20 01:23:44.544404 | 
2026-05-20 01:23:44.544490 | PLAY RECAP
2026-05-20 01:23:44.544551 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-05-20 01:23:44.544578 | 
2026-05-20 01:23:44.682563 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-05-20 01:23:44.691559 | PRE-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-05-20 01:23:45.861184 | 
2026-05-20 01:23:45.861339 | PLAY [all]
2026-05-20 01:23:45.873358 | 
2026-05-20 01:23:45.873459 | TASK [Install curl]
2026-05-20 03:20:35.093606 | PRE-RUN END RESULT_TIMED_OUT: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/pre.yml@main]
2026-05-20 03:20:35.104949 | POST-RUN START: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-05-20 03:20:35.730811 | 
2026-05-20 03:20:35.730955 | PLAY [all]
2026-05-20 03:20:35.743249 | 
2026-05-20 03:20:35.743369 | LOOP [Copy individual Hydrophone result files]
2026-05-20 03:20:36.508997 | controller | ERROR: Item: e2e.log
2026-05-20 03:20:36.509282 | controller | {
2026-05-20 03:20:36.509327 | controller |   "ansible_loop_var": "item",
2026-05-20 03:20:36.509356 | controller |   "item": "e2e.log",
2026-05-20 03:20:36.509417 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/e2e.log not found"
2026-05-20 03:20:36.509447 | controller | }
2026-05-20 03:20:36.760408 | controller | ERROR: Item: junit_01.xml
2026-05-20 03:20:36.760529 | controller | {
2026-05-20 03:20:36.760564 | controller |   "ansible_loop_var": "item",
2026-05-20 03:20:36.760587 | controller |   "item": "junit_01.xml",
2026-05-20 03:20:36.760606 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results/junit_01.xml not found"
2026-05-20 03:20:36.760624 | controller | }
2026-05-20 03:20:36.772725 | controller | ERROR: Ignoring Errors
2026-05-20 03:20:36.778049 | 
2026-05-20 03:20:36.778115 | TASK [Copy Hydrophone results tarball to output folder]
2026-05-20 03:20:37.065394 | controller | ERROR
2026-05-20 03:20:37.065566 | controller | {
2026-05-20 03:20:37.065596 | controller |   "msg": "Source src/github.com/vexxhost/magnum-cluster-api/hydrophone-results.tar.gz not found"
2026-05-20 03:20:37.065618 | controller | }
2026-05-20 03:20:37.065643 | controller | ERROR: Ignoring Errors
2026-05-20 03:20:37.076728 | 
2026-05-20 03:20:37.076797 | TASK [Return built artifacts to Zuul]
2026-05-20 03:20:37.112805 | controller | ok
2026-05-20 03:20:37.118177 | 
2026-05-20 03:20:37.118237 | TASK [Get the Docker volume ID]
2026-05-20 03:20:37.655261 | controller | ERROR
2026-05-20 03:20:37.655520 | controller | {
2026-05-20 03:20:37.655562 | controller |   "msg": "[Errno 2] No such file or directory: b'docker'",
2026-05-20 03:20:37.655594 | controller |   "rc": 2
2026-05-20 03:20:37.655623 | controller | }
2026-05-20 03:20:37.655662 | controller | ERROR: Ignoring Errors
2026-05-20 03:20:37.662218 | 
2026-05-20 03:20:37.662284 | TASK [Copy all of the pod logs]
2026-05-20 03:20:37.696537 | controller | ERROR
2026-05-20 03:20:37.696727 | controller | {
2026-05-20 03:20:37.696790 | 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/6af18001df64406f9615458d2093a257/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-05-20 03:20:37.696826 | controller | }
2026-05-20 03:20:37.696860 | controller | ERROR: Ignoring Errors
2026-05-20 03:20:37.698117 | 
2026-05-20 03:20:37.698177 | PLAY RECAP
2026-05-20 03:20:37.698235 | controller | ok: 5 changed: 0 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 4
2026-05-20 03:20:37.698264 | 
2026-05-20 03:20:37.833040 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/magnum-cluster-api/zuul.d/playbooks/hydrophone/post.yml@main]
2026-05-20 03:20:37.843593 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-05-20 03:20:38.520034 | 
2026-05-20 03:20:38.536089 | PLAY [all]
2026-05-20 03:20:38.560812 | 
2026-05-20 03:20:38.560907 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-05-20 03:20:39.144600 | controller | changed
2026-05-20 03:20:39.150278 | 
2026-05-20 03:20:39.150359 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-05-20 03:20:40.190176 | controller | ok: Runtime: 0:00:00.455768
2026-05-20 03:20:40.410287 | 
2026-05-20 03:20:40.410395 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-05-20 03:20:40.947532 | controller | ok: Runtime: 0:00:00.018781
2026-05-20 03:20:40.953007 | 
2026-05-20 03:20:40.953078 | TASK [export-devstack-journal : Export journal]
2026-05-20 03:20:41.531475 | controller | ok: Runtime: 0:00:00.024369
2026-05-20 03:20:41.538338 | 
2026-05-20 03:20:41.538476 | TASK [export-devstack-journal : Save journal README]
2026-05-20 03:20:42.315866 | controller | changed
2026-05-20 03:20:42.331851 | 
2026-05-20 03:20:42.331996 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-05-20 03:20:42.561150 | controller | changed
2026-05-20 03:20:42.572421 | 
2026-05-20 03:20:42.572634 | TASK [apache-logs-conf : Find logs]
2026-05-20 03:20:42.880051 | controller | Output suppressed because no_log was given
2026-05-20 03:20:42.885992 | 
2026-05-20 03:20:42.886159 | LOOP [apache-logs-conf : Dereference files]
2026-05-20 03:20:42.919472 | 
2026-05-20 03:20:42.919671 | LOOP [apache-logs-conf : Create hard links]
2026-05-20 03:20:42.955517 | 
2026-05-20 03:20:42.955752 | TASK [apache-logs-conf : Find logs]
2026-05-20 03:20:42.994009 | 
2026-05-20 03:20:42.994276 | LOOP [apache-logs-conf : Dereference files]
2026-05-20 03:20:43.031789 | 
2026-05-20 03:20:43.032008 | LOOP [apache-logs-conf : Create hard links]
2026-05-20 03:20:43.073264 | 
2026-05-20 03:20:43.073509 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-05-20 03:20:43.310441 | controller | changed
2026-05-20 03:20:43.317623 | 
2026-05-20 03:20:43.317688 | TASK [apache-logs-conf : Define config paths]
2026-05-20 03:20:43.349414 | controller | ok
2026-05-20 03:20:43.355714 | 
2026-05-20 03:20:43.355778 | TASK [apache-logs-conf : Discover configurations]
2026-05-20 03:20:43.582959 | controller | Output suppressed because no_log was given
2026-05-20 03:20:43.944105 | 
2026-05-20 03:20:43.944270 | LOOP [apache-logs-conf : Dereference configurations]
2026-05-20 03:20:43.982739 | 
2026-05-20 03:20:43.982888 | LOOP [apache-logs-conf : Link configurations]
2026-05-20 03:20:44.021194 | 
2026-05-20 03:20:44.021386 | TASK [capture-performance-data : Generate statistics]
2026-05-20 03:20:44.651304 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-05-20 03:20:44.668804 | controller | Using python 3.12 to install setuptools
2026-05-20 03:20:44.707358 | controller | /usr/bin/python3.12: No module named pip
2026-05-20 03:20:44.718016 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-05-20 03:20:45.059047 | controller | ERROR
2026-05-20 03:20:45.059177 | controller | {
2026-05-20 03:20:45.059211 | controller |   "delta": "0:00:00.450769",
2026-05-20 03:20:45.059233 | controller |   "end": "2026-05-20 03:20:44.719880",
2026-05-20 03:20:45.059252 | controller |   "msg": "non-zero return code",
2026-05-20 03:20:45.059276 | controller |   "rc": 127,
2026-05-20 03:20:45.059297 | controller |   "start": "2026-05-20 03:20:44.269111"
2026-05-20 03:20:45.059316 | controller | }
2026-05-20 03:20:45.059341 | controller | ERROR: Ignoring Errors
2026-05-20 03:20:45.074613 | 
2026-05-20 03:20:45.074688 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-05-20 03:20:45.319465 | controller | changed
2026-05-20 03:20:45.327271 | 
2026-05-20 03:20:45.327341 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-05-20 03:20:48.891098 | controller | Output suppressed because no_log was given
2026-05-20 03:20:48.902070 | 
2026-05-20 03:20:48.902138 | LOOP [devstack-project-conf : Copy configuration files]
2026-05-20 03:20:48.979369 | controller | skipping: Conditional result was False
2026-05-20 03:20:48.979852 | 
2026-05-20 03:20:48.982185 | controller | skipping: Conditional result was False
2026-05-20 03:20:48.983593 | controller | skipping: Conditional result was False
2026-05-20 03:20:48.986394 | controller | skipping: Conditional result was False
2026-05-20 03:20:48.989283 | controller | skipping: Conditional result was False
2026-05-20 03:20:48.992134 | controller | skipping: Conditional result was False
2026-05-20 03:20:48.994902 | controller | skipping: Conditional result was False
2026-05-20 03:20:48.997883 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.000984 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.003800 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.006533 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.009320 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.011702 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.014569 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.017298 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.023582 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.024537 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.025558 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.086351 | 
2026-05-20 03:20:49.086463 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-05-20 03:20:49.301787 | controller | ok
2026-05-20 03:20:49.308409 | 
2026-05-20 03:20:49.308475 | TASK [devstack-project-conf : Copy configuration files]
2026-05-20 03:20:49.838248 | controller | skipping: Conditional result was False
2026-05-20 03:20:49.853753 | 
2026-05-20 03:20:49.853835 | TASK [capture-system-logs : Stage various logs and reports]
2026-05-20 03:20:50.171373 | controller | /usr/bin/python3: No module named pip
2026-05-20 03:20:51.291939 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-05-20 03:20:51.394669 | controller | ok: Runtime: 0:00:01.217454
2026-05-20 03:20:51.406288 | 
2026-05-20 03:20:51.406352 | LOOP [stage-output : Register sources]
2026-05-20 03:21:01.477574 | controller | Output suppressed because no_log was given
2026-05-20 03:21:01.489445 | 
2026-05-20 03:21:01.489511 | TASK [stage-output : Check sudo]
2026-05-20 03:21:02.027690 | controller | ok: Runtime: 0:00:00.019202
2026-05-20 03:21:02.033256 | 
2026-05-20 03:21:02.033317 | LOOP [stage-output : Set source and destination for files and folders]
2026-05-20 03:21:02.130257 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.130678 | 
2026-05-20 03:21:02.132415 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.134080 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.136751 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.175270 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.175841 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.176356 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.177348 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.179784 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.182253 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.184759 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.187446 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.190273 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.192853 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.213326 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.214202 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.214715 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.215305 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.216115 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.218763 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.221523 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.224585 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.226816 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.251807 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.255692 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.347694 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.357757 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.371613 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.382479 | controller | Output suppressed because no_log was given
2026-05-20 03:21:02.396898 | 
2026-05-20 03:21:02.397029 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-05-20 03:21:02.461351 | controller | ok
2026-05-20 03:21:02.468347 | 
2026-05-20 03:21:02.468411 | LOOP [stage-output : Ensure target folders exist]
2026-05-20 03:21:02.705898 | controller | changed: "docs"
2026-05-20 03:21:02.918951 | controller | changed: "artifacts"
2026-05-20 03:21:03.127258 | controller | ok: "logs"
2026-05-20 03:21:03.139956 | 
2026-05-20 03:21:03.140110 | LOOP [stage-output : Copy files and folders to staging folder]
2026-05-20 03:21:03.412311 | controller | ok: Item: Runtime: 0:00:00.009838
2026-05-20 03:21:03.412661 | controller | changed: All items complete
2026-05-20 03:21:03.412702 | 
2026-05-20 03:21:03.640990 | controller | ok: Item: Runtime: 0:00:00.008617
2026-05-20 03:21:03.860664 | controller | ok: Item: Runtime: 0:00:00.006096
2026-05-20 03:21:04.090237 | controller | ok: Item: Runtime: 0:00:00.009645
2026-05-20 03:21:04.308627 | controller | ok: Item: Runtime: 0:00:00.007246
2026-05-20 03:21:04.528149 | controller | ok: Item: Runtime: 0:00:00.009460
2026-05-20 03:21:04.746329 | controller | ok: Item: Runtime: 0:00:00.007990
2026-05-20 03:21:04.980878 | controller | ok: Item: Runtime: 0:00:00.007405
2026-05-20 03:21:05.270807 | controller | ok: Item: Runtime: 0:00:00.007697
2026-05-20 03:21:05.446263 | controller | ok: Item: Runtime: 0:00:00.007204
2026-05-20 03:21:05.677812 | controller | ok: Item: Runtime: 0:00:00.010120
2026-05-20 03:21:05.916149 | controller | ok: Item: Runtime: 0:00:00.008320
2026-05-20 03:21:06.143901 | controller | ok: Item: Runtime: 0:00:00.008311
2026-05-20 03:21:06.368425 | controller | ok: Item: Runtime: 0:00:00.007725
2026-05-20 03:21:06.597561 | controller | ok: Item: Runtime: 0:00:00.007875
2026-05-20 03:21:06.823265 | controller | ok: Item: Runtime: 0:00:00.008261
2026-05-20 03:21:06.837993 | 
2026-05-20 03:21:06.838119 | TASK [stage-output : Make all log files readable]
2026-05-20 03:21:07.074187 | controller | changed
2026-05-20 03:21:07.081762 | 
2026-05-20 03:21:07.081826 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-05-20 03:21:07.420647 | controller | changed: Renamed files for staging.
2026-05-20 03:21:07.425904 | 
2026-05-20 03:21:07.425968 | TASK [stage-output : Discover log files for compression]
2026-05-20 03:21:07.451189 | controller | skipping: Conditional result was False
2026-05-20 03:21:07.464765 | 
2026-05-20 03:21:07.464830 | LOOP [stage-output : Archive everything from logs]
2026-05-20 03:21:07.506068 | 
2026-05-20 03:21:07.506177 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-05-20 03:21:08.150537 | controller | changed:
2026-05-20 03:21:08.150710 | controller | created directory /var/lib/zuul/builds/6af18001df64406f9615458d2093a257/work/logs/controller
2026-05-20 03:21:08.150741 | controller | cd+++++++++ logs/
2026-05-20 03:21:08.150763 | controller | >f+++++++++ logs/deprecations_log.txt
2026-05-20 03:21:08.150784 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-05-20 03:21:08.150804 | controller | >f+++++++++ logs/devstack.journal.gz
2026-05-20 03:21:08.150823 | controller | >f+++++++++ logs/df.txt
2026-05-20 03:21:08.150841 | controller | >f+++++++++ logs/dpkg-l.txt
2026-05-20 03:21:08.150859 | controller | >f+++++++++ logs/iptables.txt
2026-05-20 03:21:08.150877 | controller | >f+++++++++ logs/listen53.txt
2026-05-20 03:21:08.150895 | controller | >f+++++++++ logs/local_conf.txt
2026-05-20 03:21:08.150913 | controller | >f+++++++++ logs/mount.txt
2026-05-20 03:21:08.150947 | controller | >f+++++++++ logs/performance.json
2026-05-20 03:21:08.150966 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-05-20 03:21:08.150984 | controller | >f+++++++++ logs/resolv_conf.txt
2026-05-20 03:21:08.151001 | controller | >f+++++++++ logs/services.txt
2026-05-20 03:21:08.151019 | controller | >f+++++++++ logs/sudoers
2026-05-20 03:21:08.151037 | controller | >f+++++++++ logs/syslog.txt
2026-05-20 03:21:08.151055 | controller | cd+++++++++ logs/apache/
2026-05-20 03:21:08.151073 | controller | cd+++++++++ logs/apache_config/
2026-05-20 03:21:08.151091 | controller | cd+++++++++ logs/etc/
2026-05-20 03:21:08.151114 | controller | cd+++++++++ logs/sudoers.d/
2026-05-20 03:21:08.151138 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-05-20 03:21:08.151157 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-05-20 03:21:08.151176 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-05-20 03:21:08.151194 | controller | >f+++++++++ logs/sudoers.d/README
2026-05-20 03:21:08.151212 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-05-20 03:21:08.163361 | 
2026-05-20 03:21:08.163425 | TASK [Check if a tempest log exits]
2026-05-20 03:21:08.416844 | controller | ok
2026-05-20 03:21:08.422085 | 
2026-05-20 03:21:08.422156 | TASK [Link post-devstack tempest.log]
2026-05-20 03:21:08.447191 | controller | skipping: Conditional result was False
2026-05-20 03:21:08.459006 | 
2026-05-20 03:21:08.459070 | TASK [Capture most recent qemu crash dump, if any]
2026-05-20 03:21:08.702948 | controller | /bin/bash: line 1: coredumpctl: command not found
2026-05-20 03:21:09.000752 | controller | ERROR
2026-05-20 03:21:09.001105 | controller | {
2026-05-20 03:21:09.001182 | controller |   "delta": "0:00:00.008014",
2026-05-20 03:21:09.001232 | controller |   "end": "2026-05-20 03:21:08.703554",
2026-05-20 03:21:09.001278 | controller |   "msg": "non-zero return code",
2026-05-20 03:21:09.001320 | controller |   "rc": 127,
2026-05-20 03:21:09.001364 | controller |   "start": "2026-05-20 03:21:08.695540"
2026-05-20 03:21:09.001490 | controller | }
2026-05-20 03:21:09.001621 | controller | ERROR: Ignoring Errors
2026-05-20 03:21:09.003432 | 
2026-05-20 03:21:09.003477 | PLAY RECAP
2026-05-20 03:21:09.003525 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2026-05-20 03:21:09.003546 | 
2026-05-20 03:21:09.134440 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-05-20 03:21:09.139552 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-05-20 03:21:09.927790 | 
2026-05-20 03:21:09.927986 | PLAY [all]
2026-05-20 03:21:09.943009 | 
2026-05-20 03:21:09.943115 | TASK [fetch-output : Set log path for multiple nodes]
2026-05-20 03:21:09.999776 | controller | skipping: Conditional result was False
2026-05-20 03:21:10.013401 | 
2026-05-20 03:21:10.013550 | TASK [fetch-output : Set log path for single node]
2026-05-20 03:21:10.056295 | controller | ok
2026-05-20 03:21:10.063873 | 
2026-05-20 03:21:10.063947 | LOOP [fetch-output : Ensure local output dirs]
2026-05-20 03:21:10.474680 | controller -> localhost | ok: "/var/lib/zuul/builds/6af18001df64406f9615458d2093a257/work/logs"
2026-05-20 03:21:10.671518 | controller -> localhost | changed: "/var/lib/zuul/builds/6af18001df64406f9615458d2093a257/work/artifacts"
2026-05-20 03:21:10.871973 | controller -> localhost | changed: "/var/lib/zuul/builds/6af18001df64406f9615458d2093a257/work/docs"
2026-05-20 03:21:10.892704 | 
2026-05-20 03:21:10.892810 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-05-20 03:21:11.556713 | controller | changed: .d..t...... ./
2026-05-20 03:21:11.557032 | controller | changed: All items complete
2026-05-20 03:21:11.557065 | 
2026-05-20 03:21:12.074657 | controller | changed: .d..t...... ./
2026-05-20 03:21:12.526024 | controller | changed: .d..t...... ./
2026-05-20 03:21:12.542776 | 
2026-05-20 03:21:12.542926 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-05-20 03:21:12.958421 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006034
2026-05-20 03:21:13.192837 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006846
2026-05-20 03:21:13.213437 | 
2026-05-20 03:21:13.213512 | PLAY [all]
2026-05-20 03:21:13.220716 | 
2026-05-20 03:21:13.220777 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-05-20 03:21:13.883344 | controller | changed
2026-05-20 03:21:13.889318 | 
2026-05-20 03:21:13.889366 | PLAY RECAP
2026-05-20 03:21:13.889411 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-05-20 03:21:13.889432 | 
2026-05-20 03:21:13.990993 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-05-20 03:21:14.000600 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-05-20 03:21:14.597404 | 
2026-05-20 03:21:14.597527 | PLAY [localhost]
2026-05-20 03:21:14.607168 | 
2026-05-20 03:21:14.607238 | TASK [Generate Zuul manifest]
2026-05-20 03:21:14.625610 | localhost | ok
2026-05-20 03:21:14.644306 | 
2026-05-20 03:21:14.644385 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-05-20 03:21:15.021339 | localhost | changed
2026-05-20 03:21:15.031375 | 
2026-05-20 03:21:15.031481 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-05-20 03:21:15.064294 | localhost | ok
2026-05-20 03:21:15.073810 | 
2026-05-20 03:21:15.073913 | TASK [Upload logs]
2026-05-20 03:21:15.104046 | localhost | ok
2026-05-20 03:21:15.213650 | 
2026-05-20 03:21:15.213790 | TASK [Set zuul-log-path fact]
2026-05-20 03:21:15.236332 | localhost | ok
2026-05-20 03:21:15.250845 | 
2026-05-20 03:21:15.250949 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-05-20 03:21:15.284018 | localhost | ok
2026-05-20 03:21:15.294003 | 
2026-05-20 03:21:15.294103 | TASK [upload-logs : Create log directories]
2026-05-20 03:21:15.670318 | localhost | changed
2026-05-20 03:21:15.675819 | 
2026-05-20 03:21:15.675904 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-05-20 03:21:16.052376 | localhost -> localhost | ok: Runtime: 0:00:00.005532
2026-05-20 03:21:16.059007 | 
2026-05-20 03:21:16.059094 | TASK [upload-logs : Upload logs to log server]
2026-05-20 03:21:16.505874 | localhost | Output suppressed because no_log was given
2026-05-20 03:21:16.512094 | 
2026-05-20 03:21:16.512178 | LOOP [upload-logs : Compress console log and json output]
2026-05-20 03:21:16.559163 | localhost | skipping: Conditional result was False
2026-05-20 03:21:16.566434 | localhost | skipping: Conditional result was False
2026-05-20 03:21:16.578419 | 
2026-05-20 03:21:16.578591 | LOOP [upload-logs : Upload compressed console log and json output]
2026-05-20 03:21:16.619246 | localhost | skipping: Conditional result was False
2026-05-20 03:21:16.619540 | 
2026-05-20 03:21:16.623618 | localhost | skipping: Conditional result was False
2026-05-20 03:21:16.632341 | 
2026-05-20 03:21:16.632523 | LOOP [upload-logs : Upload console log and json output]