2025-08-19 02:24:05.162266 | Job console starting
2025-08-19 02:24:05.295014 | Updating git repos
2025-08-19 02:24:14.255137 | Cloning repos into workspace
2025-08-19 02:24:23.577007 | Restoring repo states
2025-08-19 02:24:23.952279 | Merging changes
2025-08-19 02:24:23.952308 | Checking out repos
2025-08-19 02:24:29.246901 | Preparing playbooks
2025-08-19 02:24:38.044888 | Running Ansible setup
2025-08-19 02:24:45.787933 | PRE-RUN START: [trusted : opendev.org/opendev/base-jobs/playbooks/base/pre.yaml@master]
2025-08-19 02:24:47.129465 | 
2025-08-19 02:24:47.129657 | PLAY [Create job header and inventory]
2025-08-19 02:24:47.146738 | 
2025-08-19 02:24:47.146886 | TASK [Gathering Facts]
2025-08-19 02:24:48.508818 | localhost | ok
2025-08-19 02:24:48.529682 | 
2025-08-19 02:24:48.529880 | TASK [Setup log path fact]
2025-08-19 02:24:48.565281 | localhost | ok
2025-08-19 02:24:48.579585 | localhost | included: set-zuul-log-path-fact
2025-08-19 02:24:48.585868 | 
2025-08-19 02:24:48.586001 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-08-19 02:24:48.628377 | localhost | ok
2025-08-19 02:24:48.639638 | 
2025-08-19 02:24:48.639816 | TASK [emit-job-header : Print job information]
2025-08-19 02:24:48.701745 | # Job Information
2025-08-19 02:24:48.702016 | Ansible Version: 2.18.8
2025-08-19 02:24:48.702133 | Job: devstack-tobiko-neutron
2025-08-19 02:24:48.702199 | Pipeline: periodic
2025-08-19 02:24:48.702260 | Executor: ze01.opendev.org
2025-08-19 02:24:48.702322 | Triggered by: https://opendev.org/openstack/neutron/commit/None
2025-08-19 02:24:48.702382 | Event ID: c4de525b66474c6eb8eb566fe75b500c
2025-08-19 02:24:48.707435 | 
2025-08-19 02:24:48.707554 | LOOP [emit-job-header : Print node information]
2025-08-19 02:24:48.891826 | localhost | ok:
2025-08-19 02:24:48.892157 | localhost | # Node Information
2025-08-19 02:24:48.892233 | localhost | Inventory Hostname: controller
2025-08-19 02:24:48.892318 | localhost | Hostname: np5f15016775c54
2025-08-19 02:24:48.892383 | localhost | Username: zuul
2025-08-19 02:24:48.892461 | localhost | Distro: Ubuntu 24.04
2025-08-19 02:24:48.892535 | localhost | Provider: opendev.org%2Fopendev%2Fzuul-providers/vexxhost-ca-ymq-1-main
2025-08-19 02:24:48.892650 | localhost | Region: ca-ymq-1
2025-08-19 02:24:48.892757 | localhost | Label: nested-virt-ubuntu-noble
2025-08-19 02:24:48.892850 | localhost | Product Name: OpenStack Nova
2025-08-19 02:24:48.892929 | localhost | Interface IP: 199.204.45.30
2025-08-19 02:24:48.908789 | 
2025-08-19 02:24:48.908948 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-08-19 02:24:49.549739 | localhost -> localhost | changed
2025-08-19 02:24:49.560294 | 
2025-08-19 02:24:49.560470 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-08-19 02:24:50.940004 | localhost -> localhost | changed
2025-08-19 02:24:50.950306 | 
2025-08-19 02:24:50.950400 | PLAY [Setup Zuul environment]
2025-08-19 02:24:50.963404 | 
2025-08-19 02:24:50.963528 | TASK [Gather network facts]
2025-08-19 02:24:51.788782 | controller | ok
2025-08-19 02:24:51.801318 | 
2025-08-19 02:24:51.801477 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-08-19 02:24:52.189491 | controller -> localhost | ok
2025-08-19 02:24:52.205928 | 
2025-08-19 02:24:52.206144 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-08-19 02:24:52.245367 | controller | ok
2025-08-19 02:24:52.273755 | controller | included: /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-08-19 02:24:52.283217 | 
2025-08-19 02:24:52.283790 | TASK [add-build-sshkey : Create Temp SSH key]
2025-08-19 02:24:53.800864 | controller -> localhost | Generating public/private rsa key pair.
2025-08-19 02:24:53.801156 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/41fccd9ecb204b53bc4e82d4e6cd9dec_id_rsa
2025-08-19 02:24:53.801232 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/41fccd9ecb204b53bc4e82d4e6cd9dec_id_rsa.pub
2025-08-19 02:24:53.801324 | controller -> localhost | The key fingerprint is:
2025-08-19 02:24:53.801388 | controller -> localhost | SHA256:Yh2K8tMxZs3zmeT9YBycW8pReSVNgacLy7XmA8TEHKI zuul-build-sshkey
2025-08-19 02:24:53.801448 | controller -> localhost | The key's randomart image is:
2025-08-19 02:24:53.801506 | controller -> localhost | +---[RSA 3072]----+
2025-08-19 02:24:53.801564 | controller -> localhost | |         .o.. o++|
2025-08-19 02:24:53.801622 | controller -> localhost | |        . .+ . +o|
2025-08-19 02:24:53.801678 | controller -> localhost | |       E. o   = .|
2025-08-19 02:24:53.801755 | controller -> localhost | |     . = . = = . |
2025-08-19 02:24:53.801818 | controller -> localhost | |  . . O S + O +  |
2025-08-19 02:24:53.801875 | controller -> localhost | |   o = + = X X   |
2025-08-19 02:24:53.801931 | controller -> localhost | |    o .   = %    |
2025-08-19 02:24:53.801985 | controller -> localhost | |     .     . =   |
2025-08-19 02:24:53.802093 | controller -> localhost | |              o  |
2025-08-19 02:24:53.802170 | controller -> localhost | +----[SHA256]-----+
2025-08-19 02:24:53.802276 | controller -> localhost | ok: Runtime: 0:00:00.858194
2025-08-19 02:24:53.811264 | 
2025-08-19 02:24:53.811392 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-08-19 02:24:53.845292 | controller | ok
2025-08-19 02:24:53.862557 | controller | included: /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-08-19 02:24:53.875663 | 
2025-08-19 02:24:53.875800 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-08-19 02:24:53.901967 | controller | skipping: Conditional result was False
2025-08-19 02:24:53.911604 | 
2025-08-19 02:24:53.911736 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-08-19 02:24:54.803205 | controller | changed
2025-08-19 02:24:54.812351 | 
2025-08-19 02:24:54.812468 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-08-19 02:24:55.205247 | controller | ok
2025-08-19 02:24:55.214308 | 
2025-08-19 02:24:55.214434 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-08-19 02:24:56.868905 | controller | changed
2025-08-19 02:24:56.917262 | 
2025-08-19 02:24:56.917423 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-08-19 02:24:58.602570 | controller | changed
2025-08-19 02:24:58.611655 | 
2025-08-19 02:24:58.611781 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-08-19 02:24:58.637670 | controller | skipping: Conditional result was False
2025-08-19 02:24:58.647823 | 
2025-08-19 02:24:58.647940 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-08-19 02:24:59.213935 | controller -> localhost | changed
2025-08-19 02:24:59.239592 | 
2025-08-19 02:24:59.239942 | TASK [add-build-sshkey : Add back temp key]
2025-08-19 02:24:59.713774 | controller -> localhost | Identity added: /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/41fccd9ecb204b53bc4e82d4e6cd9dec_id_rsa (zuul-build-sshkey)
2025-08-19 02:24:59.714175 | controller -> localhost | ok: Runtime: 0:00:00.017862
2025-08-19 02:24:59.730268 | 
2025-08-19 02:24:59.730412 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-08-19 02:25:00.364299 | controller | ok
2025-08-19 02:25:00.372373 | 
2025-08-19 02:25:00.372500 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-08-19 02:25:00.408652 | controller | skipping: Conditional result was False
2025-08-19 02:25:00.425774 | 
2025-08-19 02:25:00.425900 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-08-19 02:25:01.022414 | controller | ok
2025-08-19 02:25:01.051985 | 
2025-08-19 02:25:01.052196 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-08-19 02:25:01.432793 | controller | ok: "logs"
2025-08-19 02:25:01.433478 | controller | ok: All items complete
2025-08-19 02:25:01.433571 | 
2025-08-19 02:25:01.751560 | controller | ok: "artifacts"
2025-08-19 02:25:02.052347 | controller | ok: "docs"
2025-08-19 02:25:02.076034 | 
2025-08-19 02:25:02.076273 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-08-19 02:25:02.440606 | controller | changed: "logs"
2025-08-19 02:25:02.760497 | controller | changed: "artifacts"
2025-08-19 02:25:03.076597 | controller | changed: "docs"
2025-08-19 02:25:03.099024 | 
2025-08-19 02:25:03.099237 | PLAY [Configure unbound]
2025-08-19 02:25:03.111348 | 
2025-08-19 02:25:03.111494 | TASK [configure-unbound : Check that Unbound is installed]
2025-08-19 02:25:03.496507 | controller | ok
2025-08-19 02:25:03.515491 | 
2025-08-19 02:25:03.515641 | TASK [configure-unbound : Ensure that Unbound is installed]
2025-08-19 02:25:03.565816 | controller | ok: All assertions passed
2025-08-19 02:25:03.573947 | 
2025-08-19 02:25:03.574098 | TASK [configure-unbound : Check for IPv6]
2025-08-19 02:25:03.731694 | controller | skipping: Conditional result was False
2025-08-19 02:25:03.742633 | 
2025-08-19 02:25:03.742781 | TASK [configure-unbound : Set IPv6 nameservers]
2025-08-19 02:25:03.778788 | controller | skipping: Conditional result was False
2025-08-19 02:25:03.788428 | 
2025-08-19 02:25:03.788584 | TASK [configure-unbound : Set IPv4 nameservers]
2025-08-19 02:25:03.853820 | controller | ok
2025-08-19 02:25:03.862334 | 
2025-08-19 02:25:03.862458 | LOOP [configure-unbound : Include OS-specific variables]
2025-08-19 02:25:03.913765 | controller | ok: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/trusted/project_0/opendev.org/opendev/base-jobs/roles/configure-unbound/vars/Debian.yaml"
2025-08-19 02:25:03.914217 | controller | changed: All items complete
2025-08-19 02:25:03.914285 | 
2025-08-19 02:25:03.929189 | 
2025-08-19 02:25:03.929352 | TASK [configure-unbound : Ensure Unbound conf.d directory exists]
2025-08-19 02:25:04.319989 | controller | ok
2025-08-19 02:25:04.332405 | 
2025-08-19 02:25:04.332576 | TASK [configure-unbound : Configure unbound forwarding]
2025-08-19 02:25:05.991098 | controller | changed
2025-08-19 02:25:05.999894 | 
2025-08-19 02:25:06.000075 | TASK [configure-unbound : Configure unbound TTL]
2025-08-19 02:25:07.644547 | controller | changed
2025-08-19 02:25:07.653811 | 
2025-08-19 02:25:07.653969 | TASK [configure-unbound : Start unbound]
2025-08-19 02:25:08.743468 | controller | ok
2025-08-19 02:25:08.778939 | 
2025-08-19 02:25:08.779174 | TASK [configure-unbound : Restart unbound]
2025-08-19 02:25:09.521475 | controller | changed
2025-08-19 02:25:09.537072 | 
2025-08-19 02:25:09.537227 | PLAY [Prepare workspace and configure mirrors]
2025-08-19 02:25:09.552926 | 
2025-08-19 02:25:09.553157 | TASK [validate-host : Define zuul_info_dir fact]
2025-08-19 02:25:09.601316 | controller | ok
2025-08-19 02:25:09.609430 | 
2025-08-19 02:25:09.609577 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-08-19 02:25:09.996986 | controller -> localhost | ok
2025-08-19 02:25:10.018288 | 
2025-08-19 02:25:10.018459 | TASK [validate-host : Collect information about the host]
2025-08-19 02:25:11.100862 | controller | ok
2025-08-19 02:25:11.122504 | 
2025-08-19 02:25:11.122678 | TASK [validate-host : Sanitize hostname]
2025-08-19 02:25:11.212170 | controller | ok
2025-08-19 02:25:11.222555 | 
2025-08-19 02:25:11.222722 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-08-19 02:25:12.000790 | controller -> localhost | changed
2025-08-19 02:25:12.010449 | 
2025-08-19 02:25:12.010619 | TASK [validate-host : Collect information about zuul worker]
2025-08-19 02:25:14.169995 | controller | ok
2025-08-19 02:25:14.178564 | 
2025-08-19 02:25:14.178719 | TASK [validate-host : Write out all zuul information for each host]
2025-08-19 02:25:14.860325 | controller -> localhost | changed
2025-08-19 02:25:14.894274 | 
2025-08-19 02:25:14.894438 | LOOP [prepare-workspace-git : Filter zuul projects if sync-only-required-projects flag is set]
2025-08-19 02:25:14.933619 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.935944 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.940148 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.948649 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.949601 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.951220 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.954824 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.959056 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.963674 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.966956 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.970065 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.973731 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.977476 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.980672 | controller | skipping: Conditional result was False
2025-08-19 02:25:14.985985 | controller | skipping: Conditional result was False
2025-08-19 02:25:15.012498 | 
2025-08-19 02:25:15.012655 | TASK [prepare-workspace-git : Don't filter zuul projects if flag is false]
2025-08-19 02:25:15.072754 | controller | ok
2025-08-19 02:25:15.089005 | 
2025-08-19 02:25:15.089198 | TASK [prepare-workspace-git : Set initial repo states in workspace]
2025-08-19 02:25:16.364420 | controller | changed
2025-08-19 02:25:16.380842 | 
2025-08-19 02:25:16.381024 | TASK [prepare-workspace-git : Synchronize src repos to workspace directory]
2025-08-19 02:25:19.488333 | controller -> localhost | changed
2025-08-19 02:25:19.504280 | 
2025-08-19 02:25:19.504414 | TASK [prepare-workspace-git : Update remote repository state]
2025-08-19 02:25:21.226697 | controller | changed
2025-08-19 02:25:21.245167 | 
2025-08-19 02:25:21.245322 | TASK [mirror-info : Create /etc/ci]
2025-08-19 02:25:21.745452 | controller | changed
2025-08-19 02:25:21.755563 | 
2025-08-19 02:25:21.755757 | TASK [mirror-info : Install ci_mirror script]
2025-08-19 02:25:23.427445 | controller | changed
2025-08-19 02:25:23.441507 | 
2025-08-19 02:25:23.441650 | TASK [configure-mirrors : Gather needed facts]
2025-08-19 02:25:23.479161 | controller | skipping: Conditional result was False
2025-08-19 02:25:23.488075 | 
2025-08-19 02:25:23.488218 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-08-19 02:25:23.586484 | controller | ok
2025-08-19 02:25:23.599650 | controller | included: /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-08-19 02:25:23.606513 | 
2025-08-19 02:25:23.606636 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-08-19 02:25:23.965625 | controller | ok
2025-08-19 02:25:23.973230 | 
2025-08-19 02:25:23.973341 | LOOP [configure-mirrors : Include OS-specific variables]
2025-08-19 02:25:24.020980 | controller | ok: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/Ubuntu.yaml"
2025-08-19 02:25:24.021377 | 
2025-08-19 02:25:24.038480 | 
2025-08-19 02:25:24.038614 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-08-19 02:25:25.758988 | controller | changed
2025-08-19 02:25:25.772876 | 
2025-08-19 02:25:25.773166 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-08-19 02:25:25.864908 | controller | ok: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/Ubuntu.yaml"
2025-08-19 02:25:25.883605 | controller | included: /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/Ubuntu.yaml
2025-08-19 02:25:25.895322 | 
2025-08-19 02:25:25.895475 | LOOP [configure-mirrors : Install Ubuntu repository files]
2025-08-19 02:25:27.890021 | controller | changed: "etc/apt/sources.list"
2025-08-19 02:25:27.892225 | controller | ok: All items complete
2025-08-19 02:25:27.892328 | 
2025-08-19 02:25:29.546083 | controller | changed: "etc/apt/apt.conf.d/99unauthenticated"
2025-08-19 02:25:29.584130 | 
2025-08-19 02:25:29.584292 | TASK [configure-mirrors : Update apt cache]
2025-08-19 02:25:30.429893 | controller | Ign:1 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble InRelease
2025-08-19 02:25:30.430724 | controller | Ign:2 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-updates InRelease
2025-08-19 02:25:30.432054 | controller | Ign:3 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-backports InRelease
2025-08-19 02:25:30.435172 | controller | Ign:4 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-security InRelease
2025-08-19 02:25:30.437929 | controller | Get:5 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble Release [3235 B]
2025-08-19 02:25:30.441503 | controller | Get:6 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-updates Release [3254 B]
2025-08-19 02:25:30.442850 | controller | Get:7 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-backports Release [3254 B]
2025-08-19 02:25:30.443887 | controller | Get:8 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-security Release [3256 B]
2025-08-19 02:25:30.445999 | controller | Ign:9 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble Release.gpg
2025-08-19 02:25:30.446859 | controller | Ign:10 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-updates Release.gpg
2025-08-19 02:25:30.447848 | controller | Ign:11 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-backports Release.gpg
2025-08-19 02:25:30.449049 | controller | Ign:12 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-security Release.gpg
2025-08-19 02:25:30.450867 | controller | Get:13 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble/universe amd64 Packages [24.5 MB]
2025-08-19 02:25:30.631975 | controller | Get:14 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble/main amd64 Packages [2203 kB]
2025-08-19 02:25:30.632146 | controller | Get:15 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-updates/universe amd64 Packages [1673 kB]
2025-08-19 02:25:30.632346 | controller | Get:16 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-updates/main amd64 Packages [1740 kB]
2025-08-19 02:25:30.632531 | controller | Get:17 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-backports/main amd64 Packages [49.2 kB]
2025-08-19 02:25:30.632746 | controller | Get:18 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-backports/universe amd64 Packages [44.2 kB]
2025-08-19 02:25:30.633979 | controller | Get:19 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-security/main amd64 Packages [1350 kB]
2025-08-19 02:25:30.645874 | controller | Get:20 https://mirror.ca-ymq-1.vexxhost.opendev.org/ubuntu noble-security/universe amd64 Packages [1270 kB]
2025-08-19 02:25:31.808508 | controller | Fetched 32.8 MB in 1s (25.5 MB/s)
2025-08-19 02:25:32.564781 | controller | Reading package lists...
2025-08-19 02:25:32.796942 | controller | ok: Runtime: 0:00:02.620385
2025-08-19 02:25:32.799827 | 
2025-08-19 02:25:32.799912 | PLAY RECAP
2025-08-19 02:25:32.800011 | controller | ok: 44 changed: 20 unreachable: 0 failed: 0 skipped: 7 rescued: 0 ignored: 0
2025-08-19 02:25:32.800125 | localhost | ok: 7 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-08-19 02:25:32.800184 | 
2025-08-19 02:25:33.013728 | PRE-RUN END RESULT_NORMAL: [trusted : opendev.org/opendev/base-jobs/playbooks/base/pre.yaml@master]
2025-08-19 02:25:33.029899 | PRE-RUN START: [trusted : opendev.org/openstack/project-config/playbooks/openstack-fips/pre.yaml@master]
2025-08-19 02:25:34.342891 | 
2025-08-19 02:25:34.343142 | PLAY [Enable ua subscription]
2025-08-19 02:25:34.370542 | 
2025-08-19 02:25:34.370734 | TASK [Enable ua subscription for fips]
2025-08-19 02:25:34.462548 | controller | skipping: Conditional result was False
2025-08-19 02:25:34.467529 | 
2025-08-19 02:25:34.467651 | PLAY RECAP
2025-08-19 02:25:34.467762 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-08-19 02:25:34.467858 | 
2025-08-19 02:25:34.654354 | PRE-RUN END RESULT_NORMAL: [trusted : opendev.org/openstack/project-config/playbooks/openstack-fips/pre.yaml@master]
2025-08-19 02:25:34.663788 | PRE-RUN START: [untrusted : opendev.org/openstack/openstack-zuul-jobs/playbooks/fips/enable-fips.yaml@master]
2025-08-19 02:25:36.211329 | 
2025-08-19 02:25:36.211548 | PLAY [Playbook to enable fips]
2025-08-19 02:25:36.243865 | 
2025-08-19 02:25:36.244092 | TASK [Enable fips]
2025-08-19 02:25:36.351066 | controller | skipping: Conditional result was False
2025-08-19 02:25:36.355501 | 
2025-08-19 02:25:36.355694 | PLAY RECAP
2025-08-19 02:25:36.355848 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-08-19 02:25:36.355977 | 
2025-08-19 02:25:36.601695 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/openstack-zuul-jobs/playbooks/fips/enable-fips.yaml@master]
2025-08-19 02:25:36.614528 | PRE-RUN START: [untrusted : opendev.org/openstack/openstack-zuul-jobs/playbooks/multinode/enable-multinode.yaml@master]
2025-08-19 02:25:37.997394 | 
2025-08-19 02:25:37.997582 | PLAY [Configure a multi node environment]
2025-08-19 02:25:38.017216 | 
2025-08-19 02:25:38.017455 | TASK [Set up multi-node known hosts]
2025-08-19 02:25:38.053702 | controller | ok
2025-08-19 02:25:38.076639 | controller | included: multi-node-known-hosts
2025-08-19 02:25:38.084751 | 
2025-08-19 02:25:38.084886 | TASK [multi-node-known-hosts : Get known_hosts facts]
2025-08-19 02:25:39.168880 | controller | ok
2025-08-19 02:25:39.219087 | 
2025-08-19 02:25:39.219264 | LOOP [multi-node-known-hosts : Add default known_host record for every user]
2025-08-19 02:25:39.969628 | controller | changed:
2025-08-19 02:25:39.969975 | controller | {
2025-08-19 02:25:39.970091 | controller |   "key": "199.204.45.30 ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBIWjVVYakYMJ6c7MwJl53PmPfaB0yD6/l8IDaPgAeCQT6ShaNNo1zj6yGqSUkK2n5HVesagnS0onVkaIy8P3WqQ=",
2025-08-19 02:25:39.970160 | controller |   "name": "199.204.45.30"
2025-08-19 02:25:39.970219 | controller | }
2025-08-19 02:25:40.442487 | controller | changed:
2025-08-19 02:25:40.442644 | controller | {
2025-08-19 02:25:40.442710 | controller |   "key": "199.204.45.30 ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEE24Ohr80bGd+2omOzyjhD/bV+2tBlfXrtNf8jgLL+l",
2025-08-19 02:25:40.442773 | controller |   "name": "199.204.45.30"
2025-08-19 02:25:40.442831 | controller | }
2025-08-19 02:25:40.874309 | controller | changed:
2025-08-19 02:25:40.874598 | controller | {
2025-08-19 02:25:40.874683 | controller |   "key": "199.204.45.30 ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCUUgZVhPencxa662wr4OYZag+aVTqQvtU+ZBvjEILjnJDPyDIvj/8otI/IPM7ag5/QIGJD3aFKES++ofOweXXHxz8fd1ab/njewKI3rjXHW7klUGoEK0jODC779LLLArZPVgWkmR+7XEI4JixU4NAgMee5jlTRTviiXx6+VpzLvFCE0/4Vt/y9s/UjD/h/vMlLPMQ2nY4rIgMAEn9dgAecenfcnv8/1R5mAuUwo4UuS4kYlj0lXX5+RMN+YzVxPWBQ2prAij597kq9TO0VZ2TiiF8PubYR0bPOlMhHlgoyrrQmftdIA7pO35bDSJs5jOt20/jhL0NLsQKA7qUppKkjsNkfeCDGq/iajrmM/YEEibFfF7bOYnTO13AZc0Zrc4A8amZXvjF6ugC3Ok75nRl2qaUE4oULGMRfKhS3+Foyo9dZfoohVk4pE0ARUu6csP8Eo+B/eR+NFBZ7QfXW+NVQF+rgBBxUz+h5rPPeEKvTnse33jOYdEEWDiEs0++yJic=",
2025-08-19 02:25:40.874749 | controller |   "name": "199.204.45.30"
2025-08-19 02:25:40.874810 | controller | }
2025-08-19 02:25:41.280580 | controller | changed:
2025-08-19 02:25:41.280705 | controller | {
2025-08-19 02:25:41.280769 | controller |   "key": "2604:e100:1:0:f816:3eff:fe27:5e6d ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBIWjVVYakYMJ6c7MwJl53PmPfaB0yD6/l8IDaPgAeCQT6ShaNNo1zj6yGqSUkK2n5HVesagnS0onVkaIy8P3WqQ=",
2025-08-19 02:25:41.280828 | controller |   "name": "2604:e100:1:0:f816:3eff:fe27:5e6d"
2025-08-19 02:25:41.280884 | controller | }
2025-08-19 02:25:41.642167 | controller | changed:
2025-08-19 02:25:41.642375 | controller | {
2025-08-19 02:25:41.642501 | controller |   "key": "2604:e100:1:0:f816:3eff:fe27:5e6d ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEE24Ohr80bGd+2omOzyjhD/bV+2tBlfXrtNf8jgLL+l",
2025-08-19 02:25:41.642626 | controller |   "name": "2604:e100:1:0:f816:3eff:fe27:5e6d"
2025-08-19 02:25:41.642726 | controller | }
2025-08-19 02:25:42.021551 | controller | changed:
2025-08-19 02:25:42.021696 | controller | {
2025-08-19 02:25:42.021758 | controller |   "key": "2604:e100:1:0:f816:3eff:fe27:5e6d ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCUUgZVhPencxa662wr4OYZag+aVTqQvtU+ZBvjEILjnJDPyDIvj/8otI/IPM7ag5/QIGJD3aFKES++ofOweXXHxz8fd1ab/njewKI3rjXHW7klUGoEK0jODC779LLLArZPVgWkmR+7XEI4JixU4NAgMee5jlTRTviiXx6+VpzLvFCE0/4Vt/y9s/UjD/h/vMlLPMQ2nY4rIgMAEn9dgAecenfcnv8/1R5mAuUwo4UuS4kYlj0lXX5+RMN+YzVxPWBQ2prAij597kq9TO0VZ2TiiF8PubYR0bPOlMhHlgoyrrQmftdIA7pO35bDSJs5jOt20/jhL0NLsQKA7qUppKkjsNkfeCDGq/iajrmM/YEEibFfF7bOYnTO13AZc0Zrc4A8amZXvjF6ugC3Ok75nRl2qaUE4oULGMRfKhS3+Foyo9dZfoohVk4pE0ARUu6csP8Eo+B/eR+NFBZ7QfXW+NVQF+rgBBxUz+h5rPPeEKvTnse33jOYdEEWDiEs0++yJic=",
2025-08-19 02:25:42.021815 | controller |   "name": "2604:e100:1:0:f816:3eff:fe27:5e6d"
2025-08-19 02:25:42.021877 | controller | }
2025-08-19 02:25:42.371218 | controller | changed:
2025-08-19 02:25:42.371478 | controller | {
2025-08-19 02:25:42.371546 | controller |   "key": "fe80::f816:3eff:fe27:5e6d ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBIWjVVYakYMJ6c7MwJl53PmPfaB0yD6/l8IDaPgAeCQT6ShaNNo1zj6yGqSUkK2n5HVesagnS0onVkaIy8P3WqQ=",
2025-08-19 02:25:42.371604 | controller |   "name": "fe80::f816:3eff:fe27:5e6d"
2025-08-19 02:25:42.371657 | controller | }
2025-08-19 02:25:42.740813 | controller | changed:
2025-08-19 02:25:42.740942 | controller | {
2025-08-19 02:25:42.741003 | controller |   "key": "fe80::f816:3eff:fe27:5e6d ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEE24Ohr80bGd+2omOzyjhD/bV+2tBlfXrtNf8jgLL+l",
2025-08-19 02:25:42.741095 | controller |   "name": "fe80::f816:3eff:fe27:5e6d"
2025-08-19 02:25:42.741150 | controller | }
2025-08-19 02:25:43.111092 | controller | changed:
2025-08-19 02:25:43.111230 | controller | {
2025-08-19 02:25:43.111291 | controller |   "key": "fe80::f816:3eff:fe27:5e6d ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCUUgZVhPencxa662wr4OYZag+aVTqQvtU+ZBvjEILjnJDPyDIvj/8otI/IPM7ag5/QIGJD3aFKES++ofOweXXHxz8fd1ab/njewKI3rjXHW7klUGoEK0jODC779LLLArZPVgWkmR+7XEI4JixU4NAgMee5jlTRTviiXx6+VpzLvFCE0/4Vt/y9s/UjD/h/vMlLPMQ2nY4rIgMAEn9dgAecenfcnv8/1R5mAuUwo4UuS4kYlj0lXX5+RMN+YzVxPWBQ2prAij597kq9TO0VZ2TiiF8PubYR0bPOlMhHlgoyrrQmftdIA7pO35bDSJs5jOt20/jhL0NLsQKA7qUppKkjsNkfeCDGq/iajrmM/YEEibFfF7bOYnTO13AZc0Zrc4A8amZXvjF6ugC3Ok75nRl2qaUE4oULGMRfKhS3+Foyo9dZfoohVk4pE0ARUu6csP8Eo+B/eR+NFBZ7QfXW+NVQF+rgBBxUz+h5rPPeEKvTnse33jOYdEEWDiEs0++yJic=",
2025-08-19 02:25:43.111348 | controller |   "name": "fe80::f816:3eff:fe27:5e6d"
2025-08-19 02:25:43.111401 | controller | }
2025-08-19 02:25:43.471230 | controller | changed:
2025-08-19 02:25:43.471399 | controller | {
2025-08-19 02:25:43.471463 | controller |   "key": "np5f15016775c54 ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBIWjVVYakYMJ6c7MwJl53PmPfaB0yD6/l8IDaPgAeCQT6ShaNNo1zj6yGqSUkK2n5HVesagnS0onVkaIy8P3WqQ=",
2025-08-19 02:25:43.471518 | controller |   "name": "np5f15016775c54"
2025-08-19 02:25:43.471571 | controller | }
2025-08-19 02:25:43.863294 | controller | changed:
2025-08-19 02:25:43.863428 | controller | {
2025-08-19 02:25:43.863488 | controller |   "key": "np5f15016775c54 ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEE24Ohr80bGd+2omOzyjhD/bV+2tBlfXrtNf8jgLL+l",
2025-08-19 02:25:43.863544 | controller |   "name": "np5f15016775c54"
2025-08-19 02:25:43.863599 | controller | }
2025-08-19 02:25:44.228847 | controller | changed:
2025-08-19 02:25:44.228994 | controller | {
2025-08-19 02:25:44.229091 | controller |   "key": "np5f15016775c54 ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCUUgZVhPencxa662wr4OYZag+aVTqQvtU+ZBvjEILjnJDPyDIvj/8otI/IPM7ag5/QIGJD3aFKES++ofOweXXHxz8fd1ab/njewKI3rjXHW7klUGoEK0jODC779LLLArZPVgWkmR+7XEI4JixU4NAgMee5jlTRTviiXx6+VpzLvFCE0/4Vt/y9s/UjD/h/vMlLPMQ2nY4rIgMAEn9dgAecenfcnv8/1R5mAuUwo4UuS4kYlj0lXX5+RMN+YzVxPWBQ2prAij597kq9TO0VZ2TiiF8PubYR0bPOlMhHlgoyrrQmftdIA7pO35bDSJs5jOt20/jhL0NLsQKA7qUppKkjsNkfeCDGq/iajrmM/YEEibFfF7bOYnTO13AZc0Zrc4A8amZXvjF6ugC3Ok75nRl2qaUE4oULGMRfKhS3+Foyo9dZfoohVk4pE0ARUu6csP8Eo+B/eR+NFBZ7QfXW+NVQF+rgBBxUz+h5rPPeEKvTnse33jOYdEEWDiEs0++yJic=",
2025-08-19 02:25:44.229171 | controller |   "name": "np5f15016775c54"
2025-08-19 02:25:44.229228 | controller | }
2025-08-19 02:25:44.308670 | 
2025-08-19 02:25:44.308835 | TASK [Set up multi-node hosts file]
2025-08-19 02:25:44.347375 | controller | ok
2025-08-19 02:25:44.366641 | controller | included: multi-node-hosts-file
2025-08-19 02:25:44.378193 | 
2025-08-19 02:25:44.378326 | TASK [multi-node-hosts-file : Set up the list of hosts and addresses]
2025-08-19 02:25:44.443867 | controller | ok
2025-08-19 02:25:44.452897 | 
2025-08-19 02:25:44.453095 | LOOP [multi-node-hosts-file : Add inventory hostnames to the hosts file]
2025-08-19 02:25:45.079526 | controller | changed: line added
2025-08-19 02:25:45.080063 | controller | changed: All items complete
2025-08-19 02:25:45.080139 | 
2025-08-19 02:25:45.403923 | controller | changed: line added
2025-08-19 02:25:45.436396 | 
2025-08-19 02:25:45.436568 | TASK [Set up multi-node firewall]
2025-08-19 02:25:45.477064 | controller | ok
2025-08-19 02:25:45.505696 | controller | included: multi-node-firewall
2025-08-19 02:25:45.521710 | 
2025-08-19 02:25:45.521976 | LOOP [multi-node-firewall : Include operating system specific vars]
2025-08-19 02:25:45.578409 | controller | ok: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/multi-node-firewall/vars/default.yaml"
2025-08-19 02:25:45.599840 | 
2025-08-19 02:25:45.600064 | TASK [multi-node-firewall : Ensure iptables]
2025-08-19 02:25:46.894267 | controller | ok
2025-08-19 02:25:46.904013 | 
2025-08-19 02:25:46.904222 | TASK [multi-node-firewall : Set up the host ip addresses]
2025-08-19 02:25:47.042190 | controller | ok
2025-08-19 02:25:47.052735 | 
2025-08-19 02:25:47.052902 | LOOP [multi-node-firewall : Set up ipv4 iptables rules]
2025-08-19 02:25:47.789368 | controller | changed: "199.204.45.30"
2025-08-19 02:25:47.789662 | controller | ok: All items complete
2025-08-19 02:25:47.789767 | 
2025-08-19 02:25:47.807704 | 
2025-08-19 02:25:47.807910 | LOOP [multi-node-firewall : Set up ipv6 iptables rules]
2025-08-19 02:25:47.845697 | 
2025-08-19 02:25:47.846002 | TASK [Persist iptables rules]
2025-08-19 02:25:47.880471 | controller | ok
2025-08-19 02:25:47.905199 | controller | included: persistent-firewall
2025-08-19 02:25:47.916491 | 
2025-08-19 02:25:47.916676 | TASK [persistent-firewall : List current ipv4 rules]
2025-08-19 02:25:48.685302 | controller | # Generated by iptables-save v1.8.10 (nf_tables) on Tue Aug 19 02:25:48 2025
2025-08-19 02:25:48.685557 | controller | *filter
2025-08-19 02:25:48.685593 | controller | :INPUT ACCEPT [0:0]
2025-08-19 02:25:48.685609 | controller | :FORWARD ACCEPT [0:0]
2025-08-19 02:25:48.685622 | controller | :OUTPUT ACCEPT [4316:792466]
2025-08-19 02:25:48.685634 | controller | :openstack-INPUT - [0:0]
2025-08-19 02:25:48.685648 | controller | -A INPUT -s 199.204.45.30/32 -j ACCEPT
2025-08-19 02:25:48.685666 | controller | -A INPUT -j openstack-INPUT
2025-08-19 02:25:48.685675 | controller | -A openstack-INPUT -i lo -j ACCEPT
2025-08-19 02:25:48.685688 | controller | -A openstack-INPUT -p icmp -m icmp --icmp-type any -j ACCEPT
2025-08-19 02:25:48.685700 | controller | -A openstack-INPUT -p tcp -m tcp --dport 22 -j ACCEPT
2025-08-19 02:25:48.685713 | controller | -A openstack-INPUT -m state --state RELATED,ESTABLISHED -j ACCEPT
2025-08-19 02:25:48.685723 | controller | -A openstack-INPUT -p tcp -m state --state NEW -m tcp --dport 19885 -j ACCEPT
2025-08-19 02:25:48.685733 | controller | -A openstack-INPUT -s 172.24.4.0/23 -p udp -m udp --dport 69 -j ACCEPT
2025-08-19 02:25:48.685742 | controller | -A openstack-INPUT -s 172.24.4.0/23 -p tcp -m tcp --dport 6385 -j ACCEPT
2025-08-19 02:25:48.685750 | controller | -A openstack-INPUT -s 172.24.4.0/23 -p tcp -m tcp --dport 80 -j ACCEPT
2025-08-19 02:25:48.685758 | controller | -A openstack-INPUT -s 172.24.4.0/23 -p tcp -m tcp --dport 8000 -j ACCEPT
2025-08-19 02:25:48.685766 | controller | -A openstack-INPUT -s 172.24.4.0/23 -p tcp -m tcp --dport 8003 -j ACCEPT
2025-08-19 02:25:48.685782 | controller | -A openstack-INPUT -s 172.24.4.0/23 -p tcp -m tcp --dport 8004 -j ACCEPT
2025-08-19 02:25:48.685790 | controller | -A openstack-INPUT -m limit --limit 2/min -j LOG --log-prefix "iptables dropped: "
2025-08-19 02:25:48.685799 | controller | -A openstack-INPUT -j REJECT --reject-with icmp-host-prohibited
2025-08-19 02:25:48.685807 | controller | COMMIT
2025-08-19 02:25:48.685816 | controller | # Completed on Tue Aug 19 02:25:48 2025
2025-08-19 02:25:49.147851 | controller | ok: Runtime: 0:00:00.012531
2025-08-19 02:25:49.157233 | 
2025-08-19 02:25:49.157369 | TASK [persistent-firewall : List current ipv6 rules]
2025-08-19 02:25:49.651929 | controller | # Generated by ip6tables-save v1.8.10 (nf_tables) on Tue Aug 19 02:25:49 2025
2025-08-19 02:25:49.652076 | controller | *filter
2025-08-19 02:25:49.652092 | controller | :INPUT ACCEPT [0:0]
2025-08-19 02:25:49.652104 | controller | :FORWARD ACCEPT [0:0]
2025-08-19 02:25:49.652115 | controller | :OUTPUT ACCEPT [763:60079]
2025-08-19 02:25:49.652125 | controller | :openstack-INPUT - [0:0]
2025-08-19 02:25:49.652135 | controller | -A INPUT -j openstack-INPUT
2025-08-19 02:25:49.652150 | controller | -A openstack-INPUT -i lo -j ACCEPT
2025-08-19 02:25:49.652166 | controller | -A openstack-INPUT -p ipv6-icmp -j ACCEPT
2025-08-19 02:25:49.652178 | controller | -A openstack-INPUT -p tcp -m tcp --dport 22 -j ACCEPT
2025-08-19 02:25:49.652194 | controller | -A openstack-INPUT -m state --state RELATED,ESTABLISHED -j ACCEPT
2025-08-19 02:25:49.652204 | controller | -A openstack-INPUT -p tcp -m state --state NEW -m tcp --dport 19885 -j ACCEPT
2025-08-19 02:25:49.652215 | controller | -A openstack-INPUT -j REJECT --reject-with icmp6-adm-prohibited
2025-08-19 02:25:49.652224 | controller | COMMIT
2025-08-19 02:25:49.652233 | controller | # Completed on Tue Aug 19 02:25:49 2025
2025-08-19 02:25:49.884798 | controller | ok: Runtime: 0:00:00.011696
2025-08-19 02:25:49.894528 | 
2025-08-19 02:25:49.894649 | LOOP [persistent-firewall : Configure persistent iptables rules]
2025-08-19 02:25:49.940746 | controller | ok: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/persistent-firewall/tasks/persist/Debian.yaml"
2025-08-19 02:25:49.941012 | 
2025-08-19 02:25:49.964861 | controller | included: /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/persistent-firewall/tasks/persist/Debian.yaml
2025-08-19 02:25:49.975075 | 
2025-08-19 02:25:49.975273 | TASK [persistent-firewall : Install iptables-persistent]
2025-08-19 02:25:51.097404 | controller | ok
2025-08-19 02:25:51.107931 | 
2025-08-19 02:25:51.108110 | TASK [persistent-firewall : Persist ipv4 rules]
2025-08-19 02:25:53.366063 | controller | changed
2025-08-19 02:25:53.378118 | 
2025-08-19 02:25:53.378265 | TASK [persistent-firewall : Persist ipv6 rules]
2025-08-19 02:25:55.042874 | controller | changed
2025-08-19 02:25:55.052922 | 
2025-08-19 02:25:55.053078 | TASK [persistent-firewall : Ensure netfilter-persistent is started]
2025-08-19 02:25:56.200484 | controller | ok
2025-08-19 02:25:56.229615 | 
2025-08-19 02:25:56.229769 | PLAY [Configure multi-node networking switch and peer nodes]
2025-08-19 02:25:56.231237 | 
2025-08-19 02:25:56.231331 | PLAY [Copy the build ssh key to authorized_keys on all hosts for root]
2025-08-19 02:25:56.245121 | 
2025-08-19 02:25:56.245305 | TASK [copy-build-sshkey : Authorize build key]
2025-08-19 02:25:56.993838 | controller | changed
2025-08-19 02:25:57.004481 | 
2025-08-19 02:25:57.004653 | TASK [copy-build-sshkey : Get the user home folder for root]
2025-08-19 02:25:57.788953 | controller | ok
2025-08-19 02:25:57.798772 | 
2025-08-19 02:25:57.798984 | TASK [copy-build-sshkey : Install the build private key]
2025-08-19 02:25:59.464105 | controller | changed
2025-08-19 02:25:59.474229 | 
2025-08-19 02:25:59.474412 | TASK [copy-build-sshkey : Install the build public key]
2025-08-19 02:26:01.107467 | controller | changed
2025-08-19 02:26:01.117176 | 
2025-08-19 02:26:01.117295 | PLAY RECAP
2025-08-19 02:26:01.117383 | controller | ok: 23 changed: 8 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-08-19 02:26:01.117439 | 
2025-08-19 02:26:01.357715 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/openstack-zuul-jobs/playbooks/multinode/enable-multinode.yaml@master]
2025-08-19 02:26:01.372295 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2025-08-19 02:26:02.810519 | 
2025-08-19 02:26:02.810790 | PLAY [all]
2025-08-19 02:26:02.847069 | 
2025-08-19 02:26:02.847280 | TASK [Fix the permissions of the zuul home directory]
2025-08-19 02:26:03.564595 | controller | changed
2025-08-19 02:26:03.574341 | 
2025-08-19 02:26:03.574494 | TASK [Gather minimum local MTU]
2025-08-19 02:26:03.701582 | controller | ok
2025-08-19 02:26:03.711173 | 
2025-08-19 02:26:03.711333 | TASK [Calculate external_bridge_mtu]
2025-08-19 02:26:03.811790 | controller | ok
2025-08-19 02:26:03.820220 | 
2025-08-19 02:26:03.820338 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2025-08-19 02:26:03.858922 | controller | skipping: Conditional result was False
2025-08-19 02:26:03.880567 | 
2025-08-19 02:26:03.880823 | TASK [configure-swap : Get ephemeral0 device node]
2025-08-19 02:26:05.123851 | controller | ok: Runtime: 0:00:00.009401
2025-08-19 02:26:05.132778 | 
2025-08-19 02:26:05.132901 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2025-08-19 02:26:05.168998 | controller | skipping: Conditional result was False
2025-08-19 02:26:05.179656 | 
2025-08-19 02:26:05.179803 | TASK [configure-swap : Setup swap on ephemeral storage]
2025-08-19 02:26:05.215856 | controller | skipping: Conditional result was False
2025-08-19 02:26:05.228831 | 
2025-08-19 02:26:05.228998 | TASK [configure-swap : Setup swap file on root device]
2025-08-19 02:26:05.314816 | controller | ok
2025-08-19 02:26:05.337924 | controller | included: /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/untrusted/project_0/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2025-08-19 02:26:05.346496 | 
2025-08-19 02:26:05.346615 | TASK [configure-swap : Calculate required swap]
2025-08-19 02:26:05.437368 | controller | ok
2025-08-19 02:26:05.446744 | 
2025-08-19 02:26:05.446872 | TASK [configure-swap : Get root filesystem]
2025-08-19 02:26:05.919131 | controller | ext4
2025-08-19 02:26:06.206877 | controller | ok: Runtime: 0:00:00.009389
2025-08-19 02:26:06.215809 | 
2025-08-19 02:26:06.215945 | TASK [configure-swap : Save root filesystem]
2025-08-19 02:26:06.260213 | controller | ok
2025-08-19 02:26:06.269103 | 
2025-08-19 02:26:06.269222 | TASK [configure-swap : Debug the root_filesystem variable]
2025-08-19 02:26:06.314228 | controller | ok:
2025-08-19 02:26:06.314505 | controller | {
2025-08-19 02:26:06.314578 | controller |   "root_filesystem": "ext4"
2025-08-19 02:26:06.314672 | controller | }
2025-08-19 02:26:06.323158 | 
2025-08-19 02:26:06.323278 | TASK [configure-swap : Create swap backing file]
2025-08-19 02:26:24.591483 | controller | 8192+0 records in
2025-08-19 02:26:24.591679 | controller | 8192+0 records out
2025-08-19 02:26:24.591708 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 17.8224 s, 482 MB/s
2025-08-19 02:26:25.078752 | controller | ok: Runtime: 0:00:17.833303
2025-08-19 02:26:25.089523 | 
2025-08-19 02:26:25.089634 | TASK [configure-swap : Ensure swapfile perms]
2025-08-19 02:26:25.842379 | controller | changed
2025-08-19 02:26:25.857836 | 
2025-08-19 02:26:25.858527 | TASK [configure-swap : Make swapfile]
2025-08-19 02:26:47.550786 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2025-08-19 02:26:47.550958 | controller | no label, UUID=b4647108-ec04-43b6-bc04-591a81929098
2025-08-19 02:26:48.127433 | controller | ok: Runtime: 0:00:21.193213
2025-08-19 02:26:48.142938 | 
2025-08-19 02:26:48.143183 | TASK [configure-swap : Write swap to fstab]
2025-08-19 02:26:48.862492 | controller | changed
2025-08-19 02:26:48.872605 | 
2025-08-19 02:26:48.873198 | TASK [configure-swap : Add all swap]
2025-08-19 02:26:49.607312 | controller | ok: Runtime: 0:00:00.012011
2025-08-19 02:26:49.616285 | 
2025-08-19 02:26:49.616398 | TASK [configure-swap : Debug the swap_required variable]
2025-08-19 02:26:49.666183 | controller | ok:
2025-08-19 02:26:49.666453 | controller | {
2025-08-19 02:26:49.666514 | controller |   "swap_required": "8192"
2025-08-19 02:26:49.666568 | controller | }
2025-08-19 02:26:49.675275 | 
2025-08-19 02:26:49.675482 | TASK [configure-swap : Set swappiness]
2025-08-19 02:26:50.332517 | controller | changed
2025-08-19 02:26:50.341987 | 
2025-08-19 02:26:50.342139 | TASK [configure-swap : Debug the ephemeral_device variable]
2025-08-19 02:26:50.387351 | controller | ok:
2025-08-19 02:26:50.387734 | controller | {
2025-08-19 02:26:50.387842 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined"
2025-08-19 02:26:50.387940 | controller | }
2025-08-19 02:26:50.403915 | 
2025-08-19 02:26:50.404118 | TASK [setup-stack-user : Create stack group]
2025-08-19 02:26:51.094877 | controller | changed
2025-08-19 02:26:51.113280 | 
2025-08-19 02:26:51.113436 | TASK [setup-stack-user : Create the stack user home folder]
2025-08-19 02:26:51.498780 | controller | changed
2025-08-19 02:26:51.508707 | 
2025-08-19 02:26:51.508874 | TASK [setup-stack-user : Create stack user]
2025-08-19 02:26:52.346790 | controller | changed
2025-08-19 02:26:52.356622 | 
2025-08-19 02:26:52.356783 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2025-08-19 02:26:52.733005 | controller | changed
2025-08-19 02:26:52.743732 | 
2025-08-19 02:26:52.743884 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2025-08-19 02:26:55.067609 | controller | changed
2025-08-19 02:26:55.077174 | 
2025-08-19 02:26:55.077312 | TASK [setup-stack-user : Create .cache folder within BASE]
2025-08-19 02:26:55.475061 | controller | changed
2025-08-19 02:26:55.496838 | 
2025-08-19 02:26:55.497013 | TASK [setup-tempest-user : Create tempest group]
2025-08-19 02:26:55.926588 | controller | changed
2025-08-19 02:26:55.935783 | 
2025-08-19 02:26:55.935903 | TASK [setup-tempest-user : Create tempest user]
2025-08-19 02:26:56.506155 | controller | changed
2025-08-19 02:26:56.515383 | 
2025-08-19 02:26:56.515539 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2025-08-19 02:26:58.490827 | controller | changed
2025-08-19 02:26:58.511940 | 
2025-08-19 02:26:58.512174 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2025-08-19 02:26:59.106983 | controller | ok: Not all paths examined, check warnings for details
2025-08-19 02:26:59.125046 | 
2025-08-19 02:26:59.125309 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2025-08-19 02:27:01.774445 | controller | ok: Item: Runtime: 0:00:02.080129
2025-08-19 02:27:02.461483 | controller | ok: Item: Runtime: 0:00:00.266979
2025-08-19 02:27:03.164534 | controller | ok: Item: Runtime: 0:00:00.292296
2025-08-19 02:27:05.114528 | controller | ok: Item: Runtime: 0:00:01.570930
2025-08-19 02:27:05.649332 | controller | ok: Item: Runtime: 0:00:00.061650
2025-08-19 02:27:06.884181 | controller | ok: Item: Runtime: 0:00:00.812669
2025-08-19 02:27:07.803650 | controller | ok: Item: Runtime: 0:00:00.442626
2025-08-19 02:27:08.601436 | controller | ok: Item: Runtime: 0:00:00.377196
2025-08-19 02:27:09.505848 | controller | ok: Item: Runtime: 0:00:00.464684
2025-08-19 02:27:10.404059 | controller | ok: Item: Runtime: 0:00:00.481259
2025-08-19 02:27:11.013986 | controller | ok: Item: Runtime: 0:00:00.199054
2025-08-19 02:27:12.733526 | controller | ok: Item: Runtime: 0:00:01.329171
2025-08-19 02:27:13.317429 | controller | ok: Item: Runtime: 0:00:00.095262
2025-08-19 02:27:14.092590 | controller | ok: Item: Runtime: 0:00:00.377014
2025-08-19 02:27:14.130869 | 
2025-08-19 02:27:14.131067 | TASK [setup-devstack-source-dirs : Find top level github projects]
2025-08-19 02:27:14.526127 | controller | ok: All paths examined
2025-08-19 02:27:14.536229 | 
2025-08-19 02:27:14.536375 | TASK [setup-devstack-source-dirs : Find actual github repos]
2025-08-19 02:27:14.975393 | controller | ok: All paths examined
2025-08-19 02:27:14.989083 | 
2025-08-19 02:27:14.989255 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2025-08-19 02:27:15.563734 | controller | ok: Item: Runtime: 0:00:00.112261
2025-08-19 02:27:15.564162 | controller | changed: All items complete
2025-08-19 02:27:15.564241 | 
2025-08-19 02:27:15.581721 | 
2025-08-19 02:27:15.581922 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2025-08-19 02:27:15.654340 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.660705 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.670044 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.678259 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.690114 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.696296 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.703018 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.709204 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.715560 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.721908 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.728398 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.734478 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.740320 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.746584 | controller | skipping: Conditional result was False
2025-08-19 02:27:15.780282 | 
2025-08-19 02:27:15.780468 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2025-08-19 02:27:18.552897 | controller | changed
2025-08-19 02:27:18.570105 | 
2025-08-19 02:27:18.570248 | TASK [setup-devstack-log-dir : Create logs directory]
2025-08-19 02:27:19.082088 | controller | changed
2025-08-19 02:27:19.101116 | 
2025-08-19 02:27:19.101292 | TASK [setup-devstack-cache : Copy cached devstack files]
2025-08-19 02:27:19.826965 | controller | ok: Runtime: 0:00:00.065656
2025-08-19 02:27:19.836361 | 
2025-08-19 02:27:19.836480 | TASK [setup-devstack-cache : Set ownership of cached files]
2025-08-19 02:27:20.270232 | controller | changed
2025-08-19 02:27:20.288398 | 
2025-08-19 02:27:20.288515 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2025-08-19 02:27:20.668324 | controller | /usr/bin/journalctl
2025-08-19 02:27:21.012302 | controller | ok: Runtime: 0:00:00.004818
2025-08-19 02:27:21.021709 | 
2025-08-19 02:27:21.021825 | TASK [start-fresh-logging : Get current date]
2025-08-19 02:27:21.535635 | controller | 2025-08-19 02:27:21
2025-08-19 02:27:21.792996 | controller | ok: Runtime: 0:00:00.006176
2025-08-19 02:27:21.801974 | 
2025-08-19 02:27:21.802124 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2025-08-19 02:27:23.477495 | controller | changed
2025-08-19 02:27:23.487360 | 
2025-08-19 02:27:23.487529 | TASK [start-fresh-logging : Stop rsyslog]
2025-08-19 02:27:23.514084 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.524254 | 
2025-08-19 02:27:23.524413 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2025-08-19 02:27:23.596666 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.608612 | 
2025-08-19 02:27:23.608803 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2025-08-19 02:27:23.671613 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.682878 | 
2025-08-19 02:27:23.683183 | TASK [start-fresh-logging : Recreate syslog file]
2025-08-19 02:27:23.709596 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.720126 | 
2025-08-19 02:27:23.720285 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2025-08-19 02:27:23.783817 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.795207 | 
2025-08-19 02:27:23.795396 | TASK [start-fresh-logging : Recreate syslog file permissions]
2025-08-19 02:27:23.868163 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.878149 | 
2025-08-19 02:27:23.878282 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2025-08-19 02:27:23.904335 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.915262 | 
2025-08-19 02:27:23.915422 | TASK [start-fresh-logging : Recreate kern.log file]
2025-08-19 02:27:23.940158 | controller | skipping: Conditional result was False
2025-08-19 02:27:23.949951 | 
2025-08-19 02:27:23.950177 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2025-08-19 02:27:24.021364 | controller | skipping: Conditional result was False
2025-08-19 02:27:24.031867 | 
2025-08-19 02:27:24.032020 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2025-08-19 02:27:24.095091 | controller | skipping: Conditional result was False
2025-08-19 02:27:24.106902 | 
2025-08-19 02:27:24.107135 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2025-08-19 02:27:24.133098 | controller | skipping: Conditional result was False
2025-08-19 02:27:24.143970 | 
2025-08-19 02:27:24.144165 | TASK [start-fresh-logging : Start rsyslog]
2025-08-19 02:27:24.169945 | controller | skipping: Conditional result was False
2025-08-19 02:27:24.188407 | 
2025-08-19 02:27:24.188565 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2025-08-19 02:27:25.014484 | controller | ok
2025-08-19 02:27:25.031071 | 
2025-08-19 02:27:25.031194 | PLAY RECAP
2025-08-19 02:27:25.031290 | controller | ok: 39 changed: 25 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 0
2025-08-19 02:27:25.031346 | 
2025-08-19 02:27:25.460929 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2025-08-19 02:27:25.475122 | PRE-RUN START: [untrusted : opendev.org/x/devstack-plugin-tobiko/playbooks/devstack/pre.yaml@master]
2025-08-19 02:27:27.020832 | ANSIBLE PARSE ERROR
2025-08-19 02:27:27.020855 | Using /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/ansible/pre_playbook_5/ansible.cfg as config file
2025-08-19 02:27:27.020867 | ERROR! couldn't resolve module/action 'openvswitch_bridge'. This often indicates a misspelling, missing collection, or incorrect module path.
2025-08-19 02:27:27.020874 | 
2025-08-19 02:27:27.020881 | The error appears to be in '/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/untrusted/project_5/opendev.org/x/devstack-plugin-tobiko/roles/multi-node-setup/tasks/main.yaml': line 6, column 7, but may
2025-08-19 02:27:27.020889 | be elsewhere in the file depending on the exact syntax problem.
2025-08-19 02:27:27.020896 | 
2025-08-19 02:27:27.020903 | The offending line appears to be:
2025-08-19 02:27:27.020909 | 
2025-08-19 02:27:27.020915 |   block:
2025-08-19 02:27:27.020922 |     - name: Ensure the infra bridge exists
2025-08-19 02:27:27.020928 |       ^ here
2025-08-19 02:27:27.036598 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/x/devstack-plugin-tobiko/playbooks/devstack/pre.yaml@master]
2025-08-19 02:27:27.055011 | POST-RUN START: [untrusted : opendev.org/x/devstack-plugin-tobiko/playbooks/devstack/post.yaml@master]
2025-08-19 02:27:28.398335 | 
2025-08-19 02:27:28.398527 | PLAY [tempest]
2025-08-19 02:27:28.481570 | 
2025-08-19 02:27:28.481771 | TASK [tobiko-collect : ensure local directory '/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/logs' exists]
2025-08-19 02:27:29.192762 | controller -> localhost | ok
2025-08-19 02:27:29.220782 | 
2025-08-19 02:27:29.221239 | TASK [tobiko-collect : look for report files in /home/zuul/src/opendev.org/x/tobiko/report]
2025-08-19 02:27:30.000333 | controller | ok: Not all paths examined, check warnings for details
2025-08-19 02:27:30.018209 | 
2025-08-19 02:27:30.018396 | TASK [tobiko-collect : add found report files]
2025-08-19 02:27:30.161234 | controller | ok
2025-08-19 02:27:30.172871 | 
2025-08-19 02:27:30.173077 | LOOP [tobiko-collect : check if report files exists]
2025-08-19 02:27:30.802925 | controller | ok: "/home/zuul/src/opendev.org/x/tobiko/tobiko.conf"
2025-08-19 02:27:31.118803 | controller | ok: "/home/zuul/src/opendev.org/x/tobiko/report/tobiko.log"
2025-08-19 02:27:31.139605 | 
2025-08-19 02:27:31.139799 | TASK [tobiko-collect : filter out non existing report files]
2025-08-19 02:27:31.236747 | controller | ok
2025-08-19 02:27:31.248317 | 
2025-08-19 02:27:31.248573 | LOOP [tobiko-collect : workaround for Filebeat - add newline to the end of xml report]
2025-08-19 02:27:31.295450 | 
2025-08-19 02:27:31.295723 | LOOP [tobiko-collect : collect report files to local directory '/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/logs']
2025-08-19 02:27:31.333477 | 
2025-08-19 02:27:31.333698 | PLAY RECAP
2025-08-19 02:27:31.333796 | controller | ok: 5 changed: 0 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-08-19 02:27:31.333851 | 
2025-08-19 02:27:31.664573 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/x/devstack-plugin-tobiko/playbooks/devstack/post.yaml@master]
2025-08-19 02:27:31.703343 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2025-08-19 02:27:33.081235 | 
2025-08-19 02:27:33.081444 | PLAY [all]
2025-08-19 02:27:33.117133 | 
2025-08-19 02:27:33.117325 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2025-08-19 02:27:33.881369 | controller | changed
2025-08-19 02:27:33.891021 | 
2025-08-19 02:27:33.891233 | TASK [export-devstack-journal : Export legacy stack screen log files]
2025-08-19 02:27:35.615766 | controller | ok: Runtime: 0:00:00.704468
2025-08-19 02:27:35.625433 | 
2025-08-19 02:27:35.625599 | TASK [export-devstack-journal : Export legacy syslog.txt]
2025-08-19 02:27:36.353609 | controller | ok: Runtime: 0:00:00.020635
2025-08-19 02:27:36.363022 | 
2025-08-19 02:27:36.363174 | TASK [export-devstack-journal : Export journal]
2025-08-19 02:27:37.086284 | controller | ok: Runtime: 0:00:00.034015
2025-08-19 02:27:37.097663 | 
2025-08-19 02:27:37.097778 | TASK [export-devstack-journal : Save journal README]
2025-08-19 02:27:39.280324 | controller | changed
2025-08-19 02:27:39.357792 | 
2025-08-19 02:27:39.358006 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2025-08-19 02:27:39.738998 | controller | changed
2025-08-19 02:27:39.749135 | 
2025-08-19 02:27:39.749256 | TASK [apache-logs-conf : Find logs]
2025-08-19 02:27:40.296896 | controller | Output suppressed because no_log was given
2025-08-19 02:27:40.307137 | 
2025-08-19 02:27:40.307304 | LOOP [apache-logs-conf : Dereference files]
2025-08-19 02:27:40.351502 | 
2025-08-19 02:27:40.351935 | LOOP [apache-logs-conf : Create hard links]
2025-08-19 02:27:40.392773 | 
2025-08-19 02:27:40.393141 | TASK [apache-logs-conf : Find logs]
2025-08-19 02:27:40.433305 | 
2025-08-19 02:27:40.433597 | LOOP [apache-logs-conf : Dereference files]
2025-08-19 02:27:40.483402 | 
2025-08-19 02:27:40.483803 | LOOP [apache-logs-conf : Create hard links]
2025-08-19 02:27:40.531679 | 
2025-08-19 02:27:40.531999 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2025-08-19 02:27:40.908934 | controller | changed
2025-08-19 02:27:40.921705 | 
2025-08-19 02:27:40.921867 | TASK [apache-logs-conf : Define config paths]
2025-08-19 02:27:40.958338 | controller | ok
2025-08-19 02:27:40.967385 | 
2025-08-19 02:27:40.967532 | TASK [apache-logs-conf : Discover configurations]
2025-08-19 02:27:41.366822 | controller | Output suppressed because no_log was given
2025-08-19 02:27:41.377535 | 
2025-08-19 02:27:41.377713 | LOOP [apache-logs-conf : Dereference configurations]
2025-08-19 02:27:41.428184 | 
2025-08-19 02:27:41.428515 | LOOP [apache-logs-conf : Link configurations]
2025-08-19 02:27:41.496554 | 
2025-08-19 02:27:41.496841 | TASK [capture-performance-data : Generate statistics]
2025-08-19 02:27:42.355773 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2025-08-19 02:27:42.371728 | controller | Using python 3.12 to install setuptools
2025-08-19 02:27:42.411183 | controller | /usr/bin/python3.12: No module named pip
2025-08-19 02:27:42.420063 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2025-08-19 02:27:42.727499 | controller | ERROR
2025-08-19 02:27:42.727824 | controller | {
2025-08-19 02:27:42.727902 | controller |   "delta": "0:00:00.461494",
2025-08-19 02:27:42.727958 | controller |   "end": "2025-08-19 02:27:42.422322",
2025-08-19 02:27:42.728012 | controller |   "msg": "non-zero return code",
2025-08-19 02:27:42.728114 | controller |   "rc": 127,
2025-08-19 02:27:42.728170 | controller |   "start": "2025-08-19 02:27:41.960828"
2025-08-19 02:27:42.728223 | controller | }
2025-08-19 02:27:42.728311 | controller | ERROR: Ignoring Errors
2025-08-19 02:27:42.751273 | 
2025-08-19 02:27:42.751497 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2025-08-19 02:27:43.235958 | controller | changed
2025-08-19 02:27:43.246646 | 
2025-08-19 02:27:43.246829 | LOOP [devstack-project-conf : Check which projects have a config folder]
2025-08-19 02:27:48.327485 | controller | Output suppressed because no_log was given
2025-08-19 02:27:48.340686 | 
2025-08-19 02:27:48.340901 | LOOP [devstack-project-conf : Copy configuration files]
2025-08-19 02:27:48.388517 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.389186 | 
2025-08-19 02:27:48.392776 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.398320 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.405667 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.410707 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.415767 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.420724 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.425469 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.430361 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.434525 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.438911 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.443275 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.447916 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.452933 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.458372 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.492910 | 
2025-08-19 02:27:48.493114 | TASK [devstack-project-conf : Check if openstack has a config folder]
2025-08-19 02:27:48.872060 | controller | ok
2025-08-19 02:27:48.883260 | 
2025-08-19 02:27:48.883529 | TASK [devstack-project-conf : Copy configuration files]
2025-08-19 02:27:48.946464 | controller | skipping: Conditional result was False
2025-08-19 02:27:48.967234 | 
2025-08-19 02:27:48.967464 | TASK [capture-system-logs : Stage various logs and reports]
2025-08-19 02:27:49.549371 | controller | /usr/bin/python3: No module named pip
2025-08-19 02:27:50.660259 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2025-08-19 02:27:51.197279 | controller | ok: Runtime: 0:00:01.173642
2025-08-19 02:27:51.217779 | 
2025-08-19 02:27:51.217978 | LOOP [stage-output : Register sources]
2025-08-19 02:28:08.114632 | controller | Output suppressed because no_log was given
2025-08-19 02:28:08.129527 | 
2025-08-19 02:28:08.129725 | TASK [stage-output : Check sudo]
2025-08-19 02:28:08.858190 | controller | ok: Runtime: 0:00:00.019713
2025-08-19 02:28:08.872498 | 
2025-08-19 02:28:08.872638 | LOOP [stage-output : Set source and destination for files and folders]
2025-08-19 02:28:09.062204 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.062714 | 
2025-08-19 02:28:09.066981 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.071138 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.075058 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.212916 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.213676 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.214304 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.216942 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.222109 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.226421 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.231200 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.259986 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.260642 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.261966 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.272807 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.295736 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.296386 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.298697 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.303069 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.307137 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.311301 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.316538 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.321802 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.326201 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.330316 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.337079 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.378398 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.379250 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.503152 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.524539 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.597161 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.597881 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.603973 | controller | Output suppressed because no_log was given
2025-08-19 02:28:09.619844 | 
2025-08-19 02:28:09.620064 | TASK [stage-output : Build a list of source, dest dictionaries]
2025-08-19 02:28:09.732961 | controller | ok
2025-08-19 02:28:09.744496 | 
2025-08-19 02:28:09.744639 | LOOP [stage-output : Ensure target folders exist]
2025-08-19 02:28:10.295208 | controller | changed: "docs"
2025-08-19 02:28:10.642807 | controller | changed: "artifacts"
2025-08-19 02:28:10.997822 | controller | ok: "logs"
2025-08-19 02:28:11.016349 | 
2025-08-19 02:28:11.016521 | LOOP [stage-output : Copy files and folders to staging folder]
2025-08-19 02:28:11.455475 | controller | ok: Item: Runtime: 0:00:00.007483
2025-08-19 02:28:11.456010 | controller | changed: All items complete
2025-08-19 02:28:11.456111 | 
2025-08-19 02:28:11.825096 | controller | ok: Item: Runtime: 0:00:00.006685
2025-08-19 02:28:12.173979 | controller | ok: Item: Runtime: 0:00:00.007832
2025-08-19 02:28:12.522729 | controller | ok: Item: Runtime: 0:00:00.007348
2025-08-19 02:28:12.887690 | controller | ok: Item: Runtime: 0:00:00.008352
2025-08-19 02:28:13.236883 | controller | ok: Item: Runtime: 0:00:00.007411
2025-08-19 02:28:13.590228 | controller | ok: Item: Runtime: 0:00:00.008246
2025-08-19 02:28:13.956318 | controller | ok: Item: Runtime: 0:00:00.006805
2025-08-19 02:28:14.313541 | controller | ok: Item: Runtime: 0:00:00.006102
2025-08-19 02:28:14.662521 | controller | ok: Item: Runtime: 0:00:00.007629
2025-08-19 02:28:15.016499 | controller | ok: Item: Runtime: 0:00:00.009770
2025-08-19 02:28:15.362609 | controller | ok: Item: Runtime: 0:00:00.006863
2025-08-19 02:28:15.736493 | controller | ok: Item: Runtime: 0:00:00.009907
2025-08-19 02:28:16.080985 | controller | ok: Item: Runtime: 0:00:00.005918
2025-08-19 02:28:16.434771 | controller | ok: Item: Runtime: 0:00:00.007515
2025-08-19 02:28:16.783959 | controller | ok: Item: Runtime: 0:00:00.007745
2025-08-19 02:28:16.816410 | 
2025-08-19 02:28:16.816590 | TASK [stage-output : Make all log files readable]
2025-08-19 02:28:17.202600 | controller | changed
2025-08-19 02:28:17.223372 | 
2025-08-19 02:28:17.224091 | TASK [stage-output : Rename log files that match extensions_to_txt]
2025-08-19 02:28:18.037780 | controller | changed: Renamed files for staging.
2025-08-19 02:28:18.048243 | 
2025-08-19 02:28:18.048376 | TASK [stage-output : Discover log files for compression]
2025-08-19 02:28:18.086139 | controller | skipping: Conditional result was False
2025-08-19 02:28:18.097877 | 
2025-08-19 02:28:18.098123 | LOOP [stage-output : Archive everything from logs]
2025-08-19 02:28:18.157167 | 
2025-08-19 02:28:18.157436 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2025-08-19 02:28:20.022846 | controller | changed:
2025-08-19 02:28:20.023148 | controller | created directory /var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/logs/controller
2025-08-19 02:28:20.023218 | controller | cd+++++++++ logs/
2025-08-19 02:28:20.023278 | controller | >f+++++++++ logs/deprecations_log.txt
2025-08-19 02:28:20.023336 | controller | >f+++++++++ logs/devstack.journal.README.txt
2025-08-19 02:28:20.023390 | controller | >f+++++++++ logs/devstack.journal.gz
2025-08-19 02:28:20.023464 | controller | >f+++++++++ logs/df.txt
2025-08-19 02:28:20.023551 | controller | >f+++++++++ logs/dpkg-l.txt
2025-08-19 02:28:20.023608 | controller | >f+++++++++ logs/iptables.txt
2025-08-19 02:28:20.023661 | controller | >f+++++++++ logs/listen53.txt
2025-08-19 02:28:20.023763 | controller | >f+++++++++ logs/local_conf.txt
2025-08-19 02:28:20.023838 | controller | >f+++++++++ logs/performance.json
2025-08-19 02:28:20.023892 | controller | >f+++++++++ logs/pip3-freeze.txt
2025-08-19 02:28:20.023946 | controller | >f+++++++++ logs/resolv_conf.txt
2025-08-19 02:28:20.023999 | controller | >f+++++++++ logs/services.txt
2025-08-19 02:28:20.024112 | controller | >f+++++++++ logs/sudoers
2025-08-19 02:28:20.024171 | controller | >f+++++++++ logs/syslog.txt
2025-08-19 02:28:20.024225 | controller | >f+++++++++ logs/unbound_log.txt
2025-08-19 02:28:20.024278 | controller | cd+++++++++ logs/apache/
2025-08-19 02:28:20.024343 | controller | cd+++++++++ logs/apache_config/
2025-08-19 02:28:20.024396 | controller | cd+++++++++ logs/etc/
2025-08-19 02:28:20.024449 | controller | cd+++++++++ logs/sudoers.d/
2025-08-19 02:28:20.024502 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2025-08-19 02:28:20.024555 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2025-08-19 02:28:20.024608 | controller | >f+++++++++ logs/sudoers.d/README
2025-08-19 02:28:20.024660 | controller | >f+++++++++ logs/sudoers.d/zuul
2025-08-19 02:28:20.046018 | 
2025-08-19 02:28:20.046236 | TASK [Check if a tempest log exits]
2025-08-19 02:28:20.625619 | controller | ok
2025-08-19 02:28:20.649577 | 
2025-08-19 02:28:20.649786 | TASK [Link post-devstack tempest.log]
2025-08-19 02:28:20.681689 | controller | skipping: Conditional result was False
2025-08-19 02:28:20.701993 | 
2025-08-19 02:28:20.702280 | TASK [Capture most recent qemu crash dump, if any]
2025-08-19 02:28:21.280712 | controller | /bin/bash: line 1: coredumpctl: command not found
2025-08-19 02:28:21.526481 | controller | ERROR
2025-08-19 02:28:21.526756 | controller | {
2025-08-19 02:28:21.526832 | controller |   "delta": "0:00:00.008288",
2025-08-19 02:28:21.526892 | controller |   "end": "2025-08-19 02:28:21.281408",
2025-08-19 02:28:21.526950 | controller |   "msg": "non-zero return code",
2025-08-19 02:28:21.527263 | controller |   "rc": 127,
2025-08-19 02:28:21.527326 | controller |   "start": "2025-08-19 02:28:21.273120"
2025-08-19 02:28:21.527379 | controller | }
2025-08-19 02:28:21.527445 | controller | ERROR: Ignoring Errors
2025-08-19 02:28:21.530409 | 
2025-08-19 02:28:21.530524 | PLAY RECAP
2025-08-19 02:28:21.530623 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2025-08-19 02:28:21.530679 | 
2025-08-19 02:28:21.784068 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2025-08-19 02:28:21.808214 | POST-RUN START: [trusted : opendev.org/opendev/base-jobs/playbooks/base/post.yaml@master]
2025-08-19 02:28:23.164099 | 
2025-08-19 02:28:23.164355 | PLAY [all]
2025-08-19 02:28:23.191013 | 
2025-08-19 02:28:23.191248 | TASK [fetch-output : Set log path for multiple nodes]
2025-08-19 02:28:23.280593 | controller | skipping: Conditional result was False
2025-08-19 02:28:23.290597 | 
2025-08-19 02:28:23.290799 | TASK [fetch-output : Set log path for single node]
2025-08-19 02:28:23.358798 | controller | ok
2025-08-19 02:28:23.368557 | 
2025-08-19 02:28:23.368740 | LOOP [fetch-output : Ensure local output dirs]
2025-08-19 02:28:23.997214 | controller -> localhost | ok: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/logs"
2025-08-19 02:28:24.358739 | controller -> localhost | changed: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/artifacts"
2025-08-19 02:28:24.726702 | controller -> localhost | changed: "/var/lib/zuul/builds/41fccd9ecb204b53bc4e82d4e6cd9dec/work/docs"
2025-08-19 02:28:24.766650 | 
2025-08-19 02:28:24.766825 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-08-19 02:28:26.469073 | controller | changed: .d..t...... ./
2025-08-19 02:28:26.469412 | controller | changed: All items complete
2025-08-19 02:28:26.469476 | 
2025-08-19 02:28:27.923881 | controller | changed: .d..t...... ./
2025-08-19 02:28:29.393200 | controller | changed: .d..t...... ./
2025-08-19 02:28:29.422687 | 
2025-08-19 02:28:29.422935 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-08-19 02:28:29.478084 | controller | skipping: Conditional result was False
2025-08-19 02:28:29.490299 | controller | skipping: Conditional result was False
2025-08-19 02:28:29.513900 | 
2025-08-19 02:28:29.514106 | TASK [Get df disk usage]
2025-08-19 02:28:29.727460 | controller | Filesystem     1K-blocks     Used Available Use% Mounted on
2025-08-19 02:28:29.727775 | controller | tmpfs            3286624      652   3285972   1% /run
2025-08-19 02:28:29.727857 | controller | /dev/vda1      156724988 21966816 127821264  15% /
2025-08-19 02:28:29.727961 | controller | tmpfs           16433112        0  16433112   0% /dev/shm
2025-08-19 02:28:29.728096 | controller | tmpfs               5120        0      5120   0% /run/lock
2025-08-19 02:28:29.728160 | controller | /dev/sr0             502      502         0 100% /mnt/config
2025-08-19 02:28:29.728216 | controller | tmpfs            3286620        8   3286612   1% /run/user/1000
2025-08-19 02:28:29.728270 | controller | OpenSSH_9.2p1 Debian-2+deb12u7, OpenSSL 3.0.17 1 Jul 2025
2025-08-19 02:28:29.728461 | controller | debug1: auto-mux: Trying existing master
2025-08-19 02:28:29.728924 | controller | debug1: mux_client_request_session: master session id: 2
2025-08-19 02:28:29.728987 | controller | Shared connection to 199.204.45.30 closed.
2025-08-19 02:28:29.729125 | controller | changed
2025-08-19 02:28:29.737961 | 
2025-08-19 02:28:29.738140 | TASK [Get df inode usage]
2025-08-19 02:28:29.956828 | controller | Filesystem       Inodes  IUsed    IFree IUse% Mounted on
2025-08-19 02:28:29.957146 | controller | tmpfs           4108278    615  4107663    1% /run
2025-08-19 02:28:29.957214 | controller | /dev/vda1      41799680 587034 41212646    2% /
2025-08-19 02:28:29.957273 | controller | tmpfs           4108278      1  4108277    1% /dev/shm
2025-08-19 02:28:29.957327 | controller | tmpfs           4108278      2  4108276    1% /run/lock
2025-08-19 02:28:29.957401 | controller | /dev/sr0              0      0        0     - /mnt/config
2025-08-19 02:28:29.957457 | controller | tmpfs            821655     29   821626    1% /run/user/1000
2025-08-19 02:28:29.957510 | controller | OpenSSH_9.2p1 Debian-2+deb12u7, OpenSSL 3.0.17 1 Jul 2025
2025-08-19 02:28:29.957563 | controller | debug1: auto-mux: Trying existing master
2025-08-19 02:28:29.957615 | controller | debug1: mux_client_request_session: master session id: 2
2025-08-19 02:28:29.957667 | controller | Shared connection to 199.204.45.30 closed.
2025-08-19 02:28:29.957750 | controller | changed
2025-08-19 02:28:29.967713 | 
2025-08-19 02:28:29.967841 | TASK [Get l2 networking]
2025-08-19 02:28:30.186379 | controller | 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000
2025-08-19 02:28:30.186645 | controller |     link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2025-08-19 02:28:30.186710 | controller | 2: ens3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP mode DEFAULT group default qlen 1000
2025-08-19 02:28:30.186769 | controller |     link/ether fa:16:3e:27:5e:6d brd ff:ff:ff:ff:ff:ff
2025-08-19 02:28:30.186825 | controller |     altname enp0s3
2025-08-19 02:28:30.186879 | controller | OpenSSH_9.2p1 Debian-2+deb12u7, OpenSSL 3.0.17 1 Jul 2025
2025-08-19 02:28:30.186933 | controller | debug1: auto-mux: Trying existing master
2025-08-19 02:28:30.186986 | controller | debug1: mux_client_request_session: master session id: 2
2025-08-19 02:28:30.187070 | controller | Shared connection to 199.204.45.30 closed.
2025-08-19 02:28:30.187178 | controller | changed
2025-08-19 02:28:30.195200 | 
2025-08-19 02:28:30.195374 | TASK [Get l3 networking]
2025-08-19 02:28:30.408083 | controller | 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
2025-08-19 02:28:30.408338 | controller |     link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2025-08-19 02:28:30.408404 | controller |     inet 127.0.0.1/8 scope host lo
2025-08-19 02:28:30.408757 | controller |        valid_lft forever preferred_lft forever
2025-08-19 02:28:30.409018 | controller |     inet6 ::1/128 scope host noprefixroute
2025-08-19 02:28:30.409116 | controller |        valid_lft forever preferred_lft forever
2025-08-19 02:28:30.409175 | controller | 2: ens3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000
2025-08-19 02:28:30.409230 | controller |     link/ether fa:16:3e:27:5e:6d brd ff:ff:ff:ff:ff:ff
2025-08-19 02:28:30.409285 | controller |     altname enp0s3
2025-08-19 02:28:30.409358 | controller |     inet 199.204.45.30/24 brd 199.204.45.255 scope global dynamic ens3
2025-08-19 02:28:30.409463 | controller |        valid_lft 86090sec preferred_lft 86090sec
2025-08-19 02:28:30.409531 | controller |     inet6 2604:e100:1:0:f816:3eff:fe27:5e6d/64 scope global dynamic mngtmpaddr
2025-08-19 02:28:30.409585 | controller |        valid_lft 2591979sec preferred_lft 604779sec
2025-08-19 02:28:30.409639 | controller |     inet6 fe80::f816:3eff:fe27:5e6d/64 scope link
2025-08-19 02:28:30.409692 | controller |        valid_lft forever preferred_lft forever
2025-08-19 02:28:30.409744 | controller | OpenSSH_9.2p1 Debian-2+deb12u7, OpenSSL 3.0.17 1 Jul 2025
2025-08-19 02:28:30.409796 | controller | debug1: auto-mux: Trying existing master
2025-08-19 02:28:30.409849 | controller | debug1: mux_client_request_session: master session id: 2
2025-08-19 02:28:30.409902 | controller | Shared connection to 199.204.45.30 closed.
2025-08-19 02:28:30.409997 | controller | changed
2025-08-19 02:28:30.412161 | 
2025-08-19 02:28:30.412241 | PLAY RECAP
2025-08-19 02:28:30.412336 | controller | ok: 7 changed: 6 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-08-19 02:28:30.412390 | 
2025-08-19 02:28:30.581673 | POST-RUN END RESULT_NORMAL: [trusted : opendev.org/opendev/base-jobs/playbooks/base/post.yaml@master]
2025-08-19 02:28:30.598175 | POST-RUN START: [trusted : opendev.org/opendev/base-jobs/playbooks/base/cleanup.yaml@master]
2025-08-19 02:28:31.995792 | 
2025-08-19 02:28:31.995983 | PLAY [all]
2025-08-19 02:28:32.029743 | 
2025-08-19 02:28:32.031267 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-08-19 02:28:32.915924 | controller | changed
2025-08-19 02:28:32.926371 | 
2025-08-19 02:28:32.926479 | PLAY RECAP
2025-08-19 02:28:32.926582 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-08-19 02:28:32.926681 | 
2025-08-19 02:28:33.121823 | POST-RUN END RESULT_NORMAL: [trusted : opendev.org/opendev/base-jobs/playbooks/base/cleanup.yaml@master]
2025-08-19 02:28:33.140118 | POST-RUN START: [trusted : opendev.org/opendev/base-jobs/playbooks/base/post-logs.yaml@master]
2025-08-19 02:28:34.724838 | 
2025-08-19 02:28:34.725087 | PLAY [localhost]
2025-08-19 02:28:34.749326 | 
2025-08-19 02:28:34.749528 | TASK [Include Zuul manifest role]
2025-08-19 02:28:34.786769 | localhost | ok
2025-08-19 02:28:34.824194 | localhost | included: generate-zuul-manifest
2025-08-19 02:28:34.835669 | 
2025-08-19 02:28:34.835975 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-08-19 02:28:35.757567 | localhost | changed
2025-08-19 02:28:35.782713 | 
2025-08-19 02:28:35.782934 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-08-19 02:28:35.828458 | localhost | ok
2025-08-19 02:28:35.840163 | 
2025-08-19 02:28:35.840354 | TASK [Generate bulk log download script]
2025-08-19 02:28:35.869470 | localhost | ok
2025-08-19 02:28:35.887767 | localhost | included: local-log-download
2025-08-19 02:28:35.896374 | 
2025-08-19 02:28:35.896547 | TASK [local-log-download : Check API endpoint is defined]
2025-08-19 02:28:35.951691 | localhost | ok: All assertions passed
2025-08-19 02:28:35.958537 | 
2025-08-19 02:28:35.958690 | TASK [local-log-download : Create download script]
2025-08-19 02:28:37.081753 | localhost -> localhost | changed
2025-08-19 02:28:37.098152 | 
2025-08-19 02:28:37.098431 | LOOP [Select random swift provider for logs upload]
2025-08-19 02:28:37.146733 | localhost | ok: "rax_iad"
2025-08-19 02:28:37.158175 | 
2025-08-19 02:28:37.158360 | TASK [Upload swift logs to rax_iad]
2025-08-19 02:28:37.193238 | localhost | Output suppressed because no_log was given
2025-08-19 02:28:37.230225 | localhost | included: upload-logs-swift
2025-08-19 02:28:37.246440 | 
2025-08-19 02:28:37.246557 | TASK [Set zuul-log-path fact]
2025-08-19 02:28:37.289448 | localhost | ok
2025-08-19 02:28:37.303280 | localhost | included: set-zuul-log-path-fact
2025-08-19 02:28:37.309608 | 
2025-08-19 02:28:37.309733 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-08-19 02:28:37.352465 | localhost | ok
2025-08-19 02:28:37.369269 | 
2025-08-19 02:28:37.369436 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-08-19 02:28:38.050006 | localhost -> localhost | ok: Runtime: 0:00:00.008982
2025-08-19 02:28:38.057849 | 
2025-08-19 02:28:38.058007 | TASK [upload-logs-swift : Upload logs to swift]