2025-10-07 07:28:23.695132 | Job console starting...
2025-10-07 07:28:23.709412 | Updating repositories
2025-10-07 07:28:23.797371 | Preparing job workspace
2025-10-07 07:28:27.261085 | Running Ansible setup...
2025-10-07 07:28:31.183198 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-07 07:28:31.801754 | 
2025-10-07 07:28:31.801866 | PLAY [localhost]
2025-10-07 07:28:31.810395 | 
2025-10-07 07:28:31.810498 | TASK [Gathering Facts]
2025-10-07 07:28:32.721804 | localhost | ok
2025-10-07 07:28:32.753044 | 
2025-10-07 07:28:32.753518 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-07 07:28:33.206899 | localhost -> localhost | changed
2025-10-07 07:28:33.215378 | 
2025-10-07 07:28:33.215482 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-07 07:28:34.038376 | localhost -> localhost | changed
2025-10-07 07:28:34.046836 | 
2025-10-07 07:28:34.046918 | TASK [Setup log path fact]
2025-10-07 07:28:34.065031 | localhost | ok
2025-10-07 07:28:34.076836 | 
2025-10-07 07:28:34.076926 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-07 07:28:34.104715 | localhost | ok
2025-10-07 07:28:34.112405 | 
2025-10-07 07:28:34.112465 | TASK [emit-job-header : Print job information]
2025-10-07 07:28:34.139836 | # Job Information
2025-10-07 07:28:34.140000 | Ansible Version: 2.15.12
2025-10-07 07:28:34.140026 | Job: cifmw-molecule-cleanup_openstack
2025-10-07 07:28:34.140047 | Pipeline: github-check
2025-10-07 07:28:34.140065 | Executor: ze04.softwarefactory-project.io
2025-10-07 07:28:34.140083 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366
2025-10-07 07:28:34.140102 | Log URL (when completed): https://logserver.rdoproject.org/747/rdoproject.org/7475b53316c14abdac800a1cc59c20b9/
2025-10-07 07:28:34.140120 | Event ID: 0b3e6df0-a34f-11f0-8d70-8afb6d89ca3c
2025-10-07 07:28:34.144895 | 
2025-10-07 07:28:34.146527 | LOOP [emit-job-header : Print node information]
2025-10-07 07:28:34.260635 | localhost | ok:
2025-10-07 07:28:34.260834 | localhost | # Node Information
2025-10-07 07:28:34.260864 | localhost | Inventory Hostname: controller
2025-10-07 07:28:34.260898 | localhost | Hostname: np0005472996
2025-10-07 07:28:34.260923 | localhost | Username: zuul
2025-10-07 07:28:34.260948 | localhost | Distro: CentOS 9
2025-10-07 07:28:34.260971 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-07 07:28:34.260993 | localhost | Region: RegionOne
2025-10-07 07:28:34.261015 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-07 07:28:34.261036 | localhost | Product Name: OpenStack Nova
2025-10-07 07:28:34.261058 | localhost | Interface IP: 38.102.83.217
2025-10-07 07:28:34.301416 | 
2025-10-07 07:28:34.301580 | PLAY [all]
2025-10-07 07:28:34.311179 | 
2025-10-07 07:28:34.311266 | TASK [Gather network facts]
2025-10-07 07:28:34.865672 | controller | ok
2025-10-07 07:28:34.889909 | 
2025-10-07 07:28:34.890036 | TASK [include_role : start-zuul-console]
2025-10-07 07:28:34.914409 | controller | ok
2025-10-07 07:28:34.933139 | 
2025-10-07 07:28:34.933251 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-07 07:28:35.384457 | controller | ok
2025-10-07 07:28:35.407346 | 
2025-10-07 07:28:35.407499 | TASK [include_role : add-build-sshkey]
2025-10-07 07:28:35.447035 | controller | ok
2025-10-07 07:28:35.474530 | 
2025-10-07 07:28:35.474674 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-07 07:28:35.757265 | controller -> localhost | ok
2025-10-07 07:28:35.771926 | 
2025-10-07 07:28:35.772116 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-07 07:28:35.810411 | controller | ok
2025-10-07 07:28:35.849813 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-07 07:28:35.863604 | 
2025-10-07 07:28:35.863835 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-07 07:28:36.443771 | controller -> localhost | Generating public/private rsa key pair.
2025-10-07 07:28:36.444245 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/7475b53316c14abdac800a1cc59c20b9_id_rsa.
2025-10-07 07:28:36.444322 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/7475b53316c14abdac800a1cc59c20b9_id_rsa.pub.
2025-10-07 07:28:36.444373 | controller -> localhost | The key fingerprint is:
2025-10-07 07:28:36.444420 | controller -> localhost | SHA256:tDqq8dBPNZYEk/I4iAr9JinFMnISLSjWB+c/GMSA7KY zuul-build-sshkey
2025-10-07 07:28:36.444465 | controller -> localhost | The key's randomart image is:
2025-10-07 07:28:36.444513 | controller -> localhost | +---[RSA 3072]----+
2025-10-07 07:28:36.444555 | controller -> localhost | |o.oo+oo.         |
2025-10-07 07:28:36.444596 | controller -> localhost | |=+..=o.o         |
2025-10-07 07:28:36.444637 | controller -> localhost | |+* ..*  o        |
2025-10-07 07:28:36.444716 | controller -> localhost | |Bo* o =o o       |
2025-10-07 07:28:36.444771 | controller -> localhost | |** o o oS        |
2025-10-07 07:28:36.444814 | controller -> localhost | |E o.o  +..       |
2025-10-07 07:28:36.444882 | controller -> localhost | | .oo. +          |
2025-10-07 07:28:36.444932 | controller -> localhost | |   + + .         |
2025-10-07 07:28:36.444974 | controller -> localhost | |  ..o .          |
2025-10-07 07:28:36.445015 | controller -> localhost | +----[SHA256]-----+
2025-10-07 07:28:36.445106 | controller -> localhost | ok: Runtime: 0:00:00.178869
2025-10-07 07:28:36.457781 | 
2025-10-07 07:28:36.458253 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-07 07:28:36.496641 | controller | ok
2025-10-07 07:28:36.518568 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-07 07:28:36.530508 | 
2025-10-07 07:28:36.530595 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-07 07:28:36.555809 | controller | skipping: Conditional result was False
2025-10-07 07:28:36.563939 | 
2025-10-07 07:28:36.564024 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-07 07:28:37.065119 | controller | changed
2025-10-07 07:28:37.076524 | 
2025-10-07 07:28:37.076667 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-07 07:28:37.400746 | controller | ok
2025-10-07 07:28:37.411882 | 
2025-10-07 07:28:37.412028 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-07 07:28:38.265118 | controller | changed
2025-10-07 07:28:38.275848 | 
2025-10-07 07:28:38.276010 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-07 07:28:39.242140 | controller | changed
2025-10-07 07:28:39.253295 | 
2025-10-07 07:28:39.253422 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-07 07:28:39.281128 | controller | skipping: Conditional result was False
2025-10-07 07:28:39.293805 | 
2025-10-07 07:28:39.293941 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-07 07:28:39.708049 | controller -> localhost | changed
2025-10-07 07:28:39.723320 | 
2025-10-07 07:28:39.723431 | TASK [add-build-sshkey : Add back temp key]
2025-10-07 07:28:40.065335 | controller -> localhost | Identity added: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/7475b53316c14abdac800a1cc59c20b9_id_rsa (zuul-build-sshkey)
2025-10-07 07:28:40.065787 | controller -> localhost | ok: Runtime: 0:00:00.016134
2025-10-07 07:28:40.077906 | 
2025-10-07 07:28:40.078037 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-07 07:28:40.500090 | controller | ok
2025-10-07 07:28:40.510173 | 
2025-10-07 07:28:40.510270 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-07 07:28:40.548857 | controller | skipping: Conditional result was False
2025-10-07 07:28:40.558652 | 
2025-10-07 07:28:40.558755 | TASK [include_role : validate-host]
2025-10-07 07:28:40.578087 | controller | ok
2025-10-07 07:28:40.597580 | 
2025-10-07 07:28:40.597651 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-07 07:28:40.625944 | controller | ok
2025-10-07 07:28:40.630561 | 
2025-10-07 07:28:40.630624 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-07 07:28:40.898912 | controller -> localhost | ok
2025-10-07 07:28:40.905109 | 
2025-10-07 07:28:40.905174 | TASK [validate-host : Collect information about the host]
2025-10-07 07:28:41.795481 | controller | ok
2025-10-07 07:28:41.804614 | 
2025-10-07 07:28:41.804741 | TASK [validate-host : Sanitize hostname]
2025-10-07 07:28:41.863416 | controller | ok
2025-10-07 07:28:41.868512 | 
2025-10-07 07:28:41.868574 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-07 07:28:42.329282 | controller -> localhost | changed
2025-10-07 07:28:42.341038 | 
2025-10-07 07:28:42.341184 | TASK [validate-host : Collect information about zuul worker]
2025-10-07 07:28:42.764458 | controller | ok
2025-10-07 07:28:42.769105 | 
2025-10-07 07:28:42.769185 | TASK [validate-host : Write out all zuul information for each host]
2025-10-07 07:28:43.208567 | controller -> localhost | changed
2025-10-07 07:28:43.218318 | 
2025-10-07 07:28:43.218427 | TASK [include_role : prepare-workspace-openshift]
2025-10-07 07:28:43.249905 | controller | skipping: Conditional result was False
2025-10-07 07:28:43.255544 | 
2025-10-07 07:28:43.255622 | TASK [include_role : remove-zuul-sshkey]
2025-10-07 07:28:43.279738 | controller | skipping: Conditional result was False
2025-10-07 07:28:43.285138 | 
2025-10-07 07:28:43.285236 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-07 07:28:43.585031 | controller | ok: "logs"
2025-10-07 07:28:43.585258 | controller | ok: All items complete
2025-10-07 07:28:43.585285 | 
2025-10-07 07:28:43.855291 | controller | ok: "artifacts"
2025-10-07 07:28:44.096925 | controller | ok: "docs"
2025-10-07 07:28:44.113003 | 
2025-10-07 07:28:44.113141 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-07 07:28:44.477038 | controller | changed: "logs"
2025-10-07 07:28:44.729038 | controller | changed: "artifacts"
2025-10-07 07:28:44.999757 | controller | changed: "docs"
2025-10-07 07:28:45.027669 | 
2025-10-07 07:28:45.027800 | PLAY RECAP
2025-10-07 07:28:45.027843 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-07 07:28:45.027871 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-07 07:28:45.027890 | 
2025-10-07 07:28:45.138590 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-07 07:28:45.139537 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-07 07:28:45.738105 | 
2025-10-07 07:28:45.738265 | PLAY [localhost]
2025-10-07 07:28:45.756521 | 
2025-10-07 07:28:45.756665 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-07 07:28:46.228453 | localhost | ok
2025-10-07 07:28:46.242043 | 
2025-10-07 07:28:46.242209 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-07 07:28:46.911265 | localhost | changed
2025-10-07 07:28:46.950242 | 
2025-10-07 07:28:46.950341 | PLAY [all]
2025-10-07 07:28:46.973602 | 
2025-10-07 07:28:46.973750 | TASK [include_role : prepare-workspace]
2025-10-07 07:28:47.005082 | controller | ok
2025-10-07 07:28:47.025877 | 
2025-10-07 07:28:47.025994 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-07 07:28:47.494065 | controller | ok
2025-10-07 07:28:47.500883 | 
2025-10-07 07:28:47.500966 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-07 07:28:49.232589 | controller | Output suppressed because no_log was given
2025-10-07 07:28:49.242105 | 
2025-10-07 07:28:49.242168 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-07 07:28:49.552906 | controller | changed: "logs"
2025-10-07 07:28:49.831118 | controller | changed: "artifacts"
2025-10-07 07:28:50.085335 | controller | changed: "docs"
2025-10-07 07:28:50.103193 | 
2025-10-07 07:28:50.103388 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-07 07:28:50.462727 | controller | changed: "logs"
2025-10-07 07:28:50.463159 | controller | changed: All items complete
2025-10-07 07:28:50.463261 | 
2025-10-07 07:28:50.737845 | controller | changed: "artifacts"
2025-10-07 07:28:50.989229 | controller | changed: "docs"
2025-10-07 07:28:51.014015 | 
2025-10-07 07:28:51.014159 | TASK [Check if worker can sudo]
2025-10-07 07:28:51.595810 | controller | ok: Runtime: 0:00:00.066288
2025-10-07 07:28:51.611028 | 
2025-10-07 07:28:51.611385 | TASK [configure-mirrors : Gather needed facts]
2025-10-07 07:28:51.689882 | controller | skipping: Conditional result was False
2025-10-07 07:28:51.704755 | 
2025-10-07 07:28:51.704973 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-07 07:28:51.784389 | controller | ok
2025-10-07 07:28:51.801986 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-07 07:28:51.814867 | 
2025-10-07 07:28:51.814962 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-07 07:28:52.188940 | controller | ok
2025-10-07 07:28:52.205063 | 
2025-10-07 07:28:52.205168 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-07 07:28:52.279338 | controller | ok: "/var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-07 07:28:52.290324 | 
2025-10-07 07:28:52.290489 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-07 07:28:53.255859 | controller | changed
2025-10-07 07:28:53.261550 | 
2025-10-07 07:28:53.261618 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-07 07:28:53.351515 | controller | ok: "/var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-07 07:28:53.351751 | controller | ok: All items complete
2025-10-07 07:28:53.351780 | 
2025-10-07 07:28:53.418773 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-07 07:28:53.425523 | 
2025-10-07 07:28:53.425589 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-07 07:28:54.512150 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-07 07:28:55.525997 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-07 07:28:55.548497 | 
2025-10-07 07:28:55.548719 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-07 07:28:56.056856 | controller | changed: section and option added
2025-10-07 07:28:56.099809 | 
2025-10-07 07:28:56.099941 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-07 07:28:57.052522 | controller | 29 files removed
2025-10-07 07:28:57.052960 | controller | ok: Item: dnf clean all Runtime: 0:00:00.538268
2025-10-07 07:28:57.053047 | controller | changed: All items complete
2025-10-07 07:28:57.053095 | 
2025-10-07 07:29:07.561342 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-10-07 07:29:07.561517 | controller | DNF version: 4.14.0
2025-10-07 07:29:07.561572 | controller | cachedir: /var/cache/dnf
2025-10-07 07:29:07.561617 | controller | Making cache files for all metadata files.
2025-10-07 07:29:07.561657 | controller | baseos: has expired and will be refreshed.
2025-10-07 07:29:07.561734 | controller | appstream: has expired and will be refreshed.
2025-10-07 07:29:07.561777 | controller | crb: has expired and will be refreshed.
2025-10-07 07:29:07.561832 | controller | extras-common: has expired and will be refreshed.
2025-10-07 07:29:07.561870 | controller | repo: downloading from remote: baseos
2025-10-07 07:29:07.561906 | controller | CentOS Stream 9 - BaseOS                         71 MB/s | 8.8 MB     00:00
2025-10-07 07:29:07.561943 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-07 07:29:07.561979 | controller | repo: downloading from remote: appstream
2025-10-07 07:29:07.562014 | controller | CentOS Stream 9 - AppStream                     108 MB/s |  25 MB     00:00
2025-10-07 07:29:07.562049 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-07 07:29:07.562083 | controller | repo: downloading from remote: crb
2025-10-07 07:29:07.562118 | controller | CentOS Stream 9 - CRB                            89 MB/s | 7.1 MB     00:00
2025-10-07 07:29:07.562155 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-07 07:29:07.562190 | controller | repo: downloading from remote: extras-common
2025-10-07 07:29:07.562227 | controller | CentOS Stream 9 - Extras packages               1.6 MB/s |  20 kB     00:00
2025-10-07 07:29:07.562264 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-07 07:29:07.562300 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-07 07:29:07.562335 | controller | Completion plugin: Generating completion cache...
2025-10-07 07:29:07.562370 | controller | Metadata cache created.
2025-10-07 07:29:07.562426 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.187556
2025-10-07 07:29:07.588816 | 
2025-10-07 07:29:07.588966 | PLAY RECAP
2025-10-07 07:29:07.589052 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-07 07:29:07.589107 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-07 07:29:07.589147 | 
2025-10-07 07:29:07.700573 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-07 07:29:07.701494 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-07 07:29:08.360587 | 
2025-10-07 07:29:08.360706 | PLAY [all]
2025-10-07 07:29:08.392529 | 
2025-10-07 07:29:08.392640 | TASK [Install binary dependencies]
2025-10-07 07:29:08.464285 | controller | ok
2025-10-07 07:29:08.490288 | 
2025-10-07 07:29:08.490453 | TASK [bindep : Include find tasks]
2025-10-07 07:29:08.518961 | controller | ok
2025-10-07 07:29:08.526207 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-07 07:29:08.532468 | 
2025-10-07 07:29:08.532543 | TASK [bindep : Look for bindep.txt]
2025-10-07 07:29:08.969455 | controller | ok
2025-10-07 07:29:08.983559 | 
2025-10-07 07:29:08.983732 | TASK [bindep : Define bindep_file fact]
2025-10-07 07:29:09.021558 | controller | ok
2025-10-07 07:29:09.033188 | 
2025-10-07 07:29:09.033326 | TASK [bindep : Look for other-requirements.txt]
2025-10-07 07:29:09.050937 | controller | skipping: Conditional result was False
2025-10-07 07:29:09.063670 | 
2025-10-07 07:29:09.063861 | TASK [bindep : Define bindep_file fact]
2025-10-07 07:29:09.092561 | controller | skipping: Conditional result was False
2025-10-07 07:29:09.105071 | 
2025-10-07 07:29:09.105209 | TASK [bindep : Look for bindep fallback file]
2025-10-07 07:29:09.131946 | controller | skipping: Conditional result was False
2025-10-07 07:29:09.146506 | 
2025-10-07 07:29:09.146648 | TASK [bindep : Define bindep_file fact]
2025-10-07 07:29:09.183798 | controller | skipping: Conditional result was False
2025-10-07 07:29:09.196036 | 
2025-10-07 07:29:09.196185 | TASK [bindep : Include bindep tasks]
2025-10-07 07:29:09.247915 | controller | ok
2025-10-07 07:29:09.262476 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-07 07:29:09.275131 | 
2025-10-07 07:29:09.275214 | TASK [bindep : Look for bindep command]
2025-10-07 07:29:09.310816 | controller | skipping: Conditional result was False
2025-10-07 07:29:09.319274 | 
2025-10-07 07:29:09.319377 | TASK [bindep : Check for system bindep]
2025-10-07 07:29:09.865090 | controller | ok: Runtime: 0:00:00.008895
2025-10-07 07:29:09.870868 | 
2025-10-07 07:29:09.870933 | TASK [bindep : Define bindep_command fact]
2025-10-07 07:29:09.894463 | controller | skipping: Conditional result was False
2025-10-07 07:29:09.899967 | 
2025-10-07 07:29:09.900037 | TASK [bindep : Include install tasks]
2025-10-07 07:29:09.928129 | controller | ok
2025-10-07 07:29:09.935284 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-07 07:29:09.944154 | 
2025-10-07 07:29:09.944214 | TASK [bindep : Create temp dir for bindep]
2025-10-07 07:29:10.374709 | controller | changed
2025-10-07 07:29:10.386471 | 
2025-10-07 07:29:10.386609 | TASK [Ensure we have pip dependencies]
2025-10-07 07:29:10.415029 | controller | ok
2025-10-07 07:29:10.455276 | 
2025-10-07 07:29:10.455366 | TASK [ensure-pip : Check if pip is installed]
2025-10-07 03:29:10.776751 | controller | /usr/bin/pip3
2025-10-07 03:29:10.804701 | controller | /usr/bin/python3: No module named wheel
2025-10-07 07:29:10.989571 | controller | ok: Runtime: 0:00:00.040808
2025-10-07 07:29:10.995229 | 
2025-10-07 07:29:10.995292 | LOOP [ensure-pip : Install pip from packages]
2025-10-07 07:29:11.041141 | controller | ok: "/var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-07 07:29:11.060000 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-07 07:29:11.083801 | 
2025-10-07 07:29:11.083885 | TASK [ensure-pip : Install Python 3 pip]
2025-10-07 07:29:13.555867 | controller | changed
2025-10-07 07:29:13.567326 | 
2025-10-07 07:29:13.567449 | TASK [ensure-pip : Check for EPEL repository]
2025-10-07 07:29:13.626001 | controller | skipping: Conditional result was False
2025-10-07 07:29:13.639954 | 
2025-10-07 07:29:13.640107 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-07 07:29:13.689981 | controller | skipping: Conditional result was False
2025-10-07 07:29:13.705376 | 
2025-10-07 07:29:13.705598 | TASK [ensure-pip : Install Python 2 pip]
2025-10-07 07:29:13.754398 | controller | skipping: Conditional result was False
2025-10-07 07:29:13.770411 | 
2025-10-07 07:29:13.770613 | TASK [ensure-pip : Ensure setuptools]
2025-10-07 07:29:13.798672 | controller | skipping: Conditional result was False
2025-10-07 07:29:13.812803 | 
2025-10-07 07:29:13.813041 | TASK [ensure-pip : Check for ensurepip module]
2025-10-07 07:29:14.374721 | controller | skipping: Conditional result was False
2025-10-07 07:29:14.389298 | 
2025-10-07 07:29:14.389454 | TASK [ensure-pip : Ensure python3-venv]
2025-10-07 07:29:14.416518 | controller | skipping: Conditional result was False
2025-10-07 07:29:14.430003 | 
2025-10-07 07:29:14.430204 | TASK [ensure-pip : Install pip from source]
2025-10-07 07:29:14.457045 | controller | skipping: Conditional result was False
2025-10-07 07:29:14.470115 | 
2025-10-07 07:29:14.470262 | TASK [ensure-pip : Probe for venv python full path]
2025-10-07 03:29:14.791961 | controller | /usr/bin/python3
2025-10-07 07:29:15.023168 | controller | ok: Runtime: 0:00:00.008262
2025-10-07 07:29:15.035875 | 
2025-10-07 07:29:15.036021 | TASK [ensure-pip : Set host default]
2025-10-07 07:29:15.114773 | controller | ok
2025-10-07 07:29:15.126011 | 
2025-10-07 07:29:15.126191 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-07 07:29:15.189023 | controller | ok
2025-10-07 07:29:15.213000 | 
2025-10-07 07:29:15.213144 | TASK [bindep : Install bindep into temporary venv]
2025-10-07 07:29:19.388370 | controller | changed
2025-10-07 07:29:19.401999 | 
2025-10-07 07:29:19.402142 | TASK [bindep : Define bindep_command]
2025-10-07 07:29:19.452757 | controller | ok
2025-10-07 07:29:19.465157 | 
2025-10-07 07:29:19.465300 | LOOP [bindep : Include package tasks]
2025-10-07 07:29:19.533115 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-07 07:29:19.533368 | controller | ok: All items complete
2025-10-07 07:29:19.533406 | 
2025-10-07 07:29:19.563751 | controller | included: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-07 07:29:19.588575 | 
2025-10-07 07:29:19.588725 | TASK [bindep : Define bindep_run fact]
2025-10-07 07:29:19.630734 | controller | ok
2025-10-07 07:29:19.638076 | 
2025-10-07 07:29:19.638165 | TASK [bindep : Get list of packages to install from bindep]
2025-10-07 03:29:21.181861 | controller | podman
2025-10-07 03:29:21.216155 | controller | python3-jmespath
2025-10-07 03:29:21.216397 | controller | python3-libvirt
2025-10-07 03:29:21.216417 | controller | python3-lxml
2025-10-07 03:29:21.216436 | controller | python3-netaddr
2025-10-07 07:29:21.681896 | controller | ok: Runtime: 0:00:01.272053
2025-10-07 07:29:21.697335 | 
2025-10-07 07:29:21.697479 | TASK [bindep : Install distro packages from bindep]
2025-10-07 07:30:24.278574 | controller | changed
2025-10-07 07:30:24.283901 | 
2025-10-07 07:30:24.283963 | TASK [bindep : Check that packages are installed]
2025-10-07 07:30:25.815325 | controller | ok: Runtime: 0:00:01.162323
2025-10-07 07:30:25.821190 | 
2025-10-07 07:30:25.821267 | TASK [bindep : Fail if we cannot install all packages]
2025-10-07 07:30:25.845017 | controller | skipping: Conditional result was False
2025-10-07 07:30:25.855990 | 
2025-10-07 07:30:25.856055 | TASK [Run test-setup role]
2025-10-07 07:30:25.874842 | controller | ok
2025-10-07 07:30:25.891420 | 
2025-10-07 07:30:25.891485 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-07 07:30:26.177473 | controller | ok
2025-10-07 07:30:26.183622 | 
2025-10-07 07:30:26.183718 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-07 07:30:26.711948 | controller | skipping: Conditional result was False
2025-10-07 07:30:26.749848 | 
2025-10-07 07:30:26.749954 | TASK [bindep : Remove bindep temp dir]
2025-10-07 07:30:27.164755 | controller | ok
2025-10-07 07:30:27.182872 | 
2025-10-07 07:30:27.182958 | PLAY RECAP
2025-10-07 07:30:27.183013 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-07 07:30:27.183041 | 
2025-10-07 07:30:27.282431 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-07 07:30:27.283264 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-07 07:30:27.845375 | 
2025-10-07 07:30:27.845533 | PLAY [all]
2025-10-07 07:30:27.865424 | 
2025-10-07 07:30:27.865544 | TASK [Abort when test_command variable is undefined]
2025-10-07 07:30:27.899982 | controller | skipping: Conditional result was False
2025-10-07 07:30:27.905720 | 
2025-10-07 07:30:27.905797 | TASK [Convert test_command to list]
2025-10-07 07:30:27.939754 | controller | skipping: Conditional result was False
2025-10-07 07:30:27.946024 | 
2025-10-07 07:30:27.946101 | TASK [Use test_command list]
2025-10-07 07:30:27.994593 | controller | ok
2025-10-07 07:30:28.000018 | 
2025-10-07 07:30:28.000089 | LOOP [Run test_command]
2025-10-07 07:30:28.430243 | controller | no check to run
2025-10-07 07:30:28.430459 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004919
2025-10-07 07:30:28.477611 | 
2025-10-07 07:30:28.477770 | PLAY RECAP
2025-10-07 07:30:28.477827 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-07 07:30:28.477855 | 
2025-10-07 07:30:28.591976 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-07 07:30:28.593076 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-07 07:30:29.210648 | 
2025-10-07 07:30:29.210796 | PLAY [all]
2025-10-07 07:30:29.232261 | 
2025-10-07 07:30:29.232399 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-07 07:30:29.710807 | controller | changed: non-zero return code
2025-10-07 07:30:29.723214 | 
2025-10-07 07:30:29.723382 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-07 07:30:29.751032 | controller | skipping: Conditional result was False
2025-10-07 07:30:29.763407 | 
2025-10-07 07:30:29.763571 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-07 07:30:29.795176 | 
2025-10-07 07:30:29.795476 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-07 07:30:29.838670 | 
2025-10-07 07:30:29.839026 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-07 07:30:29.866971 | controller | skipping: Conditional result was False
2025-10-07 07:30:29.881600 | 
2025-10-07 07:30:29.881731 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-07 07:30:29.916539 | 
2025-10-07 07:30:29.916763 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-07 07:30:29.941856 | controller | skipping: Conditional result was False
2025-10-07 07:30:29.951124 | 
2025-10-07 07:30:29.951236 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-07 07:30:29.966508 | controller | skipping: Conditional result was False
2025-10-07 07:30:29.974455 | 
2025-10-07 07:30:29.974543 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-07 07:30:29.999613 | controller | skipping: Conditional result was False
2025-10-07 07:30:30.033323 | 
2025-10-07 07:30:30.033384 | PLAY RECAP
2025-10-07 07:30:30.033426 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-07 07:30:30.033447 | 
2025-10-07 07:30:30.124870 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-07 07:30:30.125637 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-07 07:30:30.692137 | 
2025-10-07 07:30:30.692252 | PLAY [all]
2025-10-07 07:30:30.711848 | 
2025-10-07 07:30:30.711934 | TASK [include_role : fetch-output]
2025-10-07 07:30:30.745444 | controller | ok
2025-10-07 07:30:30.763119 | 
2025-10-07 07:30:30.763220 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-07 07:30:30.818003 | controller | skipping: Conditional result was False
2025-10-07 07:30:30.824113 | 
2025-10-07 07:30:30.824181 | TASK [fetch-output : Set log path for single node]
2025-10-07 07:30:30.855215 | controller | ok
2025-10-07 07:30:30.860284 | 
2025-10-07 07:30:30.860352 | LOOP [fetch-output : Ensure local output dirs]
2025-10-07 07:30:31.269363 | controller -> localhost | ok: "/var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/logs"
2025-10-07 07:30:31.495931 | controller -> localhost | changed: "/var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/artifacts"
2025-10-07 07:30:31.710820 | controller -> localhost | changed: "/var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/docs"
2025-10-07 07:30:31.726014 | 
2025-10-07 07:30:31.726167 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-07 07:30:32.401290 | controller | changed: .d..t...... ./
2025-10-07 07:30:32.403841 | controller | changed: All items complete
2025-10-07 07:30:32.403874 | 
2025-10-07 07:30:32.870492 | controller | changed: .d..t...... ./
2025-10-07 07:30:33.444216 | controller | changed: .d..t...... ./
2025-10-07 07:30:33.472149 | 
2025-10-07 07:30:33.472299 | TASK [include_role : fetch-output-openshift]
2025-10-07 07:30:33.486800 | controller | skipping: Conditional result was False
2025-10-07 07:30:33.495095 | 
2025-10-07 07:30:33.495192 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-07 07:30:33.890236 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013124
2025-10-07 07:30:34.128081 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012364
2025-10-07 07:30:34.169182 | 
2025-10-07 07:30:34.169291 | PLAY [all]
2025-10-07 07:30:34.184538 | 
2025-10-07 07:30:34.184655 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-07 07:30:34.673360 | controller | changed
2025-10-07 07:30:34.695178 | 
2025-10-07 07:30:34.695237 | PLAY RECAP
2025-10-07 07:30:34.695277 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-07 07:30:34.695296 | 
2025-10-07 07:30:34.793817 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-07 07:30:34.794652 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-07 07:30:35.415921 | 
2025-10-07 07:30:35.416043 | PLAY [localhost]
2025-10-07 07:30:35.444519 | 
2025-10-07 07:30:35.444642 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-07 07:30:35.809445 | localhost | changed
2025-10-07 07:30:35.814358 | 
2025-10-07 07:30:35.814437 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-07 07:30:35.842390 | localhost | ok
2025-10-07 07:30:35.850516 | 
2025-10-07 07:30:35.850586 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-07 07:30:36.194599 | localhost | changed
2025-10-07 07:30:36.200273 | 
2025-10-07 07:30:36.200384 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-07 07:30:36.809652 | localhost | changed
2025-10-07 07:30:36.814957 | 
2025-10-07 07:30:36.815025 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-07 07:30:37.259885 | localhost | Identity added: /var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/tmp/ansible.l2p75tzn (/var/lib/zuul/builds/7475b53316c14abdac800a1cc59c20b9/work/tmp/ansible.l2p75tzn)
2025-10-07 07:30:37.260056 | localhost | ok: Runtime: 0:00:00.007114
2025-10-07 07:30:37.264276 | 
2025-10-07 07:30:37.264340 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-07 07:30:37.516300 | localhost | ok: Runtime: 0:00:00.006768
2025-10-07 07:30:37.521473 | 
2025-10-07 07:30:37.521537 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-07 07:30:37.581416 | localhost | changed
2025-10-07 07:30:37.586666 | 
2025-10-07 07:30:37.586748 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-07 07:30:38.044021 | localhost | changed
2025-10-07 07:30:38.072369 | 
2025-10-07 07:30:38.072454 | PLAY [localhost]
2025-10-07 07:30:38.089880 | 
2025-10-07 07:30:38.089967 | TASK [Generate bulk log download script]
2025-10-07 07:30:38.111808 | localhost | ok
2025-10-07 07:30:38.127560 | 
2025-10-07 07:30:38.127672 | TASK [local-log-download : Check API endpoint is defined]
2025-10-07 07:30:38.178376 | localhost | ok: All assertions passed
2025-10-07 07:30:38.185394 | 
2025-10-07 07:30:38.185491 | TASK [local-log-download : Create download script]
2025-10-07 07:30:38.690426 | localhost -> localhost | changed
2025-10-07 07:30:38.699411 | 
2025-10-07 07:30:38.699475 | TASK [Register quick-download link]
2025-10-07 07:30:38.727666 | localhost | ok
2025-10-07 07:30:38.773693 | 
2025-10-07 07:30:38.773819 | PLAY [logserver.rdoproject.org]
2025-10-07 07:30:38.783427 | 
2025-10-07 07:30:38.783488 | TASK [Set zuul-log-path fact]
2025-10-07 07:30:38.799665 | logserver.rdoproject.org | ok
2025-10-07 07:30:38.808570 | 
2025-10-07 07:30:38.808645 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-07 07:30:38.845674 | logserver.rdoproject.org | ok
2025-10-07 07:30:38.853385 | 
2025-10-07 07:30:38.853473 | TASK [upload-logs : Create log directories]
2025-10-07 07:30:39.578395 | logserver.rdoproject.org | changed
2025-10-07 07:30:39.585446 | 
2025-10-07 07:30:39.585588 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-07 07:30:39.909003 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008479
2025-10-07 07:30:39.918443 | 
2025-10-07 07:30:39.918595 | TASK [upload-logs : Upload logs to log server]
2025-10-07 07:30:40.612196 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-07 07:30:40.618876 | 
2025-10-07 07:30:40.619026 | LOOP [upload-logs : Compress console log and json output]
2025-10-07 07:30:40.664727 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 07:30:40.685311 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 07:30:40.694392 | 
2025-10-07 07:30:40.694574 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-07 07:30:40.755169 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 07:30:40.755542 | 
2025-10-07 07:30:40.760873 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 07:30:40.771236 | 
2025-10-07 07:30:40.771427 | LOOP [upload-logs : Upload console log and json output]