2025-12-03 11:16:23.431777 | Job console starting...
2025-12-03 11:16:23.444027 | Updating repositories
2025-12-03 11:16:23.465409 | Preparing job workspace
2025-12-03 11:16:28.673659 | Running Ansible setup...
2025-12-03 11:16:34.663004 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-03 11:16:35.292990 | 
2025-12-03 11:16:35.293166 | PLAY [localhost]
2025-12-03 11:16:35.316800 | 
2025-12-03 11:16:35.316897 | TASK [Gathering Facts]
2025-12-03 11:16:36.261968 | localhost | ok
2025-12-03 11:16:36.294634 | 
2025-12-03 11:16:36.294841 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-03 11:16:36.761720 | localhost -> localhost | changed
2025-12-03 11:16:36.769918 | 
2025-12-03 11:16:36.770094 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-03 11:16:37.600270 | localhost -> localhost | changed
2025-12-03 11:16:37.618556 | 
2025-12-03 11:16:37.618706 | TASK [Setup log path fact]
2025-12-03 11:16:37.644136 | localhost | ok
2025-12-03 11:16:37.666453 | 
2025-12-03 11:16:37.666583 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-03 11:16:37.700418 | localhost | ok
2025-12-03 11:16:37.719978 | 
2025-12-03 11:16:37.720190 | TASK [emit-job-header : Print job information]
2025-12-03 11:16:37.757761 | # Job Information
2025-12-03 11:16:37.758053 | Ansible Version: 2.15.12
2025-12-03 11:16:37.758126 | Job: cifmw-molecule-cifmw_external_dns
2025-12-03 11:16:37.758174 | Pipeline: github-check
2025-12-03 11:16:37.758218 | Executor: ze01.softwarefactory-project.io
2025-12-03 11:16:37.758259 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451
2025-12-03 11:16:37.758303 | Log URL (when completed): https://logserver.rdoproject.org/5b7/rdoproject.org/5b77e044aca74642962f84b49c22c001/
2025-12-03 11:16:37.758346 | Event ID: 4ab514e0-d039-11f0-81e0-fb882bdc02c6
2025-12-03 11:16:37.766582 | 
2025-12-03 11:16:37.766712 | LOOP [emit-job-header : Print node information]
2025-12-03 11:16:37.865926 | localhost | ok:
2025-12-03 11:16:37.866247 | localhost | # Node Information
2025-12-03 11:16:37.866309 | localhost | Inventory Hostname: controller
2025-12-03 11:16:37.866365 | localhost | Hostname: np0005543701
2025-12-03 11:16:37.866409 | localhost | Username: zuul
2025-12-03 11:16:37.866455 | localhost | Distro: CentOS 9
2025-12-03 11:16:37.866495 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-03 11:16:37.866532 | localhost | Region: RegionOne
2025-12-03 11:16:37.866569 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-03 11:16:37.866606 | localhost | Product Name: OpenStack Nova
2025-12-03 11:16:37.866642 | localhost | Interface IP: 38.129.56.33
2025-12-03 11:16:37.912760 | 
2025-12-03 11:16:37.912955 | PLAY [all]
2025-12-03 11:16:37.921853 | 
2025-12-03 11:16:37.921939 | TASK [Gather network facts]
2025-12-03 11:16:38.423144 | controller | ok
2025-12-03 11:16:38.446794 | 
2025-12-03 11:16:38.446875 | TASK [include_role : start-zuul-console]
2025-12-03 11:16:38.469086 | controller | ok
2025-12-03 11:16:38.486118 | 
2025-12-03 11:16:38.486208 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-03 11:16:38.933786 | controller | ok
2025-12-03 11:16:38.946592 | 
2025-12-03 11:16:38.946681 | TASK [include_role : add-build-sshkey]
2025-12-03 11:16:38.990122 | controller | ok
2025-12-03 11:16:39.013279 | 
2025-12-03 11:16:39.013423 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-03 11:16:39.336637 | controller -> localhost | ok
2025-12-03 11:16:39.343424 | 
2025-12-03 11:16:39.343647 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-03 11:16:39.362368 | controller | ok
2025-12-03 11:16:39.377236 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-03 11:16:39.384724 | 
2025-12-03 11:16:39.384829 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-03 11:16:40.180593 | controller -> localhost | Generating public/private rsa key pair.
2025-12-03 11:16:40.180842 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/5b77e044aca74642962f84b49c22c001_id_rsa.
2025-12-03 11:16:40.180874 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/5b77e044aca74642962f84b49c22c001_id_rsa.pub.
2025-12-03 11:16:40.180896 | controller -> localhost | The key fingerprint is:
2025-12-03 11:16:40.180916 | controller -> localhost | SHA256:KzEg1GHRBGOXtoptH4CYyL4vHz0t/pljDCiqIsqJHnE zuul-build-sshkey
2025-12-03 11:16:40.180936 | controller -> localhost | The key's randomart image is:
2025-12-03 11:16:40.180955 | controller -> localhost | +---[RSA 3072]----+
2025-12-03 11:16:40.180972 | controller -> localhost | |  ..B*o.         |
2025-12-03 11:16:40.180990 | controller -> localhost | | . o.o+          |
2025-12-03 11:16:40.181007 | controller -> localhost | |oo.... .         |
2025-12-03 11:16:40.181067 | controller -> localhost | |+......          |
2025-12-03 11:16:40.181086 | controller -> localhost | |.. E.oo S        |
2025-12-03 11:16:40.181104 | controller -> localhost | | o+.=.oo .       |
2025-12-03 11:16:40.181120 | controller -> localhost | |..oo =+o.        |
2025-12-03 11:16:40.181139 | controller -> localhost | |*oo o +=o        |
2025-12-03 11:16:40.181156 | controller -> localhost | |X++o .o+.        |
2025-12-03 11:16:40.181173 | controller -> localhost | +----[SHA256]-----+
2025-12-03 11:16:40.181221 | controller -> localhost | ok: Runtime: 0:00:00.378886
2025-12-03 11:16:40.187112 | 
2025-12-03 11:16:40.187176 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-03 11:16:40.209217 | controller | ok
2025-12-03 11:16:40.218995 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-03 11:16:40.227942 | 
2025-12-03 11:16:40.228006 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-03 11:16:40.262337 | controller | skipping: Conditional result was False
2025-12-03 11:16:40.268106 | 
2025-12-03 11:16:40.268170 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-03 11:16:40.747219 | controller | changed
2025-12-03 11:16:40.754282 | 
2025-12-03 11:16:40.754371 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-03 11:16:41.031207 | controller | ok
2025-12-03 11:16:41.040707 | 
2025-12-03 11:16:41.040807 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-03 11:16:41.849904 | controller | changed
2025-12-03 11:16:41.869217 | 
2025-12-03 11:16:41.869337 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-03 11:16:42.662864 | controller | changed
2025-12-03 11:16:42.668221 | 
2025-12-03 11:16:42.668301 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-03 11:16:42.704070 | controller | skipping: Conditional result was False
2025-12-03 11:16:42.711485 | 
2025-12-03 11:16:42.711581 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-03 11:16:43.240078 | controller -> localhost | changed
2025-12-03 11:16:43.265340 | 
2025-12-03 11:16:43.265466 | TASK [add-build-sshkey : Add back temp key]
2025-12-03 11:16:43.731886 | controller -> localhost | Identity added: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/5b77e044aca74642962f84b49c22c001_id_rsa (zuul-build-sshkey)
2025-12-03 11:16:43.732132 | controller -> localhost | ok: Runtime: 0:00:00.039778
2025-12-03 11:16:43.739783 | 
2025-12-03 11:16:43.741479 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-03 11:16:44.158531 | controller | ok
2025-12-03 11:16:44.163557 | 
2025-12-03 11:16:44.163639 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-03 11:16:44.200070 | controller | skipping: Conditional result was False
2025-12-03 11:16:44.219058 | 
2025-12-03 11:16:44.219214 | TASK [include_role : validate-host]
2025-12-03 11:16:44.241936 | controller | ok
2025-12-03 11:16:44.262328 | 
2025-12-03 11:16:44.262442 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-03 11:16:44.292404 | controller | ok
2025-12-03 11:16:44.297220 | 
2025-12-03 11:16:44.297283 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-03 11:16:44.611550 | controller -> localhost | ok
2025-12-03 11:16:44.667244 | 
2025-12-03 11:16:44.667372 | TASK [validate-host : Collect information about the host]
2025-12-03 11:16:45.522495 | controller | ok
2025-12-03 11:16:45.556044 | 
2025-12-03 11:16:45.556166 | TASK [validate-host : Sanitize hostname]
2025-12-03 11:16:45.606600 | controller | ok
2025-12-03 11:16:45.621987 | 
2025-12-03 11:16:45.622134 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-03 11:16:46.235379 | controller -> localhost | changed
2025-12-03 11:16:46.241339 | 
2025-12-03 11:16:46.241428 | TASK [validate-host : Collect information about zuul worker]
2025-12-03 11:16:46.657821 | controller | ok
2025-12-03 11:16:46.670597 | 
2025-12-03 11:16:46.670704 | TASK [validate-host : Write out all zuul information for each host]
2025-12-03 11:16:47.498291 | controller -> localhost | changed
2025-12-03 11:16:47.513544 | 
2025-12-03 11:16:47.513635 | TASK [include_role : prepare-workspace-openshift]
2025-12-03 11:16:47.593041 | controller | skipping: Conditional result was False
2025-12-03 11:16:47.598898 | 
2025-12-03 11:16:47.598970 | TASK [include_role : remove-zuul-sshkey]
2025-12-03 11:16:47.656095 | controller | skipping: Conditional result was False
2025-12-03 11:16:47.714939 | 
2025-12-03 11:16:47.717519 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-03 11:16:48.012430 | controller | ok: "logs"
2025-12-03 11:16:48.013923 | controller | ok: All items complete
2025-12-03 11:16:48.013963 | 
2025-12-03 11:16:48.238738 | controller | ok: "artifacts"
2025-12-03 11:16:48.446820 | controller | ok: "docs"
2025-12-03 11:16:48.464518 | 
2025-12-03 11:16:48.464663 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-03 11:16:48.742255 | controller | changed: "logs"
2025-12-03 11:16:48.979385 | controller | changed: "artifacts"
2025-12-03 11:16:49.232286 | controller | changed: "docs"
2025-12-03 11:16:49.274728 | 
2025-12-03 11:16:49.274831 | PLAY RECAP
2025-12-03 11:16:49.274877 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-03 11:16:49.274904 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-03 11:16:49.274922 | 
2025-12-03 11:16:49.424631 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-03 11:16:49.425408 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-03 11:16:50.204124 | 
2025-12-03 11:16:50.204273 | PLAY [localhost]
2025-12-03 11:16:50.233788 | 
2025-12-03 11:16:50.233864 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-03 11:16:50.628576 | localhost | ok
2025-12-03 11:16:50.634445 | 
2025-12-03 11:16:50.634517 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-03 11:16:51.425912 | localhost | changed
2025-12-03 11:16:51.472220 | 
2025-12-03 11:16:51.472334 | PLAY [all]
2025-12-03 11:16:51.490970 | 
2025-12-03 11:16:51.491056 | TASK [include_role : prepare-workspace]
2025-12-03 11:16:51.509733 | controller | ok
2025-12-03 11:16:51.525522 | 
2025-12-03 11:16:51.525590 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-03 11:16:51.900284 | controller | ok
2025-12-03 11:16:51.915004 | 
2025-12-03 11:16:51.915146 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-03 11:16:54.318249 | controller | Output suppressed because no_log was given
2025-12-03 11:16:54.353540 | 
2025-12-03 11:16:54.353661 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-03 11:16:54.677866 | controller | changed: "logs"
2025-12-03 11:16:54.878553 | controller | changed: "artifacts"
2025-12-03 11:16:55.083688 | controller | changed: "docs"
2025-12-03 11:16:55.100458 | 
2025-12-03 11:16:55.100550 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-03 11:16:55.418868 | controller | changed: "logs"
2025-12-03 11:16:55.419117 | controller | changed: All items complete
2025-12-03 11:16:55.419143 | 
2025-12-03 11:16:55.638490 | controller | changed: "artifacts"
2025-12-03 11:16:55.861094 | controller | changed: "docs"
2025-12-03 11:16:55.882905 | 
2025-12-03 11:16:55.883017 | TASK [Check if worker can sudo]
2025-12-03 11:16:56.450322 | controller | ok: Runtime: 0:00:00.030883
2025-12-03 11:16:56.456565 | 
2025-12-03 11:16:56.456661 | TASK [configure-mirrors : Gather needed facts]
2025-12-03 11:16:56.562768 | controller | skipping: Conditional result was False
2025-12-03 11:16:56.620464 | 
2025-12-03 11:16:56.620571 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-03 11:16:56.736690 | controller | ok
2025-12-03 11:16:56.747210 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-03 11:16:56.761331 | 
2025-12-03 11:16:56.761611 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-03 11:16:57.113941 | controller | ok
2025-12-03 11:16:57.122892 | 
2025-12-03 11:16:57.123009 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-03 11:16:57.211685 | controller | ok: "/var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-03 11:16:57.226094 | 
2025-12-03 11:16:57.226166 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-03 11:16:58.166016 | controller | changed
2025-12-03 11:16:58.179909 | 
2025-12-03 11:16:58.180054 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-03 11:16:58.279543 | controller | ok: "/var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-03 11:16:58.279772 | controller | ok: All items complete
2025-12-03 11:16:58.279799 | 
2025-12-03 11:16:58.329946 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-03 11:16:58.336398 | 
2025-12-03 11:16:58.336462 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-03 11:16:59.301457 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-03 11:17:01.194343 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-03 11:17:01.203571 | 
2025-12-03 11:17:01.203691 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-03 11:17:01.640368 | controller | changed: section and option added
2025-12-03 11:17:01.667071 | 
2025-12-03 11:17:01.669198 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-03 11:17:02.232107 | controller | 29 files removed
2025-12-03 11:17:02.232322 | controller | ok: Item: dnf clean all Runtime: 0:00:00.276490
2025-12-03 11:17:02.232361 | controller | changed: All items complete
2025-12-03 11:17:02.232381 | 
2025-12-03 11:17:15.528757 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-12-03 11:17:15.528877 | controller | DNF version: 4.14.0
2025-12-03 11:17:15.528907 | controller | cachedir: /var/cache/dnf
2025-12-03 11:17:15.528930 | controller | Making cache files for all metadata files.
2025-12-03 11:17:15.528952 | controller | baseos: has expired and will be refreshed.
2025-12-03 11:17:15.528973 | controller | appstream: has expired and will be refreshed.
2025-12-03 11:17:15.528993 | controller | crb: has expired and will be refreshed.
2025-12-03 11:17:15.529035 | controller | extras-common: has expired and will be refreshed.
2025-12-03 11:17:15.529061 | controller | repo: downloading from remote: baseos
2025-12-03 11:17:15.529082 | controller | CentOS Stream 9 - BaseOS                         26 MB/s | 8.8 MB     00:00
2025-12-03 11:17:15.529103 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-03 11:17:15.529123 | controller | repo: downloading from remote: appstream
2025-12-03 11:17:15.529143 | controller | CentOS Stream 9 - AppStream                      60 MB/s |  25 MB     00:00
2025-12-03 11:17:15.529163 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-03 11:17:15.529183 | controller | repo: downloading from remote: crb
2025-12-03 11:17:15.529202 | controller | CentOS Stream 9 - CRB                            33 MB/s | 7.3 MB     00:00
2025-12-03 11:17:15.529222 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-03 11:17:15.529243 | controller | repo: downloading from remote: extras-common
2025-12-03 11:17:15.529263 | controller | CentOS Stream 9 - Extras packages                45 kB/s |  20 kB     00:00
2025-12-03 11:17:15.529282 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-03 11:17:15.529301 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-03 11:17:15.529321 | controller | Completion plugin: Generating completion cache...
2025-12-03 11:17:15.529341 | controller | Metadata cache created.
2025-12-03 11:17:15.529369 | controller | ok: Item: dnf makecache -v Runtime: 0:00:13.023872
2025-12-03 11:17:15.555478 | 
2025-12-03 11:17:15.555601 | PLAY RECAP
2025-12-03 11:17:15.555656 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-03 11:17:15.555690 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-03 11:17:15.555714 | 
2025-12-03 11:17:15.665351 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-03 11:17:15.666199 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-03 11:17:16.420332 | 
2025-12-03 11:17:16.420447 | PLAY [all]
2025-12-03 11:17:16.440921 | 
2025-12-03 11:17:16.441008 | TASK [Install binary dependencies]
2025-12-03 11:17:16.490182 | controller | ok
2025-12-03 11:17:16.510090 | 
2025-12-03 11:17:16.510182 | TASK [bindep : Include find tasks]
2025-12-03 11:17:16.538898 | controller | ok
2025-12-03 11:17:16.546258 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-03 11:17:16.553274 | 
2025-12-03 11:17:16.553336 | TASK [bindep : Look for bindep.txt]
2025-12-03 11:17:16.953337 | controller | ok
2025-12-03 11:17:16.966465 | 
2025-12-03 11:17:16.966579 | TASK [bindep : Define bindep_file fact]
2025-12-03 11:17:17.007932 | controller | ok
2025-12-03 11:17:17.014148 | 
2025-12-03 11:17:17.014244 | TASK [bindep : Look for other-requirements.txt]
2025-12-03 11:17:17.041230 | controller | skipping: Conditional result was False
2025-12-03 11:17:17.046810 | 
2025-12-03 11:17:17.046894 | TASK [bindep : Define bindep_file fact]
2025-12-03 11:17:17.081036 | controller | skipping: Conditional result was False
2025-12-03 11:17:17.086802 | 
2025-12-03 11:17:17.086873 | TASK [bindep : Look for bindep fallback file]
2025-12-03 11:17:17.128212 | controller | skipping: Conditional result was False
2025-12-03 11:17:17.134231 | 
2025-12-03 11:17:17.134314 | TASK [bindep : Define bindep_file fact]
2025-12-03 11:17:17.169257 | controller | skipping: Conditional result was False
2025-12-03 11:17:17.176468 | 
2025-12-03 11:17:17.176551 | TASK [bindep : Include bindep tasks]
2025-12-03 11:17:17.205804 | controller | ok
2025-12-03 11:17:17.212316 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-03 11:17:17.220182 | 
2025-12-03 11:17:17.220272 | TASK [bindep : Look for bindep command]
2025-12-03 11:17:17.243923 | controller | skipping: Conditional result was False
2025-12-03 11:17:17.250323 | 
2025-12-03 11:17:17.250390 | TASK [bindep : Check for system bindep]
2025-12-03 11:17:17.791537 | controller | ok: Runtime: 0:00:00.005992
2025-12-03 11:17:17.801243 | 
2025-12-03 11:17:17.801416 | TASK [bindep : Define bindep_command fact]
2025-12-03 11:17:17.825773 | controller | skipping: Conditional result was False
2025-12-03 11:17:17.832111 | 
2025-12-03 11:17:17.832176 | TASK [bindep : Include install tasks]
2025-12-03 11:17:17.861284 | controller | ok
2025-12-03 11:17:17.869107 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-03 11:17:17.879855 | 
2025-12-03 11:17:17.879982 | TASK [bindep : Create temp dir for bindep]
2025-12-03 11:17:18.271673 | controller | changed
2025-12-03 11:17:18.277003 | 
2025-12-03 11:17:18.277099 | TASK [Ensure we have pip dependencies]
2025-12-03 11:17:18.297484 | controller | ok
2025-12-03 11:17:18.328444 | 
2025-12-03 11:17:18.328587 | TASK [ensure-pip : Check if pip is installed]
2025-12-03 06:17:18.612063 | controller | /usr/bin/pip3
2025-12-03 06:17:18.639871 | controller | /usr/bin/python3: No module named wheel
2025-12-03 11:17:18.869505 | controller | ok: Runtime: 0:00:00.037826
2025-12-03 11:17:18.875280 | 
2025-12-03 11:17:18.875344 | LOOP [ensure-pip : Install pip from packages]
2025-12-03 11:17:18.913453 | controller | ok: "/var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-03 11:17:18.928880 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-03 11:17:18.941516 | 
2025-12-03 11:17:18.941584 | TASK [ensure-pip : Install Python 3 pip]
2025-12-03 11:17:20.969335 | controller | changed
2025-12-03 11:17:20.980384 | 
2025-12-03 11:17:20.980491 | TASK [ensure-pip : Check for EPEL repository]
2025-12-03 11:17:21.037359 | controller | skipping: Conditional result was False
2025-12-03 11:17:21.044355 | 
2025-12-03 11:17:21.044448 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-03 11:17:21.097640 | controller | skipping: Conditional result was False
2025-12-03 11:17:21.110193 | 
2025-12-03 11:17:21.110298 | TASK [ensure-pip : Install Python 2 pip]
2025-12-03 11:17:21.158094 | controller | skipping: Conditional result was False
2025-12-03 11:17:21.171638 | 
2025-12-03 11:17:21.171754 | TASK [ensure-pip : Ensure setuptools]
2025-12-03 11:17:21.187972 | controller | skipping: Conditional result was False
2025-12-03 11:17:21.201167 | 
2025-12-03 11:17:21.201312 | TASK [ensure-pip : Check for ensurepip module]
2025-12-03 11:17:21.733441 | controller | skipping: Conditional result was False
2025-12-03 11:17:21.739718 | 
2025-12-03 11:17:21.739802 | TASK [ensure-pip : Ensure python3-venv]
2025-12-03 11:17:21.774501 | controller | skipping: Conditional result was False
2025-12-03 11:17:21.781610 | 
2025-12-03 11:17:21.781680 | TASK [ensure-pip : Install pip from source]
2025-12-03 11:17:21.816889 | controller | skipping: Conditional result was False
2025-12-03 11:17:21.823802 | 
2025-12-03 11:17:21.823869 | TASK [ensure-pip : Probe for venv python full path]
2025-12-03 06:17:22.100733 | controller | /usr/bin/python3
2025-12-03 11:17:22.358553 | controller | ok: Runtime: 0:00:00.007320
2025-12-03 11:17:22.365484 | 
2025-12-03 11:17:22.365590 | TASK [ensure-pip : Set host default]
2025-12-03 11:17:22.507840 | controller | ok
2025-12-03 11:17:22.524207 | 
2025-12-03 11:17:22.524324 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-03 11:17:22.605887 | controller | ok
2025-12-03 11:17:22.622944 | 
2025-12-03 11:17:22.623093 | TASK [bindep : Install bindep into temporary venv]
2025-12-03 11:17:28.689859 | controller | changed
2025-12-03 11:17:28.696002 | 
2025-12-03 11:17:28.696082 | TASK [bindep : Define bindep_command]
2025-12-03 11:17:28.725410 | controller | ok
2025-12-03 11:17:28.730911 | 
2025-12-03 11:17:28.730974 | LOOP [bindep : Include package tasks]
2025-12-03 11:17:28.776117 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-03 11:17:28.776383 | controller | ok: All items complete
2025-12-03 11:17:28.776414 | 
2025-12-03 11:17:28.794178 | controller | included: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-03 11:17:28.804669 | 
2025-12-03 11:17:28.804736 | TASK [bindep : Define bindep_run fact]
2025-12-03 11:17:28.835260 | controller | ok
2025-12-03 11:17:28.844361 | 
2025-12-03 11:17:28.844426 | TASK [bindep : Get list of packages to install from bindep]
2025-12-03 06:17:30.386762 | controller | podman
2025-12-03 06:17:30.418648 | controller | python3-jmespath
2025-12-03 06:17:30.418769 | controller | python3-libvirt
2025-12-03 06:17:30.418779 | controller | python3-lxml
2025-12-03 06:17:30.418791 | controller | python3-netaddr
2025-12-03 11:17:30.898540 | controller | ok: Runtime: 0:00:01.301155
2025-12-03 11:17:30.904729 | 
2025-12-03 11:17:30.904796 | TASK [bindep : Install distro packages from bindep]
2025-12-03 11:18:38.257998 | controller | changed
2025-12-03 11:18:38.264211 | 
2025-12-03 11:18:38.264293 | TASK [bindep : Check that packages are installed]
2025-12-03 11:18:39.819957 | controller | ok: Runtime: 0:00:01.131950
2025-12-03 11:18:39.826091 | 
2025-12-03 11:18:39.826158 | TASK [bindep : Fail if we cannot install all packages]
2025-12-03 11:18:39.880763 | controller | skipping: Conditional result was False
2025-12-03 11:18:39.891131 | 
2025-12-03 11:18:39.891196 | TASK [Run test-setup role]
2025-12-03 11:18:39.921054 | controller | ok
2025-12-03 11:18:39.937691 | 
2025-12-03 11:18:39.937774 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-03 11:18:40.193132 | controller | ok
2025-12-03 11:18:40.199233 | 
2025-12-03 11:18:40.199295 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-03 11:18:40.730413 | controller | skipping: Conditional result was False
2025-12-03 11:18:40.754745 | 
2025-12-03 11:18:40.754892 | TASK [bindep : Remove bindep temp dir]
2025-12-03 11:18:41.143094 | controller | ok
2025-12-03 11:18:41.152841 | 
2025-12-03 11:18:41.152894 | PLAY RECAP
2025-12-03 11:18:41.152933 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-03 11:18:41.152953 | 
2025-12-03 11:18:41.251319 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-03 11:18:41.252255 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-03 11:18:41.801600 | 
2025-12-03 11:18:41.801752 | PLAY [all]
2025-12-03 11:18:41.822034 | 
2025-12-03 11:18:41.822110 | TASK [Abort when test_command variable is undefined]
2025-12-03 11:18:41.857869 | controller | skipping: Conditional result was False
2025-12-03 11:18:41.863459 | 
2025-12-03 11:18:41.863532 | TASK [Convert test_command to list]
2025-12-03 11:18:41.947427 | controller | skipping: Conditional result was False
2025-12-03 11:18:41.953766 | 
2025-12-03 11:18:41.953846 | TASK [Use test_command list]
2025-12-03 11:18:42.017628 | controller | ok
2025-12-03 11:18:42.025167 | 
2025-12-03 11:18:42.025232 | LOOP [Run test_command]
2025-12-03 11:18:42.410765 | controller | no check to run
2025-12-03 11:18:42.410954 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004674
2025-12-03 11:18:42.435439 | 
2025-12-03 11:18:42.435582 | PLAY RECAP
2025-12-03 11:18:42.435630 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-03 11:18:42.435656 | 
2025-12-03 11:18:42.553179 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-03 11:18:42.559756 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-03 11:18:44.431819 | 
2025-12-03 11:18:44.432061 | PLAY [all]
2025-12-03 11:18:44.453767 | 
2025-12-03 11:18:44.453888 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-03 11:18:44.759543 | controller | changed: non-zero return code
2025-12-03 11:18:44.765467 | 
2025-12-03 11:18:44.765595 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-03 11:18:44.780591 | controller | skipping: Conditional result was False
2025-12-03 11:18:44.787342 | 
2025-12-03 11:18:44.787469 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-03 11:18:44.821470 | 
2025-12-03 11:18:44.821626 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-03 11:18:44.852254 | 
2025-12-03 11:18:44.852407 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-03 11:18:44.876647 | controller | skipping: Conditional result was False
2025-12-03 11:18:44.882955 | 
2025-12-03 11:18:44.883051 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-03 11:18:44.914414 | 
2025-12-03 11:18:44.914586 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-03 11:18:44.929056 | controller | skipping: Conditional result was False
2025-12-03 11:18:44.936147 | 
2025-12-03 11:18:44.936245 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-03 11:18:44.956551 | controller | skipping: Conditional result was False
2025-12-03 11:18:44.963716 | 
2025-12-03 11:18:44.963809 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-03 11:18:44.982832 | controller | skipping: Conditional result was False
2025-12-03 11:18:45.010051 | 
2025-12-03 11:18:45.010158 | PLAY RECAP
2025-12-03 11:18:45.010199 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-03 11:18:45.010218 | 
2025-12-03 11:18:45.113158 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-03 11:18:45.114221 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-03 11:18:45.708719 | 
2025-12-03 11:18:45.708836 | PLAY [all]
2025-12-03 11:18:45.728256 | 
2025-12-03 11:18:45.728383 | TASK [include_role : fetch-output]
2025-12-03 11:18:45.778354 | controller | ok
2025-12-03 11:18:45.797469 | 
2025-12-03 11:18:45.797612 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-03 11:18:45.852844 | controller | skipping: Conditional result was False
2025-12-03 11:18:45.858542 | 
2025-12-03 11:18:45.858622 | TASK [fetch-output : Set log path for single node]
2025-12-03 11:18:45.888099 | controller | ok
2025-12-03 11:18:45.896266 | 
2025-12-03 11:18:45.896371 | LOOP [fetch-output : Ensure local output dirs]
2025-12-03 11:18:46.269557 | controller -> localhost | ok: "/var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/logs"
2025-12-03 11:18:46.487077 | controller -> localhost | changed: "/var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/artifacts"
2025-12-03 11:18:46.691201 | controller -> localhost | changed: "/var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/docs"
2025-12-03 11:18:46.704468 | 
2025-12-03 11:18:46.704582 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-03 11:18:47.413634 | controller | changed: .d..t...... ./
2025-12-03 11:18:47.428159 | controller | changed: All items complete
2025-12-03 11:18:47.428295 | 
2025-12-03 11:18:47.853614 | controller | changed: .d..t...... ./
2025-12-03 11:18:48.310327 | controller | changed: .d..t...... ./
2025-12-03 11:18:48.330602 | 
2025-12-03 11:18:48.330707 | TASK [include_role : fetch-output-openshift]
2025-12-03 11:18:48.344835 | controller | skipping: Conditional result was False
2025-12-03 11:18:48.350819 | 
2025-12-03 11:18:48.350886 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-03 11:18:48.777705 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.011189
2025-12-03 11:18:48.992110 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006806
2025-12-03 11:18:49.028908 | 
2025-12-03 11:18:49.029065 | PLAY [all]
2025-12-03 11:18:49.045440 | 
2025-12-03 11:18:49.045523 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-03 11:18:49.544149 | controller | changed
2025-12-03 11:18:49.603825 | 
2025-12-03 11:18:49.603903 | PLAY RECAP
2025-12-03 11:18:49.603942 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-03 11:18:49.603963 | 
2025-12-03 11:18:49.707240 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-03 11:18:49.708178 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-03 11:18:53.800766 | 
2025-12-03 11:18:53.800906 | PLAY [localhost]
2025-12-03 11:18:53.820178 | 
2025-12-03 11:18:53.820271 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-03 11:18:54.205386 | localhost | changed
2025-12-03 11:18:54.215147 | 
2025-12-03 11:18:54.215273 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-03 11:18:54.243235 | localhost | ok
2025-12-03 11:18:54.256542 | 
2025-12-03 11:18:54.256613 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-03 11:18:54.651728 | localhost | changed
2025-12-03 11:18:54.657547 | 
2025-12-03 11:18:54.657621 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-03 11:18:55.306567 | localhost | changed
2025-12-03 11:18:55.311883 | 
2025-12-03 11:18:55.311947 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-03 11:18:55.696628 | localhost | Identity added: /var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/tmp/ansible.8pn55_kk (/var/lib/zuul/builds/5b77e044aca74642962f84b49c22c001/work/tmp/ansible.8pn55_kk)
2025-12-03 11:18:55.696853 | localhost | ok: Runtime: 0:00:00.009792
2025-12-03 11:18:55.703866 | 
2025-12-03 11:18:55.703958 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-03 11:18:55.968004 | localhost | ok: Runtime: 0:00:00.005125
2025-12-03 11:18:55.973049 | 
2025-12-03 11:18:55.973112 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-03 11:18:56.023546 | localhost | changed
2025-12-03 11:18:56.028409 | 
2025-12-03 11:18:56.028477 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-03 11:18:56.464810 | localhost | changed
2025-12-03 11:18:56.484946 | 
2025-12-03 11:18:56.485051 | PLAY [localhost]
2025-12-03 11:18:56.497180 | 
2025-12-03 11:18:56.497249 | TASK [Generate bulk log download script]
2025-12-03 11:18:56.515281 | localhost | ok
2025-12-03 11:18:56.527878 | 
2025-12-03 11:18:56.527946 | TASK [local-log-download : Check API endpoint is defined]
2025-12-03 11:18:56.555806 | localhost | ok: All assertions passed
2025-12-03 11:18:56.560443 | 
2025-12-03 11:18:56.560505 | TASK [local-log-download : Create download script]
2025-12-03 11:18:56.949542 | localhost -> localhost | changed
2025-12-03 11:18:56.958769 | 
2025-12-03 11:18:56.958849 | TASK [Register quick-download link]
2025-12-03 11:18:56.977647 | localhost | ok
2025-12-03 11:18:57.031901 | 
2025-12-03 11:18:57.031991 | PLAY [logserver.rdoproject.org]
2025-12-03 11:18:57.041901 | 
2025-12-03 11:18:57.041982 | TASK [Set zuul-log-path fact]
2025-12-03 11:18:57.058814 | logserver.rdoproject.org | ok
2025-12-03 11:18:57.069096 | 
2025-12-03 11:18:57.069184 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-03 11:18:57.095675 | logserver.rdoproject.org | ok
2025-12-03 11:18:57.103196 | 
2025-12-03 11:18:57.103276 | TASK [upload-logs : Create log directories]
2025-12-03 11:18:57.849219 | logserver.rdoproject.org | changed
2025-12-03 11:18:57.852761 | 
2025-12-03 11:18:57.852824 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-03 11:18:58.141321 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004645
2025-12-03 11:18:58.145848 | 
2025-12-03 11:18:58.145911 | TASK [upload-logs : Upload logs to log server]
2025-12-03 11:18:58.805646 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-03 11:18:58.808840 | 
2025-12-03 11:18:58.808904 | LOOP [upload-logs : Compress console log and json output]
2025-12-03 11:18:58.875104 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:18:58.889330 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:18:58.902753 | 
2025-12-03 11:18:58.902889 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-03 11:18:58.961563 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:18:58.962011 | 
2025-12-03 11:18:58.965492 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:18:58.973203 | 
2025-12-03 11:18:58.973322 | LOOP [upload-logs : Upload console log and json output]