2025-10-07 14:33:39.605329 | Job console starting...
2025-10-07 14:33:39.612960 | Updating repositories
2025-10-07 14:33:39.639764 | Preparing job workspace
2025-10-07 14:33:43.095319 | Running Ansible setup...
2025-10-07 14:33:47.317596 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-07 14:33:47.997316 | 
2025-10-07 14:33:47.997437 | PLAY [localhost]
2025-10-07 14:33:48.018531 | 
2025-10-07 14:33:48.018621 | TASK [Gathering Facts]
2025-10-07 14:33:49.153580 | localhost | ok
2025-10-07 14:33:49.168507 | 
2025-10-07 14:33:49.168614 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-07 14:33:49.578557 | localhost -> localhost | changed
2025-10-07 14:33:49.588235 | 
2025-10-07 14:33:49.588321 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-07 14:33:50.411762 | localhost -> localhost | changed
2025-10-07 14:33:50.421061 | 
2025-10-07 14:33:50.421136 | TASK [Setup log path fact]
2025-10-07 14:33:50.443721 | localhost | ok
2025-10-07 14:33:50.459801 | 
2025-10-07 14:33:50.459899 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-07 14:33:50.493136 | localhost | ok
2025-10-07 14:33:50.501861 | 
2025-10-07 14:33:50.501949 | TASK [emit-job-header : Print job information]
2025-10-07 14:33:50.542530 | # Job Information
2025-10-07 14:33:50.542710 | Ansible Version: 2.15.12
2025-10-07 14:33:50.542741 | Job: cifmw-molecule-switch_config
2025-10-07 14:33:50.542762 | Pipeline: github-check
2025-10-07 14:33:50.542781 | Executor: ze04.softwarefactory-project.io
2025-10-07 14:33:50.542798 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366
2025-10-07 14:33:50.542817 | Log URL (when completed): https://logserver.rdoproject.org/125/rdoproject.org/1258d0d4cfe547a49010c191c2c47a6b/
2025-10-07 14:33:50.542835 | Event ID: 640e52c0-a38a-11f0-87db-ca38cb57bc1b
2025-10-07 14:33:50.546753 | 
2025-10-07 14:33:50.546820 | LOOP [emit-job-header : Print node information]
2025-10-07 14:33:50.636713 | localhost | ok:
2025-10-07 14:33:50.636924 | localhost | # Node Information
2025-10-07 14:33:50.636951 | localhost | Inventory Hostname: controller
2025-10-07 14:33:50.636973 | localhost | Hostname: np0005474084
2025-10-07 14:33:50.636992 | localhost | Username: zuul
2025-10-07 14:33:50.637012 | localhost | Distro: CentOS 9
2025-10-07 14:33:50.637029 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-07 14:33:50.637046 | localhost | Region: RegionOne
2025-10-07 14:33:50.637083 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-07 14:33:50.637101 | localhost | Product Name: OpenStack Nova
2025-10-07 14:33:50.637118 | localhost | Interface IP: 38.129.56.100
2025-10-07 14:33:50.659063 | 
2025-10-07 14:33:50.659141 | PLAY [all]
2025-10-07 14:33:50.665649 | 
2025-10-07 14:33:50.665730 | TASK [Gather network facts]
2025-10-07 14:33:51.154058 | controller | ok
2025-10-07 14:33:51.181420 | 
2025-10-07 14:33:51.181568 | TASK [include_role : start-zuul-console]
2025-10-07 14:33:51.205204 | controller | ok
2025-10-07 14:33:51.221897 | 
2025-10-07 14:33:51.221993 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-07 14:33:51.688080 | controller | ok
2025-10-07 14:33:51.697306 | 
2025-10-07 14:33:51.697382 | TASK [include_role : add-build-sshkey]
2025-10-07 14:33:51.717627 | controller | ok
2025-10-07 14:33:51.731607 | 
2025-10-07 14:33:51.731694 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-07 14:33:51.965769 | controller -> localhost | ok
2025-10-07 14:33:51.972847 | 
2025-10-07 14:33:51.972916 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-07 14:33:52.003906 | controller | ok
2025-10-07 14:33:52.018502 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-07 14:33:52.024725 | 
2025-10-07 14:33:52.024788 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-07 14:33:52.518460 | controller -> localhost | Generating public/private rsa key pair.
2025-10-07 14:33:52.518733 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/1258d0d4cfe547a49010c191c2c47a6b_id_rsa.
2025-10-07 14:33:52.518769 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/1258d0d4cfe547a49010c191c2c47a6b_id_rsa.pub.
2025-10-07 14:33:52.518792 | controller -> localhost | The key fingerprint is:
2025-10-07 14:33:52.518811 | controller -> localhost | SHA256:R5uvPhjttUqGq0RYbgPhjiIvOe7ylPLKet438QkYSqU zuul-build-sshkey
2025-10-07 14:33:52.518830 | controller -> localhost | The key's randomart image is:
2025-10-07 14:33:52.518849 | controller -> localhost | +---[RSA 3072]----+
2025-10-07 14:33:52.518867 | controller -> localhost | |    .            |
2025-10-07 14:33:52.518884 | controller -> localhost | |   ...           |
2025-10-07 14:33:52.518902 | controller -> localhost | |   oo .   .      |
2025-10-07 14:33:52.518920 | controller -> localhost | |  Eo.=   . o     |
2025-10-07 14:33:52.518937 | controller -> localhost | |o...oo= S.+      |
2025-10-07 14:33:52.518955 | controller -> localhost | |.+...oo..o...    |
2025-10-07 14:33:52.518972 | controller -> localhost | |= +   .+.=o...   |
2025-10-07 14:33:52.518991 | controller -> localhost | |+*.. .o ++o..    |
2025-10-07 14:33:52.519008 | controller -> localhost | |*O+ ...o..+o     |
2025-10-07 14:33:52.519025 | controller -> localhost | +----[SHA256]-----+
2025-10-07 14:33:52.519071 | controller -> localhost | ok: Runtime: 0:00:00.075391
2025-10-07 14:33:52.525297 | 
2025-10-07 14:33:52.525365 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-07 14:33:52.555845 | controller | ok
2025-10-07 14:33:52.566424 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-07 14:33:52.574976 | 
2025-10-07 14:33:52.575047 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-07 14:33:52.599447 | controller | skipping: Conditional result was False
2025-10-07 14:33:52.604987 | 
2025-10-07 14:33:52.605051 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-07 14:33:53.120799 | controller | changed
2025-10-07 14:33:53.128460 | 
2025-10-07 14:33:53.128539 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-07 14:33:53.390002 | controller | ok
2025-10-07 14:33:53.406974 | 
2025-10-07 14:33:53.407137 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-07 14:33:54.313005 | controller | changed
2025-10-07 14:33:54.320268 | 
2025-10-07 14:33:54.320531 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-07 14:33:55.261138 | controller | changed
2025-10-07 14:33:55.270360 | 
2025-10-07 14:33:55.270422 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-07 14:33:55.304399 | controller | skipping: Conditional result was False
2025-10-07 14:33:55.311657 | 
2025-10-07 14:33:55.311772 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-07 14:33:55.902100 | controller -> localhost | changed
2025-10-07 14:33:55.919352 | 
2025-10-07 14:33:55.919452 | TASK [add-build-sshkey : Add back temp key]
2025-10-07 14:33:56.386236 | controller -> localhost | Identity added: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/1258d0d4cfe547a49010c191c2c47a6b_id_rsa (zuul-build-sshkey)
2025-10-07 14:33:56.386521 | controller -> localhost | ok: Runtime: 0:00:00.018522
2025-10-07 14:33:56.393504 | 
2025-10-07 14:33:56.393577 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-07 14:33:56.993176 | controller | ok
2025-10-07 14:33:56.998196 | 
2025-10-07 14:33:56.998260 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-07 14:33:57.057521 | controller | skipping: Conditional result was False
2025-10-07 14:33:57.067673 | 
2025-10-07 14:33:57.067754 | TASK [include_role : validate-host]
2025-10-07 14:33:57.086424 | controller | ok
2025-10-07 14:33:57.110801 | 
2025-10-07 14:33:57.110896 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-07 14:33:57.150391 | controller | ok
2025-10-07 14:33:57.155446 | 
2025-10-07 14:33:57.155507 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-07 14:33:57.460577 | controller -> localhost | ok
2025-10-07 14:33:57.525381 | 
2025-10-07 14:33:57.525491 | TASK [validate-host : Collect information about the host]
2025-10-07 14:33:58.268287 | controller | ok
2025-10-07 14:33:58.280869 | 
2025-10-07 14:33:58.280960 | TASK [validate-host : Sanitize hostname]
2025-10-07 14:33:58.353144 | controller | ok
2025-10-07 14:33:58.358313 | 
2025-10-07 14:33:58.358378 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-07 14:33:58.820973 | controller -> localhost | changed
2025-10-07 14:33:58.826454 | 
2025-10-07 14:33:58.826516 | TASK [validate-host : Collect information about zuul worker]
2025-10-07 14:33:59.247894 | controller | ok
2025-10-07 14:33:59.260817 | 
2025-10-07 14:33:59.260957 | TASK [validate-host : Write out all zuul information for each host]
2025-10-07 14:33:59.795240 | controller -> localhost | changed
2025-10-07 14:33:59.805665 | 
2025-10-07 14:33:59.805777 | TASK [include_role : prepare-workspace-openshift]
2025-10-07 14:33:59.831193 | controller | skipping: Conditional result was False
2025-10-07 14:33:59.836959 | 
2025-10-07 14:33:59.837033 | TASK [include_role : remove-zuul-sshkey]
2025-10-07 14:33:59.862295 | controller | skipping: Conditional result was False
2025-10-07 14:33:59.867951 | 
2025-10-07 14:33:59.868019 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-07 14:34:00.392507 | controller | ok: "logs"
2025-10-07 14:34:00.393010 | controller | ok: All items complete
2025-10-07 14:34:00.393047 | 
2025-10-07 14:34:00.649270 | controller | ok: "artifacts"
2025-10-07 14:34:00.906022 | controller | ok: "docs"
2025-10-07 14:34:00.917562 | 
2025-10-07 14:34:00.917704 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-07 14:34:01.222985 | controller | changed: "logs"
2025-10-07 14:34:01.452841 | controller | changed: "artifacts"
2025-10-07 14:34:01.681378 | controller | changed: "docs"
2025-10-07 14:34:01.716924 | 
2025-10-07 14:34:01.717074 | PLAY RECAP
2025-10-07 14:34:01.717121 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-07 14:34:01.717147 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-07 14:34:01.717165 | 
2025-10-07 14:34:01.878268 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-07 14:34:01.879169 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-07 14:34:02.671170 | 
2025-10-07 14:34:02.671372 | PLAY [localhost]
2025-10-07 14:34:02.724897 | 
2025-10-07 14:34:02.725176 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-07 14:34:03.408035 | localhost | ok
2025-10-07 14:34:03.415389 | 
2025-10-07 14:34:03.415476 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-07 14:34:04.245974 | localhost | changed
2025-10-07 14:34:04.275054 | 
2025-10-07 14:34:04.275147 | PLAY [all]
2025-10-07 14:34:04.301352 | 
2025-10-07 14:34:04.301473 | TASK [include_role : prepare-workspace]
2025-10-07 14:34:04.321546 | controller | ok
2025-10-07 14:34:04.339469 | 
2025-10-07 14:34:04.339545 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-07 14:34:04.827808 | controller | ok
2025-10-07 14:34:04.840853 | 
2025-10-07 14:34:04.840927 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-07 14:34:06.736278 | controller | Output suppressed because no_log was given
2025-10-07 14:34:06.750307 | 
2025-10-07 14:34:06.750386 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-07 14:34:07.034136 | controller | changed: "logs"
2025-10-07 14:34:07.312188 | controller | changed: "artifacts"
2025-10-07 14:34:07.535751 | controller | changed: "docs"
2025-10-07 14:34:07.547992 | 
2025-10-07 14:34:07.548299 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-07 14:34:07.841048 | controller | changed: "logs"
2025-10-07 14:34:07.841453 | controller | changed: All items complete
2025-10-07 14:34:07.841496 | 
2025-10-07 14:34:08.159834 | controller | changed: "artifacts"
2025-10-07 14:34:08.389145 | controller | changed: "docs"
2025-10-07 14:34:08.420282 | 
2025-10-07 14:34:08.420554 | TASK [Check if worker can sudo]
2025-10-07 14:34:09.468252 | controller | ok: Runtime: 0:00:00.150274
2025-10-07 14:34:09.474242 | 
2025-10-07 14:34:09.474305 | TASK [configure-mirrors : Gather needed facts]
2025-10-07 14:34:09.520536 | controller | skipping: Conditional result was False
2025-10-07 14:34:09.527384 | 
2025-10-07 14:34:09.527469 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-07 14:34:09.587585 | controller | ok
2025-10-07 14:34:09.595580 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-07 14:34:09.629248 | 
2025-10-07 14:34:09.629396 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-07 14:34:09.925057 | controller | ok
2025-10-07 14:34:09.931379 | 
2025-10-07 14:34:09.931462 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-07 14:34:10.003342 | controller | ok: "/var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-07 14:34:10.016111 | 
2025-10-07 14:34:10.016270 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-07 14:34:10.826812 | controller | changed
2025-10-07 14:34:10.832801 | 
2025-10-07 14:34:10.832872 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-07 14:34:10.911121 | controller | ok: "/var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-07 14:34:10.911378 | controller | ok: All items complete
2025-10-07 14:34:10.911403 | 
2025-10-07 14:34:10.962338 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-07 14:34:10.969876 | 
2025-10-07 14:34:10.969970 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-07 14:34:11.918956 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-07 14:34:12.749396 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-07 14:34:12.769184 | 
2025-10-07 14:34:12.769404 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-07 14:34:13.221465 | controller | changed: section and option added
2025-10-07 14:34:13.259980 | 
2025-10-07 14:34:13.260111 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-07 14:34:15.918246 | controller | 29 files removed
2025-10-07 14:34:15.918903 | controller | ok: Item: dnf clean all Runtime: 0:00:02.279156
2025-10-07 14:34:15.919013 | controller | changed: All items complete
2025-10-07 14:34:15.919060 | 
2025-10-07 14:34:30.486776 | 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 14:34:30.486919 | controller | DNF version: 4.14.0
2025-10-07 14:34:30.486953 | controller | cachedir: /var/cache/dnf
2025-10-07 14:34:30.486979 | controller | Making cache files for all metadata files.
2025-10-07 14:34:30.487003 | controller | baseos: has expired and will be refreshed.
2025-10-07 14:34:30.487026 | controller | appstream: has expired and will be refreshed.
2025-10-07 14:34:30.487048 | controller | crb: has expired and will be refreshed.
2025-10-07 14:34:30.487083 | controller | extras-common: has expired and will be refreshed.
2025-10-07 14:34:30.487107 | controller | repo: downloading from remote: baseos
2025-10-07 14:34:30.487129 | controller | CentOS Stream 9 - BaseOS                        6.5 MB/s | 8.8 MB     00:01
2025-10-07 14:34:30.487151 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-07 14:34:30.487173 | controller | repo: downloading from remote: appstream
2025-10-07 14:34:30.487195 | controller | CentOS Stream 9 - AppStream                      35 MB/s |  25 MB     00:00
2025-10-07 14:34:30.487216 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-07 14:34:30.487237 | controller | repo: downloading from remote: crb
2025-10-07 14:34:30.487258 | controller | CentOS Stream 9 - CRB                           9.8 MB/s | 7.1 MB     00:00
2025-10-07 14:34:30.487280 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-07 14:34:30.487301 | controller | repo: downloading from remote: extras-common
2025-10-07 14:34:30.487323 | controller | CentOS Stream 9 - Extras packages                83 kB/s |  20 kB     00:00
2025-10-07 14:34:30.487345 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-07 14:34:30.487366 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-07 14:34:30.487389 | controller | Completion plugin: Generating completion cache...
2025-10-07 14:34:30.487411 | controller | Metadata cache created.
2025-10-07 14:34:30.487446 | controller | ok: Item: dnf makecache -v Runtime: 0:00:14.235026
2025-10-07 14:34:30.507345 | 
2025-10-07 14:34:30.507495 | PLAY RECAP
2025-10-07 14:34:30.507541 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-07 14:34:30.507566 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-07 14:34:30.507583 | 
2025-10-07 14:34:30.673560 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-07 14:34:30.674794 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-07 14:34:33.881665 | 
2025-10-07 14:34:33.881837 | PLAY [all]
2025-10-07 14:34:33.907926 | 
2025-10-07 14:34:33.908015 | TASK [Install binary dependencies]
2025-10-07 14:34:33.961843 | controller | ok
2025-10-07 14:34:33.989270 | 
2025-10-07 14:34:33.989449 | TASK [bindep : Include find tasks]
2025-10-07 14:34:34.019764 | controller | ok
2025-10-07 14:34:34.027767 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-07 14:34:34.033968 | 
2025-10-07 14:34:34.034032 | TASK [bindep : Look for bindep.txt]
2025-10-07 14:34:34.520221 | controller | ok
2025-10-07 14:34:34.536428 | 
2025-10-07 14:34:34.536647 | TASK [bindep : Define bindep_file fact]
2025-10-07 14:34:34.586841 | controller | ok
2025-10-07 14:34:34.598579 | 
2025-10-07 14:34:34.598653 | TASK [bindep : Look for other-requirements.txt]
2025-10-07 14:34:34.634403 | controller | skipping: Conditional result was False
2025-10-07 14:34:34.642155 | 
2025-10-07 14:34:34.642233 | TASK [bindep : Define bindep_file fact]
2025-10-07 14:34:34.666241 | controller | skipping: Conditional result was False
2025-10-07 14:34:34.674798 | 
2025-10-07 14:34:34.674879 | TASK [bindep : Look for bindep fallback file]
2025-10-07 14:34:34.700808 | controller | skipping: Conditional result was False
2025-10-07 14:34:34.706645 | 
2025-10-07 14:34:34.707052 | TASK [bindep : Define bindep_file fact]
2025-10-07 14:34:34.732856 | controller | skipping: Conditional result was False
2025-10-07 14:34:34.739706 | 
2025-10-07 14:34:34.739934 | TASK [bindep : Include bindep tasks]
2025-10-07 14:34:34.773191 | controller | ok
2025-10-07 14:34:34.783597 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-07 14:34:34.793721 | 
2025-10-07 14:34:34.793853 | TASK [bindep : Look for bindep command]
2025-10-07 14:34:34.818726 | controller | skipping: Conditional result was False
2025-10-07 14:34:34.825761 | 
2025-10-07 14:34:34.825837 | TASK [bindep : Check for system bindep]
2025-10-07 14:34:35.357348 | controller | ok: Runtime: 0:00:00.005723
2025-10-07 14:34:35.365365 | 
2025-10-07 14:34:35.365454 | TASK [bindep : Define bindep_command fact]
2025-10-07 14:34:35.404887 | controller | skipping: Conditional result was False
2025-10-07 14:34:35.420575 | 
2025-10-07 14:34:35.420745 | TASK [bindep : Include install tasks]
2025-10-07 14:34:35.453175 | controller | ok
2025-10-07 14:34:35.474023 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-07 14:34:35.487578 | 
2025-10-07 14:34:35.487644 | TASK [bindep : Create temp dir for bindep]
2025-10-07 14:34:35.862199 | controller | changed
2025-10-07 14:34:35.872112 | 
2025-10-07 14:34:35.872187 | TASK [Ensure we have pip dependencies]
2025-10-07 14:34:35.913078 | controller | ok
2025-10-07 14:34:35.940224 | 
2025-10-07 14:34:35.940309 | TASK [ensure-pip : Check if pip is installed]
2025-10-07 10:34:36.485416 | controller | /usr/bin/pip3
2025-10-07 10:34:36.525349 | controller | /usr/bin/python3: No module named wheel
2025-10-07 14:34:36.966968 | controller | ok: Runtime: 0:00:00.099565
2025-10-07 14:34:36.973079 | 
2025-10-07 14:34:36.973155 | LOOP [ensure-pip : Install pip from packages]
2025-10-07 14:34:37.034077 | controller | ok: "/var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-07 14:34:37.046959 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-07 14:34:37.062923 | 
2025-10-07 14:34:37.063004 | TASK [ensure-pip : Install Python 3 pip]
2025-10-07 14:34:43.003388 | controller | changed
2025-10-07 14:34:43.015722 | 
2025-10-07 14:34:43.015870 | TASK [ensure-pip : Check for EPEL repository]
2025-10-07 14:34:43.075966 | controller | skipping: Conditional result was False
2025-10-07 14:34:43.092324 | 
2025-10-07 14:34:43.092496 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-07 14:34:43.151625 | controller | skipping: Conditional result was False
2025-10-07 14:34:43.166042 | 
2025-10-07 14:34:43.166182 | TASK [ensure-pip : Install Python 2 pip]
2025-10-07 14:34:43.214661 | controller | skipping: Conditional result was False
2025-10-07 14:34:43.225926 | 
2025-10-07 14:34:43.226022 | TASK [ensure-pip : Ensure setuptools]
2025-10-07 14:34:43.251207 | controller | skipping: Conditional result was False
2025-10-07 14:34:43.260008 | 
2025-10-07 14:34:43.260134 | TASK [ensure-pip : Check for ensurepip module]
2025-10-07 14:34:43.797849 | controller | skipping: Conditional result was False
2025-10-07 14:34:43.813365 | 
2025-10-07 14:34:43.813532 | TASK [ensure-pip : Ensure python3-venv]
2025-10-07 14:34:43.841340 | controller | skipping: Conditional result was False
2025-10-07 14:34:43.855569 | 
2025-10-07 14:34:43.855741 | TASK [ensure-pip : Install pip from source]
2025-10-07 14:34:43.883078 | controller | skipping: Conditional result was False
2025-10-07 14:34:43.896509 | 
2025-10-07 14:34:43.896650 | TASK [ensure-pip : Probe for venv python full path]
2025-10-07 10:34:44.204794 | controller | /usr/bin/python3
2025-10-07 14:34:44.442424 | controller | ok: Runtime: 0:00:00.005965
2025-10-07 14:34:44.454864 | 
2025-10-07 14:34:44.455002 | TASK [ensure-pip : Set host default]
2025-10-07 14:34:44.534080 | controller | ok
2025-10-07 14:34:44.545623 | 
2025-10-07 14:34:44.545781 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-07 14:34:44.626635 | controller | ok
2025-10-07 14:34:44.644169 | 
2025-10-07 14:34:44.644334 | TASK [bindep : Install bindep into temporary venv]
2025-10-07 14:34:49.057661 | controller | changed
2025-10-07 14:34:49.065739 | 
2025-10-07 14:34:49.065836 | TASK [bindep : Define bindep_command]
2025-10-07 14:34:49.098599 | controller | ok
2025-10-07 14:34:49.106490 | 
2025-10-07 14:34:49.106588 | LOOP [bindep : Include package tasks]
2025-10-07 14:34:49.169626 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-07 14:34:49.169908 | controller | ok: All items complete
2025-10-07 14:34:49.169957 | 
2025-10-07 14:34:49.185664 | controller | included: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-07 14:34:49.201282 | 
2025-10-07 14:34:49.201376 | TASK [bindep : Define bindep_run fact]
2025-10-07 14:34:49.235282 | controller | ok
2025-10-07 14:34:49.242929 | 
2025-10-07 14:34:49.243019 | TASK [bindep : Get list of packages to install from bindep]
2025-10-07 10:34:50.813046 | controller | podman
2025-10-07 10:34:50.852574 | controller | python3-jmespath
2025-10-07 10:34:50.852646 | controller | python3-libvirt
2025-10-07 10:34:50.852695 | controller | python3-lxml
2025-10-07 10:34:50.852813 | controller | python3-netaddr
2025-10-07 14:34:51.282263 | controller | ok: Runtime: 0:00:01.344609
2025-10-07 14:34:51.295754 | 
2025-10-07 14:34:51.295908 | TASK [bindep : Install distro packages from bindep]
2025-10-07 14:36:05.376312 | controller | changed
2025-10-07 14:36:05.390174 | 
2025-10-07 14:36:05.390310 | TASK [bindep : Check that packages are installed]
2025-10-07 14:36:06.934313 | controller | ok: Runtime: 0:00:01.082494
2025-10-07 14:36:06.948227 | 
2025-10-07 14:36:06.948369 | TASK [bindep : Fail if we cannot install all packages]
2025-10-07 14:36:06.986221 | controller | skipping: Conditional result was False
2025-10-07 14:36:07.011094 | 
2025-10-07 14:36:07.011279 | TASK [Run test-setup role]
2025-10-07 14:36:07.046622 | controller | ok
2025-10-07 14:36:07.070499 | 
2025-10-07 14:36:07.070622 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-07 14:36:07.302985 | controller | ok
2025-10-07 14:36:07.316771 | 
2025-10-07 14:36:07.316916 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-07 14:36:07.852082 | controller | skipping: Conditional result was False
2025-10-07 14:36:07.871765 | 
2025-10-07 14:36:07.871842 | TASK [bindep : Remove bindep temp dir]
2025-10-07 14:36:08.326929 | controller | ok
2025-10-07 14:36:08.349591 | 
2025-10-07 14:36:08.349734 | PLAY RECAP
2025-10-07 14:36:08.349824 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-07 14:36:08.349869 | 
2025-10-07 14:36:08.485743 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-07 14:36:08.487560 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-07 14:36:09.066847 | 
2025-10-07 14:36:09.066956 | PLAY [all]
2025-10-07 14:36:09.089196 | 
2025-10-07 14:36:09.089325 | TASK [Abort when test_command variable is undefined]
2025-10-07 14:36:09.124189 | controller | skipping: Conditional result was False
2025-10-07 14:36:09.130276 | 
2025-10-07 14:36:09.130352 | TASK [Convert test_command to list]
2025-10-07 14:36:09.165021 | controller | skipping: Conditional result was False
2025-10-07 14:36:09.172045 | 
2025-10-07 14:36:09.172112 | TASK [Use test_command list]
2025-10-07 14:36:09.221219 | controller | ok
2025-10-07 14:36:09.226981 | 
2025-10-07 14:36:09.227043 | LOOP [Run test_command]
2025-10-07 14:36:09.687555 | controller | no check to run
2025-10-07 14:36:09.687784 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.032492
2025-10-07 14:36:09.734363 | 
2025-10-07 14:36:09.734562 | PLAY RECAP
2025-10-07 14:36:09.734632 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-07 14:36:09.734662 | 
2025-10-07 14:36:09.850156 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-07 14:36:09.851055 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-07 14:36:10.462920 | 
2025-10-07 14:36:10.463146 | PLAY [all]
2025-10-07 14:36:10.484864 | 
2025-10-07 14:36:10.484972 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-07 14:36:10.861177 | controller | changed: non-zero return code
2025-10-07 14:36:10.867251 | 
2025-10-07 14:36:10.867330 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-07 14:36:10.892055 | controller | skipping: Conditional result was False
2025-10-07 14:36:10.897631 | 
2025-10-07 14:36:10.897721 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-07 14:36:10.928915 | 
2025-10-07 14:36:10.929059 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-07 14:36:10.959467 | 
2025-10-07 14:36:10.959596 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-07 14:36:10.983993 | controller | skipping: Conditional result was False
2025-10-07 14:36:10.991499 | 
2025-10-07 14:36:10.991581 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-07 14:36:11.012966 | 
2025-10-07 14:36:11.013234 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-07 14:36:11.052646 | controller | skipping: Conditional result was False
2025-10-07 14:36:11.058569 | 
2025-10-07 14:36:11.058637 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-07 14:36:11.082113 | controller | skipping: Conditional result was False
2025-10-07 14:36:11.088126 | 
2025-10-07 14:36:11.088198 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-07 14:36:11.112118 | controller | skipping: Conditional result was False
2025-10-07 14:36:11.137244 | 
2025-10-07 14:36:11.137307 | PLAY RECAP
2025-10-07 14:36:11.137350 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-07 14:36:11.137371 | 
2025-10-07 14:36:11.255500 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-07 14:36:11.257173 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-07 14:36:11.847899 | 
2025-10-07 14:36:11.848022 | PLAY [all]
2025-10-07 14:36:11.867841 | 
2025-10-07 14:36:11.867936 | TASK [include_role : fetch-output]
2025-10-07 14:36:11.905061 | controller | ok
2025-10-07 14:36:11.923793 | 
2025-10-07 14:36:11.923887 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-07 14:36:11.988487 | controller | skipping: Conditional result was False
2025-10-07 14:36:11.996483 | 
2025-10-07 14:36:11.996576 | TASK [fetch-output : Set log path for single node]
2025-10-07 14:36:12.039039 | controller | ok
2025-10-07 14:36:12.054403 | 
2025-10-07 14:36:12.054516 | LOOP [fetch-output : Ensure local output dirs]
2025-10-07 14:36:12.432487 | controller -> localhost | ok: "/var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/logs"
2025-10-07 14:36:12.661422 | controller -> localhost | changed: "/var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/artifacts"
2025-10-07 14:36:12.876488 | controller -> localhost | changed: "/var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/docs"
2025-10-07 14:36:12.898743 | 
2025-10-07 14:36:12.898940 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-07 14:36:13.494922 | controller | changed: .d..t...... ./
2025-10-07 14:36:13.495140 | controller | changed: All items complete
2025-10-07 14:36:13.495169 | 
2025-10-07 14:36:13.945638 | controller | changed: .d..t...... ./
2025-10-07 14:36:14.422644 | controller | changed: .d..t...... ./
2025-10-07 14:36:14.461984 | 
2025-10-07 14:36:14.462128 | TASK [include_role : fetch-output-openshift]
2025-10-07 14:36:14.487594 | controller | skipping: Conditional result was False
2025-10-07 14:36:14.497068 | 
2025-10-07 14:36:14.497162 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-07 14:36:14.937084 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008389
2025-10-07 14:36:15.144129 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.010660
2025-10-07 14:36:15.189179 | 
2025-10-07 14:36:15.189287 | PLAY [all]
2025-10-07 14:36:15.216016 | 
2025-10-07 14:36:15.216274 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-07 14:36:15.783945 | controller | changed
2025-10-07 14:36:15.811836 | 
2025-10-07 14:36:15.811940 | PLAY RECAP
2025-10-07 14:36:15.811984 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-07 14:36:15.812006 | 
2025-10-07 14:36:15.939173 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-07 14:36:15.941168 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-07 14:36:16.597843 | 
2025-10-07 14:36:16.597967 | PLAY [localhost]
2025-10-07 14:36:16.617149 | 
2025-10-07 14:36:16.617268 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-07 14:36:17.042070 | localhost | changed
2025-10-07 14:36:17.046908 | 
2025-10-07 14:36:17.046981 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-07 14:36:17.080872 | localhost | ok
2025-10-07 14:36:17.089828 | 
2025-10-07 14:36:17.089896 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-07 14:36:17.433235 | localhost | changed
2025-10-07 14:36:17.439243 | 
2025-10-07 14:36:17.439315 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-07 14:36:18.116937 | localhost | changed
2025-10-07 14:36:18.129395 | 
2025-10-07 14:36:18.129554 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-07 14:36:18.615727 | localhost | Identity added: /var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/tmp/ansible.v3kik_d2 (/var/lib/zuul/builds/1258d0d4cfe547a49010c191c2c47a6b/work/tmp/ansible.v3kik_d2)
2025-10-07 14:36:18.616111 | localhost | ok: Runtime: 0:00:00.013597
2025-10-07 14:36:18.625871 | 
2025-10-07 14:36:18.626011 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-07 14:36:18.978728 | localhost | ok: Runtime: 0:00:00.009480
2025-10-07 14:36:18.989946 | 
2025-10-07 14:36:18.990090 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-07 14:36:19.063450 | localhost | changed
2025-10-07 14:36:19.069411 | 
2025-10-07 14:36:19.069505 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-07 14:36:19.513029 | localhost | changed
2025-10-07 14:36:19.557112 | 
2025-10-07 14:36:19.557223 | PLAY [localhost]
2025-10-07 14:36:19.575351 | 
2025-10-07 14:36:19.575445 | TASK [Generate bulk log download script]
2025-10-07 14:36:19.597999 | localhost | ok
2025-10-07 14:36:19.615950 | 
2025-10-07 14:36:19.616042 | TASK [local-log-download : Check API endpoint is defined]
2025-10-07 14:36:19.667071 | localhost | ok: All assertions passed
2025-10-07 14:36:19.673546 | 
2025-10-07 14:36:19.673628 | TASK [local-log-download : Create download script]
2025-10-07 14:36:20.209377 | localhost -> localhost | changed
2025-10-07 14:36:20.218915 | 
2025-10-07 14:36:20.218986 | TASK [Register quick-download link]
2025-10-07 14:36:20.238749 | localhost | ok
2025-10-07 14:36:20.287287 | 
2025-10-07 14:36:20.287399 | PLAY [logserver.rdoproject.org]
2025-10-07 14:36:20.298013 | 
2025-10-07 14:36:20.298098 | TASK [Set zuul-log-path fact]
2025-10-07 14:36:20.314880 | logserver.rdoproject.org | ok
2025-10-07 14:36:20.325227 | 
2025-10-07 14:36:20.325301 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-07 14:36:20.363737 | logserver.rdoproject.org | ok
2025-10-07 14:36:20.372830 | 
2025-10-07 14:36:20.372923 | TASK [upload-logs : Create log directories]
2025-10-07 14:36:21.098615 | logserver.rdoproject.org | changed
2025-10-07 14:36:21.105998 | 
2025-10-07 14:36:21.106139 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-07 14:36:21.459283 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008047
2025-10-07 14:36:21.464320 | 
2025-10-07 14:36:21.464403 | TASK [upload-logs : Upload logs to log server]
2025-10-07 14:36:22.174769 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-07 14:36:22.181385 | 
2025-10-07 14:36:22.181518 | LOOP [upload-logs : Compress console log and json output]
2025-10-07 14:36:22.248514 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:36:22.269221 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:36:22.281633 | 
2025-10-07 14:36:22.281926 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-07 14:36:22.344072 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:36:22.344513 | 
2025-10-07 14:36:22.348247 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:36:22.362714 | 
2025-10-07 14:36:22.362953 | LOOP [upload-logs : Upload console log and json output]