2025-12-03 11:16:42.119757 | Job console starting...
2025-12-03 11:16:42.129997 | Updating repositories
2025-12-03 11:16:42.150995 | Preparing job workspace
2025-12-03 11:16:47.916042 | Running Ansible setup...
2025-12-03 11:16:52.856863 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-03 11:16:53.447107 | 
2025-12-03 11:16:53.447217 | PLAY [localhost]
2025-12-03 11:16:53.456477 | 
2025-12-03 11:16:53.456553 | TASK [Gathering Facts]
2025-12-03 11:16:55.155369 | localhost | ok
2025-12-03 11:16:55.174124 | 
2025-12-03 11:16:55.174255 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-03 11:16:55.792602 | localhost -> localhost | changed
2025-12-03 11:16:55.800582 | 
2025-12-03 11:16:55.800685 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-03 11:16:57.138484 | localhost -> localhost | changed
2025-12-03 11:16:57.168191 | 
2025-12-03 11:16:57.168553 | TASK [Setup log path fact]
2025-12-03 11:16:57.208447 | localhost | ok
2025-12-03 11:16:57.231383 | 
2025-12-03 11:16:57.231494 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-03 11:16:57.259645 | localhost | ok
2025-12-03 11:16:57.267249 | 
2025-12-03 11:16:57.267310 | TASK [emit-job-header : Print job information]
2025-12-03 11:16:57.305128 | # Job Information
2025-12-03 11:16:57.305271 | Ansible Version: 2.15.12
2025-12-03 11:16:57.305296 | Job: cifmw-molecule-ovirt
2025-12-03 11:16:57.305316 | Pipeline: github-check
2025-12-03 11:16:57.305334 | Executor: ze01.softwarefactory-project.io
2025-12-03 11:16:57.305352 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451
2025-12-03 11:16:57.305370 | Log URL (when completed): https://logserver.rdoproject.org/418/rdoproject.org/418c3488bbd8431c9b9a3e917fbbb42a/
2025-12-03 11:16:57.305388 | Event ID: 4ab514e0-d039-11f0-81e0-fb882bdc02c6
2025-12-03 11:16:57.309097 | 
2025-12-03 11:16:57.309161 | LOOP [emit-job-header : Print node information]
2025-12-03 11:16:57.445384 | localhost | ok:
2025-12-03 11:16:57.445544 | localhost | # Node Information
2025-12-03 11:16:57.445572 | localhost | Inventory Hostname: controller
2025-12-03 11:16:57.445595 | localhost | Hostname: np0005543712
2025-12-03 11:16:57.445615 | localhost | Username: zuul
2025-12-03 11:16:57.445635 | localhost | Distro: CentOS 9
2025-12-03 11:16:57.445654 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-03 11:16:57.445672 | localhost | Region: RegionOne
2025-12-03 11:16:57.445689 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-03 11:16:57.445706 | localhost | Product Name: OpenStack Nova
2025-12-03 11:16:57.445723 | localhost | Interface IP: 38.129.56.150
2025-12-03 11:16:57.468283 | 
2025-12-03 11:16:57.468388 | PLAY [all]
2025-12-03 11:16:57.474825 | 
2025-12-03 11:16:57.474885 | TASK [Gather network facts]
2025-12-03 11:16:57.956168 | controller | ok
2025-12-03 11:16:58.008609 | 
2025-12-03 11:16:58.008724 | TASK [include_role : start-zuul-console]
2025-12-03 11:16:58.046117 | controller | ok
2025-12-03 11:16:58.067108 | 
2025-12-03 11:16:58.067214 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-03 11:16:58.539823 | controller | ok
2025-12-03 11:16:58.560439 | 
2025-12-03 11:16:58.560576 | TASK [include_role : add-build-sshkey]
2025-12-03 11:16:58.597505 | controller | ok
2025-12-03 11:16:58.612824 | 
2025-12-03 11:16:58.612889 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-03 11:16:58.844351 | controller -> localhost | ok
2025-12-03 11:16:58.850061 | 
2025-12-03 11:16:58.850124 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-03 11:16:58.886238 | controller | ok
2025-12-03 11:16:58.901551 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-03 11:16:58.907969 | 
2025-12-03 11:16:58.908055 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-03 11:16:59.781717 | controller -> localhost | Generating public/private rsa key pair.
2025-12-03 11:16:59.781926 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/418c3488bbd8431c9b9a3e917fbbb42a_id_rsa.
2025-12-03 11:16:59.781958 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/418c3488bbd8431c9b9a3e917fbbb42a_id_rsa.pub.
2025-12-03 11:16:59.781979 | controller -> localhost | The key fingerprint is:
2025-12-03 11:16:59.781998 | controller -> localhost | SHA256:dfR2kvso01i0FGCwZi71a6jfh5Cc0JvxfRAzoqKIu2Y zuul-build-sshkey
2025-12-03 11:16:59.782031 | controller -> localhost | The key's randomart image is:
2025-12-03 11:16:59.782054 | controller -> localhost | +---[RSA 3072]----+
2025-12-03 11:16:59.782073 | controller -> localhost | |          ..+..  |
2025-12-03 11:16:59.782092 | controller -> localhost | |           +..+o |
2025-12-03 11:16:59.782110 | controller -> localhost | |         .*...B+.|
2025-12-03 11:16:59.782128 | controller -> localhost | |        o*+o +.= |
2025-12-03 11:16:59.782146 | controller -> localhost | |   . . .S+.B..+. |
2025-12-03 11:16:59.782163 | controller -> localhost | |  . . .  .B..=.o.|
2025-12-03 11:16:59.782180 | controller -> localhost | |   .      ..*.o..|
2025-12-03 11:16:59.782197 | controller -> localhost | |  E      . o.o.  |
2025-12-03 11:16:59.782215 | controller -> localhost | | o..    ... ..   |
2025-12-03 11:16:59.782231 | controller -> localhost | +----[SHA256]-----+
2025-12-03 11:16:59.782275 | controller -> localhost | ok: Runtime: 0:00:00.456531
2025-12-03 11:16:59.787825 | 
2025-12-03 11:16:59.787887 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-03 11:16:59.828132 | controller | ok
2025-12-03 11:16:59.844990 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-03 11:16:59.857906 | 
2025-12-03 11:16:59.858054 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-03 11:16:59.908954 | controller | skipping: Conditional result was False
2025-12-03 11:16:59.916444 | 
2025-12-03 11:16:59.916510 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-03 11:17:00.528506 | controller | changed
2025-12-03 11:17:00.534977 | 
2025-12-03 11:17:00.535100 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-03 11:17:00.940206 | controller | ok
2025-12-03 11:17:00.945351 | 
2025-12-03 11:17:00.945416 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-03 11:17:01.870917 | controller | changed
2025-12-03 11:17:01.877281 | 
2025-12-03 11:17:01.877346 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-03 11:17:02.752779 | controller | changed
2025-12-03 11:17:02.758241 | 
2025-12-03 11:17:02.758303 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-03 11:17:02.772211 | controller | skipping: Conditional result was False
2025-12-03 11:17:02.778336 | 
2025-12-03 11:17:02.778398 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-03 11:17:03.143859 | controller -> localhost | changed
2025-12-03 11:17:03.154081 | 
2025-12-03 11:17:03.154145 | TASK [add-build-sshkey : Add back temp key]
2025-12-03 11:17:03.454266 | controller -> localhost | Identity added: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/418c3488bbd8431c9b9a3e917fbbb42a_id_rsa (zuul-build-sshkey)
2025-12-03 11:17:03.454521 | controller -> localhost | ok: Runtime: 0:00:00.015445
2025-12-03 11:17:03.460190 | 
2025-12-03 11:17:03.460250 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-03 11:17:03.833778 | controller | ok
2025-12-03 11:17:03.838684 | 
2025-12-03 11:17:03.838748 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-03 11:17:03.873437 | controller | skipping: Conditional result was False
2025-12-03 11:17:03.883871 | 
2025-12-03 11:17:03.883953 | TASK [include_role : validate-host]
2025-12-03 11:17:03.913779 | controller | ok
2025-12-03 11:17:03.961135 | 
2025-12-03 11:17:03.961258 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-03 11:17:04.004203 | controller | ok
2025-12-03 11:17:04.008891 | 
2025-12-03 11:17:04.008958 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-03 11:17:04.249820 | controller -> localhost | ok
2025-12-03 11:17:04.265979 | 
2025-12-03 11:17:04.266158 | TASK [validate-host : Collect information about the host]
2025-12-03 11:17:05.050132 | controller | ok
2025-12-03 11:17:05.064469 | 
2025-12-03 11:17:05.064582 | TASK [validate-host : Sanitize hostname]
2025-12-03 11:17:05.131161 | controller | ok
2025-12-03 11:17:05.136548 | 
2025-12-03 11:17:05.136613 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-03 11:17:05.645350 | controller -> localhost | changed
2025-12-03 11:17:05.652088 | 
2025-12-03 11:17:05.652165 | TASK [validate-host : Collect information about zuul worker]
2025-12-03 11:17:06.106302 | controller | ok
2025-12-03 11:17:06.111533 | 
2025-12-03 11:17:06.111595 | TASK [validate-host : Write out all zuul information for each host]
2025-12-03 11:17:06.518468 | controller -> localhost | changed
2025-12-03 11:17:06.528484 | 
2025-12-03 11:17:06.528547 | TASK [include_role : prepare-workspace-openshift]
2025-12-03 11:17:06.552247 | controller | skipping: Conditional result was False
2025-12-03 11:17:06.557217 | 
2025-12-03 11:17:06.557276 | TASK [include_role : remove-zuul-sshkey]
2025-12-03 11:17:06.580797 | controller | skipping: Conditional result was False
2025-12-03 11:17:06.587375 | 
2025-12-03 11:17:06.587438 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-03 11:17:06.886164 | controller | ok: "logs"
2025-12-03 11:17:06.886366 | controller | ok: All items complete
2025-12-03 11:17:06.886393 | 
2025-12-03 11:17:07.136167 | controller | ok: "artifacts"
2025-12-03 11:17:07.361500 | controller | ok: "docs"
2025-12-03 11:17:07.374226 | 
2025-12-03 11:17:07.374363 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-03 11:17:07.647723 | controller | changed: "logs"
2025-12-03 11:17:07.887926 | controller | changed: "artifacts"
2025-12-03 11:17:08.144856 | controller | changed: "docs"
2025-12-03 11:17:08.190641 | 
2025-12-03 11:17:08.191413 | PLAY RECAP
2025-12-03 11:17:08.191510 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-03 11:17:08.191568 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-03 11:17:08.191610 | 
2025-12-03 11:17:08.334938 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-03 11:17:08.335799 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-03 11:17:08.960059 | 
2025-12-03 11:17:08.960225 | PLAY [localhost]
2025-12-03 11:17:08.988782 | 
2025-12-03 11:17:08.988888 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-03 11:17:09.366767 | localhost | ok
2025-12-03 11:17:09.374791 | 
2025-12-03 11:17:09.374893 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-03 11:17:10.101690 | localhost | changed
2025-12-03 11:17:10.126490 | 
2025-12-03 11:17:10.126561 | PLAY [all]
2025-12-03 11:17:10.141702 | 
2025-12-03 11:17:10.141766 | TASK [include_role : prepare-workspace]
2025-12-03 11:17:10.170502 | controller | ok
2025-12-03 11:17:10.184755 | 
2025-12-03 11:17:10.184824 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-03 11:17:10.587074 | controller | ok
2025-12-03 11:17:10.604730 | 
2025-12-03 11:17:10.604978 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-03 11:17:12.778993 | controller | Output suppressed because no_log was given
2025-12-03 11:17:12.790981 | 
2025-12-03 11:17:12.791078 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-03 11:17:13.051521 | controller | changed: "logs"
2025-12-03 11:17:13.279419 | controller | changed: "artifacts"
2025-12-03 11:17:13.526923 | controller | changed: "docs"
2025-12-03 11:17:13.544067 | 
2025-12-03 11:17:13.544198 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-03 11:17:13.845003 | controller | changed: "logs"
2025-12-03 11:17:13.845307 | controller | changed: All items complete
2025-12-03 11:17:13.845345 | 
2025-12-03 11:17:14.074352 | controller | changed: "artifacts"
2025-12-03 11:17:14.306064 | controller | changed: "docs"
2025-12-03 11:17:14.342425 | 
2025-12-03 11:17:14.342577 | TASK [Check if worker can sudo]
2025-12-03 11:17:15.392098 | controller | ok: Runtime: 0:00:00.042579
2025-12-03 11:17:15.399441 | 
2025-12-03 11:17:15.399516 | TASK [configure-mirrors : Gather needed facts]
2025-12-03 11:17:15.602451 | controller | skipping: Conditional result was False
2025-12-03 11:17:15.713419 | 
2025-12-03 11:17:15.713758 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-03 11:17:15.832238 | controller | ok
2025-12-03 11:17:15.852610 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-03 11:17:15.866725 | 
2025-12-03 11:17:15.866862 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-03 11:17:16.249451 | controller | ok
2025-12-03 11:17:16.261139 | 
2025-12-03 11:17:16.261216 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-03 11:17:16.346327 | controller | ok: "/var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-03 11:17:16.355736 | 
2025-12-03 11:17:16.355858 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-03 11:17:17.357894 | controller | changed
2025-12-03 11:17:17.366295 | 
2025-12-03 11:17:17.366366 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-03 11:17:17.452099 | controller | ok: "/var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-03 11:17:17.452260 | controller | ok: All items complete
2025-12-03 11:17:17.452287 | 
2025-12-03 11:17:17.502148 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-03 11:17:17.508913 | 
2025-12-03 11:17:17.508980 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-03 11:17:18.426291 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-03 11:17:19.384781 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-03 11:17:19.400721 | 
2025-12-03 11:17:19.400802 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-03 11:17:19.908250 | controller | changed: section and option added
2025-12-03 11:17:19.945934 | 
2025-12-03 11:17:19.946073 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-03 11:17:20.707099 | controller | 29 files removed
2025-12-03 11:17:20.707336 | controller | ok: Item: dnf clean all Runtime: 0:00:00.402081
2025-12-03 11:17:20.707376 | controller | changed: All items complete
2025-12-03 11:17:20.707398 | 
2025-12-03 11:17:37.696148 | 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:37.696262 | controller | DNF version: 4.14.0
2025-12-03 11:17:37.696288 | controller | cachedir: /var/cache/dnf
2025-12-03 11:17:37.696308 | controller | Making cache files for all metadata files.
2025-12-03 11:17:37.696327 | controller | baseos: has expired and will be refreshed.
2025-12-03 11:17:37.696345 | controller | appstream: has expired and will be refreshed.
2025-12-03 11:17:37.696362 | controller | crb: has expired and will be refreshed.
2025-12-03 11:17:37.696388 | controller | extras-common: has expired and will be refreshed.
2025-12-03 11:17:37.696405 | controller | repo: downloading from remote: baseos
2025-12-03 11:17:37.696422 | controller | CentOS Stream 9 - BaseOS                         39 MB/s | 8.8 MB     00:00
2025-12-03 11:17:37.696440 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-03 11:17:37.696457 | controller | repo: downloading from remote: appstream
2025-12-03 11:17:37.696473 | controller | CentOS Stream 9 - AppStream                      44 MB/s |  25 MB     00:00
2025-12-03 11:17:37.696490 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-03 11:17:37.696507 | controller | repo: downloading from remote: crb
2025-12-03 11:17:37.696523 | controller | CentOS Stream 9 - CRB                           4.6 MB/s | 7.3 MB     00:01
2025-12-03 11:17:37.696540 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-03 11:17:37.696557 | controller | repo: downloading from remote: extras-common
2025-12-03 11:17:37.696573 | controller | CentOS Stream 9 - Extras packages                30 kB/s |  20 kB     00:00
2025-12-03 11:17:37.696590 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-03 11:17:37.696607 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-03 11:17:37.696624 | controller | Completion plugin: Generating completion cache...
2025-12-03 11:17:37.696640 | controller | Metadata cache created.
2025-12-03 11:17:37.696665 | controller | ok: Item: dnf makecache -v Runtime: 0:00:16.681817
2025-12-03 11:17:37.728493 | 
2025-12-03 11:17:37.728649 | PLAY RECAP
2025-12-03 11:17:37.728709 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-03 11:17:37.728747 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-03 11:17:37.728772 | 
2025-12-03 11:17:37.883802 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-03 11:17:37.884821 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-03 11:17:38.485877 | 
2025-12-03 11:17:38.485978 | PLAY [all]
2025-12-03 11:17:38.516727 | 
2025-12-03 11:17:38.516845 | TASK [Install binary dependencies]
2025-12-03 11:17:38.594936 | controller | ok
2025-12-03 11:17:38.615814 | 
2025-12-03 11:17:38.615899 | TASK [bindep : Include find tasks]
2025-12-03 11:17:38.667772 | controller | ok
2025-12-03 11:17:38.680182 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-03 11:17:38.686383 | 
2025-12-03 11:17:38.686446 | TASK [bindep : Look for bindep.txt]
2025-12-03 11:17:39.157149 | controller | ok
2025-12-03 11:17:39.165995 | 
2025-12-03 11:17:39.166197 | TASK [bindep : Define bindep_file fact]
2025-12-03 11:17:39.199983 | controller | ok
2025-12-03 11:17:39.207077 | 
2025-12-03 11:17:39.207168 | TASK [bindep : Look for other-requirements.txt]
2025-12-03 11:17:39.232216 | controller | skipping: Conditional result was False
2025-12-03 11:17:39.241313 | 
2025-12-03 11:17:39.241423 | TASK [bindep : Define bindep_file fact]
2025-12-03 11:17:39.266875 | controller | skipping: Conditional result was False
2025-12-03 11:17:39.275663 | 
2025-12-03 11:17:39.275751 | TASK [bindep : Look for bindep fallback file]
2025-12-03 11:17:39.301795 | controller | skipping: Conditional result was False
2025-12-03 11:17:39.311455 | 
2025-12-03 11:17:39.311686 | TASK [bindep : Define bindep_file fact]
2025-12-03 11:17:39.346668 | controller | skipping: Conditional result was False
2025-12-03 11:17:39.356463 | 
2025-12-03 11:17:39.356553 | TASK [bindep : Include bindep tasks]
2025-12-03 11:17:39.389277 | controller | ok
2025-12-03 11:17:39.399415 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-03 11:17:39.411166 | 
2025-12-03 11:17:39.411225 | TASK [bindep : Look for bindep command]
2025-12-03 11:17:39.445898 | controller | skipping: Conditional result was False
2025-12-03 11:17:39.452486 | 
2025-12-03 11:17:39.452834 | TASK [bindep : Check for system bindep]
2025-12-03 11:17:39.996085 | controller | ok: Runtime: 0:00:00.005990
2025-12-03 11:17:40.001567 | 
2025-12-03 11:17:40.001630 | TASK [bindep : Define bindep_command fact]
2025-12-03 11:17:40.025670 | controller | skipping: Conditional result was False
2025-12-03 11:17:40.031378 | 
2025-12-03 11:17:40.031439 | TASK [bindep : Include install tasks]
2025-12-03 11:17:40.060926 | controller | ok
2025-12-03 11:17:40.068419 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-03 11:17:40.077163 | 
2025-12-03 11:17:40.077228 | TASK [bindep : Create temp dir for bindep]
2025-12-03 11:17:40.436646 | controller | changed
2025-12-03 11:17:40.441730 | 
2025-12-03 11:17:40.441788 | TASK [Ensure we have pip dependencies]
2025-12-03 11:17:40.461586 | controller | ok
2025-12-03 11:17:40.485826 | 
2025-12-03 11:17:40.485892 | TASK [ensure-pip : Check if pip is installed]
2025-12-03 06:17:40.995281 | controller | /usr/bin/pip3
2025-12-03 06:17:41.018467 | controller | /usr/bin/python3: No module named wheel
2025-12-03 11:17:41.516370 | controller | ok: Runtime: 0:00:00.038822
2025-12-03 11:17:41.522605 | 
2025-12-03 11:17:41.522691 | LOOP [ensure-pip : Install pip from packages]
2025-12-03 11:17:41.586996 | controller | ok: "/var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-03 11:17:41.603401 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-03 11:17:41.616349 | 
2025-12-03 11:17:41.616438 | TASK [ensure-pip : Install Python 3 pip]
2025-12-03 11:17:54.317687 | controller | changed
2025-12-03 11:17:54.329748 | 
2025-12-03 11:17:54.329872 | TASK [ensure-pip : Check for EPEL repository]
2025-12-03 11:17:54.387963 | controller | skipping: Conditional result was False
2025-12-03 11:17:54.401344 | 
2025-12-03 11:17:54.401501 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-03 11:17:54.460319 | controller | skipping: Conditional result was False
2025-12-03 11:17:54.473437 | 
2025-12-03 11:17:54.473567 | TASK [ensure-pip : Install Python 2 pip]
2025-12-03 11:17:54.521351 | controller | skipping: Conditional result was False
2025-12-03 11:17:54.533791 | 
2025-12-03 11:17:54.533924 | TASK [ensure-pip : Ensure setuptools]
2025-12-03 11:17:54.561275 | controller | skipping: Conditional result was False
2025-12-03 11:17:54.575367 | 
2025-12-03 11:17:54.575500 | TASK [ensure-pip : Check for ensurepip module]
2025-12-03 11:17:55.121922 | controller | skipping: Conditional result was False
2025-12-03 11:17:55.131631 | 
2025-12-03 11:17:55.131822 | TASK [ensure-pip : Ensure python3-venv]
2025-12-03 11:17:55.156172 | controller | skipping: Conditional result was False
2025-12-03 11:17:55.162840 | 
2025-12-03 11:17:55.162909 | TASK [ensure-pip : Install pip from source]
2025-12-03 11:17:55.187213 | controller | skipping: Conditional result was False
2025-12-03 11:17:55.194040 | 
2025-12-03 11:17:55.194111 | TASK [ensure-pip : Probe for venv python full path]
2025-12-03 06:17:55.503901 | controller | /usr/bin/python3
2025-12-03 11:17:55.730976 | controller | ok: Runtime: 0:00:00.006912
2025-12-03 11:17:55.737196 | 
2025-12-03 11:17:55.737272 | TASK [ensure-pip : Set host default]
2025-12-03 11:17:55.797957 | controller | ok
2025-12-03 11:17:55.803456 | 
2025-12-03 11:17:55.803574 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-03 11:17:55.865773 | controller | ok
2025-12-03 11:17:55.886775 | 
2025-12-03 11:17:55.886902 | TASK [bindep : Install bindep into temporary venv]
2025-12-03 11:18:02.805686 | controller | changed
2025-12-03 11:18:02.815166 | 
2025-12-03 11:18:02.815259 | TASK [bindep : Define bindep_command]
2025-12-03 11:18:02.856017 | controller | ok
2025-12-03 11:18:02.861305 | 
2025-12-03 11:18:02.861369 | LOOP [bindep : Include package tasks]
2025-12-03 11:18:02.929707 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-03 11:18:02.929966 | controller | ok: All items complete
2025-12-03 11:18:02.930002 | 
2025-12-03 11:18:02.946357 | controller | included: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-03 11:18:02.962830 | 
2025-12-03 11:18:02.962911 | TASK [bindep : Define bindep_run fact]
2025-12-03 11:18:03.002415 | controller | ok
2025-12-03 11:18:03.009277 | 
2025-12-03 11:18:03.009339 | TASK [bindep : Get list of packages to install from bindep]
2025-12-03 06:18:04.756645 | controller | podman
2025-12-03 06:18:04.793220 | controller | python3-jmespath
2025-12-03 06:18:04.793451 | controller | python3-libvirt
2025-12-03 06:18:04.793464 | controller | python3-lxml
2025-12-03 06:18:04.793475 | controller | python3-netaddr
2025-12-03 11:18:05.050570 | controller | ok: Runtime: 0:00:01.472342
2025-12-03 11:18:05.063542 | 
2025-12-03 11:18:05.063684 | TASK [bindep : Install distro packages from bindep]
2025-12-03 11:19:23.849867 | controller | changed
2025-12-03 11:19:23.865178 | 
2025-12-03 11:19:23.865348 | TASK [bindep : Check that packages are installed]
2025-12-03 11:19:25.934117 | controller | ok: Runtime: 0:00:01.463655
2025-12-03 11:19:25.948888 | 
2025-12-03 11:19:25.949434 | TASK [bindep : Fail if we cannot install all packages]
2025-12-03 11:19:26.038889 | controller | skipping: Conditional result was False
2025-12-03 11:19:26.108251 | 
2025-12-03 11:19:26.108412 | TASK [Run test-setup role]
2025-12-03 11:19:26.142065 | controller | ok
2025-12-03 11:19:26.169489 | 
2025-12-03 11:19:26.169730 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-03 11:19:26.436094 | controller | ok
2025-12-03 11:19:26.445993 | 
2025-12-03 11:19:26.446146 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-03 11:19:26.987470 | controller | skipping: Conditional result was False
2025-12-03 11:19:27.008531 | 
2025-12-03 11:19:27.008663 | TASK [bindep : Remove bindep temp dir]
2025-12-03 11:19:27.485063 | controller | ok
2025-12-03 11:19:27.496926 | 
2025-12-03 11:19:27.497003 | PLAY RECAP
2025-12-03 11:19:27.497064 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-03 11:19:27.497090 | 
2025-12-03 11:19:27.619664 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-03 11:19:27.621747 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-03 11:19:28.270368 | 
2025-12-03 11:19:28.270507 | PLAY [all]
2025-12-03 11:19:28.295044 | 
2025-12-03 11:19:28.295168 | TASK [Abort when test_command variable is undefined]
2025-12-03 11:19:28.320045 | controller | skipping: Conditional result was False
2025-12-03 11:19:28.327495 | 
2025-12-03 11:19:28.327581 | TASK [Convert test_command to list]
2025-12-03 11:19:28.361558 | controller | skipping: Conditional result was False
2025-12-03 11:19:28.369309 | 
2025-12-03 11:19:28.369393 | TASK [Use test_command list]
2025-12-03 11:19:28.435796 | controller | ok
2025-12-03 11:19:28.442094 | 
2025-12-03 11:19:28.442163 | LOOP [Run test_command]
2025-12-03 11:19:28.919545 | controller | no check to run
2025-12-03 11:19:28.919901 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007135
2025-12-03 11:19:28.947742 | 
2025-12-03 11:19:28.947859 | PLAY RECAP
2025-12-03 11:19:28.947902 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-03 11:19:28.947922 | 
2025-12-03 11:19:29.060747 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-03 11:19:29.061649 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-03 11:19:29.683111 | 
2025-12-03 11:19:29.683241 | PLAY [all]
2025-12-03 11:19:29.707004 | 
2025-12-03 11:19:29.707132 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-03 11:19:30.514097 | controller | changed: non-zero return code
2025-12-03 11:19:30.528677 | 
2025-12-03 11:19:30.528885 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-03 11:19:30.575239 | controller | skipping: Conditional result was False
2025-12-03 11:19:30.584684 | 
2025-12-03 11:19:30.584786 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-03 11:19:30.619513 | 
2025-12-03 11:19:30.619708 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-03 11:19:30.653217 | 
2025-12-03 11:19:30.653421 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-03 11:19:30.678830 | controller | skipping: Conditional result was False
2025-12-03 11:19:30.688675 | 
2025-12-03 11:19:30.688813 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-03 11:19:30.722765 | 
2025-12-03 11:19:30.722994 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-03 11:19:30.738374 | controller | skipping: Conditional result was False
2025-12-03 11:19:30.746001 | 
2025-12-03 11:19:30.746107 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-03 11:19:30.760636 | controller | skipping: Conditional result was False
2025-12-03 11:19:30.768844 | 
2025-12-03 11:19:30.768932 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-03 11:19:30.783610 | controller | skipping: Conditional result was False
2025-12-03 11:19:30.818354 | 
2025-12-03 11:19:30.818435 | PLAY RECAP
2025-12-03 11:19:30.818477 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-03 11:19:30.818497 | 
2025-12-03 11:19:30.922105 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-03 11:19:30.922940 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-03 11:19:31.526690 | 
2025-12-03 11:19:31.526819 | PLAY [all]
2025-12-03 11:19:31.546555 | 
2025-12-03 11:19:31.546636 | TASK [include_role : fetch-output]
2025-12-03 11:19:31.597509 | controller | ok
2025-12-03 11:19:31.616769 | 
2025-12-03 11:19:31.616870 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-03 11:19:31.681332 | controller | skipping: Conditional result was False
2025-12-03 11:19:31.687149 | 
2025-12-03 11:19:31.687213 | TASK [fetch-output : Set log path for single node]
2025-12-03 11:19:31.746489 | controller | ok
2025-12-03 11:19:31.751487 | 
2025-12-03 11:19:31.751551 | LOOP [fetch-output : Ensure local output dirs]
2025-12-03 11:19:32.200834 | controller -> localhost | ok: "/var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/logs"
2025-12-03 11:19:32.523459 | controller -> localhost | changed: "/var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/artifacts"
2025-12-03 11:19:32.816822 | controller -> localhost | changed: "/var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/docs"
2025-12-03 11:19:32.839402 | 
2025-12-03 11:19:32.839587 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-03 11:19:33.586324 | controller | changed: .d..t...... ./
2025-12-03 11:19:33.586950 | controller | changed: All items complete
2025-12-03 11:19:33.587053 | 
2025-12-03 11:19:34.197116 | controller | changed: .d..t...... ./
2025-12-03 11:19:34.730639 | controller | changed: .d..t...... ./
2025-12-03 11:19:34.758975 | 
2025-12-03 11:19:34.759178 | TASK [include_role : fetch-output-openshift]
2025-12-03 11:19:34.786041 | controller | skipping: Conditional result was False
2025-12-03 11:19:34.799011 | 
2025-12-03 11:19:34.799207 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-03 11:19:35.262771 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013372
2025-12-03 11:19:35.568599 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009762
2025-12-03 11:19:35.618072 | 
2025-12-03 11:19:35.618196 | PLAY [all]
2025-12-03 11:19:35.638849 | 
2025-12-03 11:19:35.638958 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-03 11:19:36.223631 | controller | changed
2025-12-03 11:19:36.263623 | 
2025-12-03 11:19:36.263722 | PLAY RECAP
2025-12-03 11:19:36.263764 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-03 11:19:36.263786 | 
2025-12-03 11:19:36.360152 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-03 11:19:36.361969 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-03 11:19:37.008847 | 
2025-12-03 11:19:37.008973 | PLAY [localhost]
2025-12-03 11:19:37.027875 | 
2025-12-03 11:19:37.027994 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-03 11:19:37.421365 | localhost | changed
2025-12-03 11:19:37.429047 | 
2025-12-03 11:19:37.429149 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-03 11:19:37.456987 | localhost | ok
2025-12-03 11:19:37.465245 | 
2025-12-03 11:19:37.465311 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-03 11:19:37.847407 | localhost | changed
2025-12-03 11:19:37.853505 | 
2025-12-03 11:19:37.853577 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-03 11:19:38.602552 | localhost | changed
2025-12-03 11:19:38.607963 | 
2025-12-03 11:19:38.608054 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-03 11:19:39.089623 | localhost | Identity added: /var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/tmp/ansible.uznc80_3 (/var/lib/zuul/builds/418c3488bbd8431c9b9a3e917fbbb42a/work/tmp/ansible.uznc80_3)
2025-12-03 11:19:39.089980 | localhost | ok: Runtime: 0:00:00.013146
2025-12-03 11:19:39.105417 | 
2025-12-03 11:19:39.105568 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-03 11:19:39.409306 | localhost | ok: Runtime: 0:00:00.006947
2025-12-03 11:19:39.414552 | 
2025-12-03 11:19:39.414623 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-03 11:19:39.483101 | localhost | changed
2025-12-03 11:19:39.487500 | 
2025-12-03 11:19:39.487565 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-03 11:19:39.889726 | localhost | changed
2025-12-03 11:19:39.910215 | 
2025-12-03 11:19:39.910276 | PLAY [localhost]
2025-12-03 11:19:39.922754 | 
2025-12-03 11:19:39.922832 | TASK [Generate bulk log download script]
2025-12-03 11:19:39.943292 | localhost | ok
2025-12-03 11:19:39.955805 | 
2025-12-03 11:19:39.955867 | TASK [local-log-download : Check API endpoint is defined]
2025-12-03 11:19:39.984904 | localhost | ok: All assertions passed
2025-12-03 11:19:39.989453 | 
2025-12-03 11:19:39.989515 | TASK [local-log-download : Create download script]
2025-12-03 11:19:40.441585 | localhost -> localhost | changed
2025-12-03 11:19:40.461011 | 
2025-12-03 11:19:40.461164 | TASK [Register quick-download link]
2025-12-03 11:19:40.486924 | localhost | ok
2025-12-03 11:19:40.540097 | 
2025-12-03 11:19:40.540209 | PLAY [logserver.rdoproject.org]
2025-12-03 11:19:40.554348 | 
2025-12-03 11:19:40.554430 | TASK [Set zuul-log-path fact]
2025-12-03 11:19:40.571980 | logserver.rdoproject.org | ok
2025-12-03 11:19:40.584866 | 
2025-12-03 11:19:40.584949 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-03 11:19:40.612776 | logserver.rdoproject.org | ok
2025-12-03 11:19:40.620694 | 
2025-12-03 11:19:40.620783 | TASK [upload-logs : Create log directories]
2025-12-03 11:19:41.487258 | logserver.rdoproject.org | changed
2025-12-03 11:19:41.491837 | 
2025-12-03 11:19:41.491915 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-03 11:19:41.824655 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008838
2025-12-03 11:19:41.836657 | 
2025-12-03 11:19:41.836818 | TASK [upload-logs : Upload logs to log server]
2025-12-03 11:19:42.603480 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-03 11:19:42.607661 | 
2025-12-03 11:19:42.607745 | LOOP [upload-logs : Compress console log and json output]
2025-12-03 11:19:42.672881 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:19:42.698114 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:19:42.709911 | 
2025-12-03 11:19:42.710186 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-03 11:19:42.759000 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:19:42.759293 | 
2025-12-03 11:19:42.764194 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-03 11:19:42.771630 | 
2025-12-03 11:19:42.771780 | LOOP [upload-logs : Upload console log and json output]