2025-10-02 19:26:49.052254 | Job console starting...
2025-10-02 19:26:49.070057 | Updating repositories
2025-10-02 19:26:49.106783 | Preparing job workspace
2025-10-02 19:26:52.891376 | Running Ansible setup...
2025-10-02 19:26:56.842942 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-02 19:26:57.388746 | 
2025-10-02 19:26:57.388859 | PLAY [localhost]
2025-10-02 19:26:57.397245 | 
2025-10-02 19:26:57.397310 | TASK [Gathering Facts]
2025-10-02 19:26:58.373369 | localhost | ok
2025-10-02 19:26:58.392044 | 
2025-10-02 19:26:58.392155 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-02 19:26:58.811292 | localhost -> localhost | changed
2025-10-02 19:26:58.816798 | 
2025-10-02 19:26:58.816864 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-02 19:26:59.755829 | localhost -> localhost | changed
2025-10-02 19:26:59.778208 | 
2025-10-02 19:26:59.778345 | TASK [Setup log path fact]
2025-10-02 19:26:59.799856 | localhost | ok
2025-10-02 19:26:59.815505 | 
2025-10-02 19:26:59.815594 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 19:26:59.845328 | localhost | ok
2025-10-02 19:26:59.861166 | 
2025-10-02 19:26:59.861258 | TASK [emit-job-header : Print job information]
2025-10-02 19:26:59.914128 | # Job Information
2025-10-02 19:26:59.914657 | Ansible Version: 2.15.12
2025-10-02 19:26:59.914739 | Job: cifmw-molecule-ci_lvms_storage
2025-10-02 19:26:59.914801 | Pipeline: github-check
2025-10-02 19:26:59.914833 | Executor: ze04.softwarefactory-project.io
2025-10-02 19:26:59.914886 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-02 19:26:59.914918 | Log URL (when completed): https://logserver.rdoproject.org/02a/rdoproject.org/02a096d1c5df42e09cfae514e695d67b/
2025-10-02 19:26:59.914970 | Event ID: 9ca491d0-9fc5-11f0-8734-f8eb35e200a5
2025-10-02 19:26:59.921033 | 
2025-10-02 19:26:59.921117 | LOOP [emit-job-header : Print node information]
2025-10-02 19:27:00.035449 | localhost | ok:
2025-10-02 19:27:00.035841 | localhost | # Node Information
2025-10-02 19:27:00.035902 | localhost | Inventory Hostname: controller
2025-10-02 19:27:00.035951 | localhost | Hostname: np0005467127
2025-10-02 19:27:00.035992 | localhost | Username: zuul
2025-10-02 19:27:00.036036 | localhost | Distro: CentOS 9
2025-10-02 19:27:00.036076 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-02 19:27:00.036113 | localhost | Region: RegionOne
2025-10-02 19:27:00.036150 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-02 19:27:00.036187 | localhost | Product Name: OpenStack Nova
2025-10-02 19:27:00.036222 | localhost | Interface IP: 38.102.83.230
2025-10-02 19:27:00.078582 | 
2025-10-02 19:27:00.078668 | PLAY [all]
2025-10-02 19:27:00.087747 | 
2025-10-02 19:27:00.087833 | TASK [Gather network facts]
2025-10-02 19:27:00.558807 | controller | ok
2025-10-02 19:27:00.592136 | 
2025-10-02 19:27:00.592225 | TASK [include_role : start-zuul-console]
2025-10-02 19:27:00.617907 | controller | ok
2025-10-02 19:27:00.634424 | 
2025-10-02 19:27:00.634522 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-02 19:27:01.072420 | controller | ok
2025-10-02 19:27:01.083689 | 
2025-10-02 19:27:01.083761 | TASK [include_role : add-build-sshkey]
2025-10-02 19:27:01.122817 | controller | ok
2025-10-02 19:27:01.136230 | 
2025-10-02 19:27:01.136300 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-02 19:27:01.407756 | controller -> localhost | ok
2025-10-02 19:27:01.413843 | 
2025-10-02 19:27:01.413911 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-02 19:27:01.433777 | controller | ok
2025-10-02 19:27:01.450383 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-02 19:27:01.456501 | 
2025-10-02 19:27:01.456565 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-02 19:27:02.121513 | controller -> localhost | Generating public/private rsa key pair.
2025-10-02 19:27:02.121725 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/02a096d1c5df42e09cfae514e695d67b_id_rsa.
2025-10-02 19:27:02.121759 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/02a096d1c5df42e09cfae514e695d67b_id_rsa.pub.
2025-10-02 19:27:02.121781 | controller -> localhost | The key fingerprint is:
2025-10-02 19:27:02.121801 | controller -> localhost | SHA256:79nQs4LCYXmqaMzZrzQOW+LrKMf+o4HDPj9ATCx6w6s zuul-build-sshkey
2025-10-02 19:27:02.121821 | controller -> localhost | The key's randomart image is:
2025-10-02 19:27:02.121840 | controller -> localhost | +---[RSA 3072]----+
2025-10-02 19:27:02.121857 | controller -> localhost | |.                |
2025-10-02 19:27:02.121876 | controller -> localhost | |.o               |
2025-10-02 19:27:02.121894 | controller -> localhost | |=.               |
2025-10-02 19:27:02.121913 | controller -> localhost | |.o+              |
2025-10-02 19:27:02.121930 | controller -> localhost | |.. o   .S        |
2025-10-02 19:27:02.121948 | controller -> localhost | |.o.   + .. .     |
2025-10-02 19:27:02.121965 | controller -> localhost | |o*=o+o + .o o    |
2025-10-02 19:27:02.121985 | controller -> localhost | |E=B@o.+ ...+ o   |
2025-10-02 19:27:02.122003 | controller -> localhost | |o*@=*=..  o.o    |
2025-10-02 19:27:02.122020 | controller -> localhost | +----[SHA256]-----+
2025-10-02 19:27:02.122066 | controller -> localhost | ok: Runtime: 0:00:00.273693
2025-10-02 19:27:02.128173 | 
2025-10-02 19:27:02.128234 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-02 19:27:02.150949 | controller | ok
2025-10-02 19:27:02.161067 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-02 19:27:02.169024 | 
2025-10-02 19:27:02.169088 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-02 19:27:02.196220 | controller | skipping: Conditional result was False
2025-10-02 19:27:02.203644 | 
2025-10-02 19:27:02.203734 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-02 19:27:02.654759 | controller | changed
2025-10-02 19:27:02.660709 | 
2025-10-02 19:27:02.660774 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-02 19:27:02.892257 | controller | ok
2025-10-02 19:27:02.897459 | 
2025-10-02 19:27:02.897524 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-02 19:27:03.626338 | controller | changed
2025-10-02 19:27:03.639225 | 
2025-10-02 19:27:03.639453 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-02 19:27:04.355326 | controller | changed
2025-10-02 19:27:04.367771 | 
2025-10-02 19:27:04.367855 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-02 19:27:04.392371 | controller | skipping: Conditional result was False
2025-10-02 19:27:04.400781 | 
2025-10-02 19:27:04.400874 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-02 19:27:04.763821 | controller -> localhost | changed
2025-10-02 19:27:04.777195 | 
2025-10-02 19:27:04.777312 | TASK [add-build-sshkey : Add back temp key]
2025-10-02 19:27:05.038642 | controller -> localhost | Identity added: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/02a096d1c5df42e09cfae514e695d67b_id_rsa (zuul-build-sshkey)
2025-10-02 19:27:05.038932 | controller -> localhost | ok: Runtime: 0:00:00.025469
2025-10-02 19:27:05.044845 | 
2025-10-02 19:27:05.044914 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-02 19:27:05.444922 | controller | ok
2025-10-02 19:27:05.449591 | 
2025-10-02 19:27:05.449652 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-02 19:27:05.496907 | controller | skipping: Conditional result was False
2025-10-02 19:27:05.515632 | 
2025-10-02 19:27:05.515734 | TASK [include_role : validate-host]
2025-10-02 19:27:05.546578 | controller | ok
2025-10-02 19:27:05.566081 | 
2025-10-02 19:27:05.566161 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-02 19:27:05.606789 | controller | ok
2025-10-02 19:27:05.611268 | 
2025-10-02 19:27:05.611328 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-02 19:27:05.890527 | controller -> localhost | ok
2025-10-02 19:27:05.903130 | 
2025-10-02 19:27:05.903264 | TASK [validate-host : Collect information about the host]
2025-10-02 19:27:06.709634 | controller | ok
2025-10-02 19:27:06.720718 | 
2025-10-02 19:27:06.720799 | TASK [validate-host : Sanitize hostname]
2025-10-02 19:27:06.771923 | controller | ok
2025-10-02 19:27:06.778334 | 
2025-10-02 19:27:06.778416 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-02 19:27:07.262119 | controller -> localhost | changed
2025-10-02 19:27:07.268183 | 
2025-10-02 19:27:07.268288 | TASK [validate-host : Collect information about zuul worker]
2025-10-02 19:27:07.654988 | controller | ok
2025-10-02 19:27:07.659983 | 
2025-10-02 19:27:07.660052 | TASK [validate-host : Write out all zuul information for each host]
2025-10-02 19:27:08.098639 | controller -> localhost | changed
2025-10-02 19:27:08.108574 | 
2025-10-02 19:27:08.108651 | TASK [include_role : prepare-workspace-openshift]
2025-10-02 19:27:08.122764 | controller | skipping: Conditional result was False
2025-10-02 19:27:08.128633 | 
2025-10-02 19:27:08.128724 | TASK [include_role : remove-zuul-sshkey]
2025-10-02 19:27:08.142510 | controller | skipping: Conditional result was False
2025-10-02 19:27:08.148978 | 
2025-10-02 19:27:08.149068 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-02 19:27:08.441106 | controller | ok: "logs"
2025-10-02 19:27:08.441350 | controller | ok: All items complete
2025-10-02 19:27:08.441376 | 
2025-10-02 19:27:08.634024 | controller | ok: "artifacts"
2025-10-02 19:27:08.864488 | controller | ok: "docs"
2025-10-02 19:27:08.877962 | 
2025-10-02 19:27:08.878075 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-02 19:27:09.121861 | controller | changed: "logs"
2025-10-02 19:27:09.337108 | controller | changed: "artifacts"
2025-10-02 19:27:09.583959 | controller | changed: "docs"
2025-10-02 19:27:09.683414 | 
2025-10-02 19:27:09.683517 | PLAY RECAP
2025-10-02 19:27:09.683631 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-02 19:27:09.683667 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-02 19:27:09.683703 | 
2025-10-02 19:27:09.792973 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-02 19:27:09.793820 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-02 19:27:10.525943 | 
2025-10-02 19:27:10.526079 | PLAY [localhost]
2025-10-02 19:27:10.547273 | 
2025-10-02 19:27:10.547373 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-02 19:27:10.911701 | localhost | ok
2025-10-02 19:27:10.916889 | 
2025-10-02 19:27:10.916969 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-02 19:27:11.555454 | localhost | changed
2025-10-02 19:27:11.605058 | 
2025-10-02 19:27:11.605161 | PLAY [all]
2025-10-02 19:27:11.633567 | 
2025-10-02 19:27:11.633647 | TASK [include_role : prepare-workspace]
2025-10-02 19:27:11.661898 | controller | ok
2025-10-02 19:27:11.685827 | 
2025-10-02 19:27:11.685957 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-02 19:27:12.080255 | controller | ok
2025-10-02 19:27:12.101559 | 
2025-10-02 19:27:12.101763 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-02 19:27:13.888309 | controller | Output suppressed because no_log was given
2025-10-02 19:27:13.899885 | 
2025-10-02 19:27:13.899948 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-02 19:27:14.169654 | controller | changed: "logs"
2025-10-02 19:27:14.409961 | controller | changed: "artifacts"
2025-10-02 19:27:14.630187 | controller | changed: "docs"
2025-10-02 19:27:14.645549 | 
2025-10-02 19:27:14.645644 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-02 19:27:14.988398 | controller | changed: "logs"
2025-10-02 19:27:14.988643 | controller | changed: All items complete
2025-10-02 19:27:14.988673 | 
2025-10-02 19:27:15.192406 | controller | changed: "artifacts"
2025-10-02 19:27:15.479279 | controller | changed: "docs"
2025-10-02 19:27:15.491753 | 
2025-10-02 19:27:15.491883 | TASK [Check if worker can sudo]
2025-10-02 19:27:16.032286 | controller | ok: Runtime: 0:00:00.049964
2025-10-02 19:27:16.038003 | 
2025-10-02 19:27:16.038072 | TASK [configure-mirrors : Gather needed facts]
2025-10-02 19:27:16.093597 | controller | skipping: Conditional result was False
2025-10-02 19:27:16.100175 | 
2025-10-02 19:27:16.100247 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-02 19:27:16.152411 | controller | ok
2025-10-02 19:27:16.164242 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-02 19:27:16.173818 | 
2025-10-02 19:27:16.173886 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-02 19:27:16.538183 | controller | ok
2025-10-02 19:27:16.544735 | 
2025-10-02 19:27:16.544799 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-02 19:27:16.641326 | controller | ok: "/var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-02 19:27:16.657331 | 
2025-10-02 19:27:16.657451 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-02 19:27:17.541291 | controller | changed
2025-10-02 19:27:17.548885 | 
2025-10-02 19:27:17.549013 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-02 19:27:17.610188 | controller | ok: "/var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-02 19:27:17.610352 | controller | ok: All items complete
2025-10-02 19:27:17.610377 | 
2025-10-02 19:27:17.661741 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-02 19:27:17.668387 | 
2025-10-02 19:27:17.668453 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-02 19:27:18.460293 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-02 19:27:19.237840 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-02 19:27:19.255158 | 
2025-10-02 19:27:19.255281 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-02 19:27:19.933441 | controller | changed: section and option added
2025-10-02 19:27:19.959370 | 
2025-10-02 19:27:19.959477 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-02 19:27:20.697853 | controller | 29 files removed
2025-10-02 19:27:20.700301 | controller | ok: Item: dnf clean all Runtime: 0:00:00.429439
2025-10-02 19:27:20.700414 | controller | changed: All items complete
2025-10-02 19:27:20.700438 | 
2025-10-02 19:27:31.562848 | 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-02 19:27:31.563025 | controller | DNF version: 4.14.0
2025-10-02 19:27:31.563079 | controller | cachedir: /var/cache/dnf
2025-10-02 19:27:31.563126 | controller | Making cache files for all metadata files.
2025-10-02 19:27:31.563168 | controller | baseos: has expired and will be refreshed.
2025-10-02 19:27:31.563206 | controller | appstream: has expired and will be refreshed.
2025-10-02 19:27:31.563242 | controller | crb: has expired and will be refreshed.
2025-10-02 19:27:31.563488 | controller | extras-common: has expired and will be refreshed.
2025-10-02 19:27:31.563526 | controller | repo: downloading from remote: baseos
2025-10-02 19:27:31.563563 | controller | CentOS Stream 9 - BaseOS                         76 MB/s | 8.8 MB     00:00
2025-10-02 19:27:31.563600 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-02 19:27:31.563635 | controller | repo: downloading from remote: appstream
2025-10-02 19:27:31.563671 | controller | CentOS Stream 9 - AppStream                      93 MB/s |  25 MB     00:00
2025-10-02 19:27:31.563771 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-02 19:27:31.563811 | controller | repo: downloading from remote: crb
2025-10-02 19:27:31.563847 | controller | CentOS Stream 9 - CRB                            67 MB/s | 7.1 MB     00:00
2025-10-02 19:27:31.563883 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-02 19:27:31.563920 | controller | repo: downloading from remote: extras-common
2025-10-02 19:27:31.563956 | controller | CentOS Stream 9 - Extras packages               343 kB/s |  20 kB     00:00
2025-10-02 19:27:31.563991 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-02 19:27:31.564026 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-02 19:27:31.564061 | controller | Completion plugin: Generating completion cache...
2025-10-02 19:27:31.564096 | controller | Metadata cache created.
2025-10-02 19:27:31.564150 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.596964
2025-10-02 19:27:31.577648 | 
2025-10-02 19:27:31.577778 | PLAY RECAP
2025-10-02 19:27:31.577822 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-02 19:27:31.577847 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-02 19:27:31.577864 | 
2025-10-02 19:27:31.720716 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-02 19:27:31.721620 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-02 19:27:32.338150 | 
2025-10-02 19:27:32.338251 | PLAY [all]
2025-10-02 19:27:32.358775 | 
2025-10-02 19:27:32.358850 | TASK [Install binary dependencies]
2025-10-02 19:27:32.408125 | controller | ok
2025-10-02 19:27:32.441246 | 
2025-10-02 19:27:32.441387 | TASK [bindep : Include find tasks]
2025-10-02 19:27:32.470118 | controller | ok
2025-10-02 19:27:32.478169 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-02 19:27:32.484067 | 
2025-10-02 19:27:32.484128 | TASK [bindep : Look for bindep.txt]
2025-10-02 19:27:32.875149 | controller | ok
2025-10-02 19:27:32.884100 | 
2025-10-02 19:27:32.884189 | TASK [bindep : Define bindep_file fact]
2025-10-02 19:27:32.915397 | controller | ok
2025-10-02 19:27:32.922519 | 
2025-10-02 19:27:32.922626 | TASK [bindep : Look for other-requirements.txt]
2025-10-02 19:27:32.941368 | controller | skipping: Conditional result was False
2025-10-02 19:27:32.954445 | 
2025-10-02 19:27:32.954540 | TASK [bindep : Define bindep_file fact]
2025-10-02 19:27:32.981767 | controller | skipping: Conditional result was False
2025-10-02 19:27:32.987618 | 
2025-10-02 19:27:32.987712 | TASK [bindep : Look for bindep fallback file]
2025-10-02 19:27:33.021731 | controller | skipping: Conditional result was False
2025-10-02 19:27:33.027835 | 
2025-10-02 19:27:33.027905 | TASK [bindep : Define bindep_file fact]
2025-10-02 19:27:33.054377 | controller | skipping: Conditional result was False
2025-10-02 19:27:33.060297 | 
2025-10-02 19:27:33.060359 | TASK [bindep : Include bindep tasks]
2025-10-02 19:27:33.090366 | controller | ok
2025-10-02 19:27:33.098482 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-02 19:27:33.106293 | 
2025-10-02 19:27:33.106355 | TASK [bindep : Look for bindep command]
2025-10-02 19:27:33.129727 | controller | skipping: Conditional result was False
2025-10-02 19:27:33.136995 | 
2025-10-02 19:27:33.137058 | TASK [bindep : Check for system bindep]
2025-10-02 19:27:33.667080 | controller | ok: Runtime: 0:00:00.005796
2025-10-02 19:27:33.679403 | 
2025-10-02 19:27:33.679540 | TASK [bindep : Define bindep_command fact]
2025-10-02 19:27:33.706054 | controller | skipping: Conditional result was False
2025-10-02 19:27:33.723949 | 
2025-10-02 19:27:33.724086 | TASK [bindep : Include install tasks]
2025-10-02 19:27:33.764030 | controller | ok
2025-10-02 19:27:33.775211 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-02 19:27:33.787568 | 
2025-10-02 19:27:33.787628 | TASK [bindep : Create temp dir for bindep]
2025-10-02 19:27:34.176625 | controller | changed
2025-10-02 19:27:34.185275 | 
2025-10-02 19:27:34.185363 | TASK [Ensure we have pip dependencies]
2025-10-02 19:27:34.206833 | controller | ok
2025-10-02 19:27:34.236607 | 
2025-10-02 19:27:34.236735 | TASK [ensure-pip : Check if pip is installed]
2025-10-02 15:27:34.498557 | controller | /usr/bin/pip3
2025-10-02 15:27:34.518870 | controller | /usr/bin/python3: No module named wheel
2025-10-02 19:27:34.778523 | controller | ok: Runtime: 0:00:00.031635
2025-10-02 19:27:34.784252 | 
2025-10-02 19:27:34.784313 | LOOP [ensure-pip : Install pip from packages]
2025-10-02 19:27:34.811828 | controller | ok: "/var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-02 19:27:34.828514 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-02 19:27:34.838468 | 
2025-10-02 19:27:34.838531 | TASK [ensure-pip : Install Python 3 pip]
2025-10-02 19:27:37.259750 | controller | changed
2025-10-02 19:27:37.269197 | 
2025-10-02 19:27:37.269320 | TASK [ensure-pip : Check for EPEL repository]
2025-10-02 19:27:37.333256 | controller | skipping: Conditional result was False
2025-10-02 19:27:37.339765 | 
2025-10-02 19:27:37.339832 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-02 19:27:37.396113 | controller | skipping: Conditional result was False
2025-10-02 19:27:37.402997 | 
2025-10-02 19:27:37.403067 | TASK [ensure-pip : Install Python 2 pip]
2025-10-02 19:27:37.437018 | controller | skipping: Conditional result was False
2025-10-02 19:27:37.443579 | 
2025-10-02 19:27:37.443647 | TASK [ensure-pip : Ensure setuptools]
2025-10-02 19:27:37.457123 | controller | skipping: Conditional result was False
2025-10-02 19:27:37.462901 | 
2025-10-02 19:27:37.462964 | TASK [ensure-pip : Check for ensurepip module]
2025-10-02 19:27:37.990425 | controller | skipping: Conditional result was False
2025-10-02 19:27:38.003990 | 
2025-10-02 19:27:38.004138 | TASK [ensure-pip : Ensure python3-venv]
2025-10-02 19:27:38.030973 | controller | skipping: Conditional result was False
2025-10-02 19:27:38.045311 | 
2025-10-02 19:27:38.045453 | TASK [ensure-pip : Install pip from source]
2025-10-02 19:27:38.072599 | controller | skipping: Conditional result was False
2025-10-02 19:27:38.085741 | 
2025-10-02 19:27:38.085885 | TASK [ensure-pip : Probe for venv python full path]
2025-10-02 15:27:38.412797 | controller | /usr/bin/python3
2025-10-02 19:27:38.650457 | controller | ok: Runtime: 0:00:00.009546
2025-10-02 19:27:38.656055 | 
2025-10-02 19:27:38.656119 | TASK [ensure-pip : Set host default]
2025-10-02 19:27:38.695603 | controller | ok
2025-10-02 19:27:38.701003 | 
2025-10-02 19:27:38.701080 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-02 19:27:38.741543 | controller | ok
2025-10-02 19:27:38.752881 | 
2025-10-02 19:27:38.752953 | TASK [bindep : Install bindep into temporary venv]
2025-10-02 19:27:43.246620 | controller | changed
2025-10-02 19:27:43.254772 | 
2025-10-02 19:27:43.254861 | TASK [bindep : Define bindep_command]
2025-10-02 19:27:43.308231 | controller | ok
2025-10-02 19:27:43.318212 | 
2025-10-02 19:27:43.318335 | LOOP [bindep : Include package tasks]
2025-10-02 19:27:43.404633 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-02 19:27:43.404844 | controller | ok: All items complete
2025-10-02 19:27:43.404880 | 
2025-10-02 19:27:43.427845 | controller | included: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-02 19:27:43.450648 | 
2025-10-02 19:27:43.450817 | TASK [bindep : Define bindep_run fact]
2025-10-02 19:27:43.484573 | controller | ok
2025-10-02 19:27:43.491776 | 
2025-10-02 19:27:43.491859 | TASK [bindep : Get list of packages to install from bindep]
2025-10-02 15:27:44.834150 | controller | podman
2025-10-02 15:27:44.862974 | controller | python3-jmespath
2025-10-02 15:27:44.863109 | controller | python3-libvirt
2025-10-02 15:27:44.863118 | controller | python3-lxml
2025-10-02 15:27:44.863126 | controller | python3-netaddr
2025-10-02 19:27:45.030769 | controller | ok: Runtime: 0:00:01.090781
2025-10-02 19:27:45.036668 | 
2025-10-02 19:27:45.036744 | TASK [bindep : Install distro packages from bindep]
2025-10-02 19:28:47.553587 | controller | changed
2025-10-02 19:28:47.559025 | 
2025-10-02 19:28:47.559102 | TASK [bindep : Check that packages are installed]
2025-10-02 19:28:49.091565 | controller | ok: Runtime: 0:00:01.089636
2025-10-02 19:28:49.104626 | 
2025-10-02 19:28:49.104863 | TASK [bindep : Fail if we cannot install all packages]
2025-10-02 19:28:49.143311 | controller | skipping: Conditional result was False
2025-10-02 19:28:49.167596 | 
2025-10-02 19:28:49.167794 | TASK [Run test-setup role]
2025-10-02 19:28:49.197308 | controller | ok
2025-10-02 19:28:49.228946 | 
2025-10-02 19:28:49.229063 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-02 19:28:49.464551 | controller | ok
2025-10-02 19:28:49.471782 | 
2025-10-02 19:28:49.471869 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-02 19:28:50.012147 | controller | skipping: Conditional result was False
2025-10-02 19:28:50.039696 | 
2025-10-02 19:28:50.039837 | TASK [bindep : Remove bindep temp dir]
2025-10-02 19:28:50.444108 | controller | ok
2025-10-02 19:28:50.466887 | 
2025-10-02 19:28:50.466994 | PLAY RECAP
2025-10-02 19:28:50.467079 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-02 19:28:50.467123 | 
2025-10-02 19:28:50.591755 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-02 19:28:50.593525 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-02 19:28:51.190494 | 
2025-10-02 19:28:51.190600 | PLAY [all]
2025-10-02 19:28:51.209950 | 
2025-10-02 19:28:51.210024 | TASK [Abort when test_command variable is undefined]
2025-10-02 19:28:51.244987 | controller | skipping: Conditional result was False
2025-10-02 19:28:51.251256 | 
2025-10-02 19:28:51.251332 | TASK [Convert test_command to list]
2025-10-02 19:28:51.306027 | controller | skipping: Conditional result was False
2025-10-02 19:28:51.312464 | 
2025-10-02 19:28:51.312532 | TASK [Use test_command list]
2025-10-02 19:28:51.379021 | controller | ok
2025-10-02 19:28:51.391152 | 
2025-10-02 19:28:51.391279 | LOOP [Run test_command]
2025-10-02 19:28:51.809386 | controller | no check to run
2025-10-02 19:28:51.809778 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006019
2025-10-02 19:28:51.836907 | 
2025-10-02 19:28:51.837007 | PLAY RECAP
2025-10-02 19:28:51.837048 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-02 19:28:51.837069 | 
2025-10-02 19:28:51.929008 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-02 19:28:51.930740 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-02 19:28:52.520363 | 
2025-10-02 19:28:52.520474 | PLAY [all]
2025-10-02 19:28:52.541656 | 
2025-10-02 19:28:52.541774 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-02 19:28:52.956116 | controller | changed: non-zero return code
2025-10-02 19:28:52.968081 | 
2025-10-02 19:28:52.968243 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-02 19:28:52.995027 | controller | skipping: Conditional result was False
2025-10-02 19:28:53.007615 | 
2025-10-02 19:28:53.007792 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-02 19:28:53.047127 | 
2025-10-02 19:28:53.047384 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-02 19:28:53.085079 | 
2025-10-02 19:28:53.085345 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-02 19:28:53.111318 | controller | skipping: Conditional result was False
2025-10-02 19:28:53.123996 | 
2025-10-02 19:28:53.124186 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-02 19:28:53.164496 | 
2025-10-02 19:28:53.164790 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-02 19:28:53.190648 | controller | skipping: Conditional result was False
2025-10-02 19:28:53.202424 | 
2025-10-02 19:28:53.202566 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-02 19:28:53.228450 | controller | skipping: Conditional result was False
2025-10-02 19:28:53.240670 | 
2025-10-02 19:28:53.240842 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-02 19:28:53.266966 | controller | skipping: Conditional result was False
2025-10-02 19:28:53.313155 | 
2025-10-02 19:28:53.313237 | PLAY RECAP
2025-10-02 19:28:53.313296 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-02 19:28:53.313324 | 
2025-10-02 19:28:53.408252 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-02 19:28:53.409947 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-02 19:28:53.999669 | 
2025-10-02 19:28:53.999808 | PLAY [all]
2025-10-02 19:28:54.019022 | 
2025-10-02 19:28:54.019099 | TASK [include_role : fetch-output]
2025-10-02 19:28:54.057817 | controller | ok
2025-10-02 19:28:54.075606 | 
2025-10-02 19:28:54.075712 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-02 19:28:54.140742 | controller | skipping: Conditional result was False
2025-10-02 19:28:54.158312 | 
2025-10-02 19:28:54.158531 | TASK [fetch-output : Set log path for single node]
2025-10-02 19:28:54.207522 | controller | ok
2025-10-02 19:28:54.219343 | 
2025-10-02 19:28:54.219484 | LOOP [fetch-output : Ensure local output dirs]
2025-10-02 19:28:54.648128 | controller -> localhost | ok: "/var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/logs"
2025-10-02 19:28:54.909576 | controller -> localhost | changed: "/var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/artifacts"
2025-10-02 19:28:55.135667 | controller -> localhost | changed: "/var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/docs"
2025-10-02 19:28:55.151487 | 
2025-10-02 19:28:55.151576 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-02 19:28:55.862845 | controller | changed: .d..t...... ./
2025-10-02 19:28:55.863176 | controller | changed: All items complete
2025-10-02 19:28:55.863235 | 
2025-10-02 19:28:56.315618 | controller | changed: .d..t...... ./
2025-10-02 19:28:56.832382 | controller | changed: .d..t...... ./
2025-10-02 19:28:56.858074 | 
2025-10-02 19:28:56.858220 | TASK [include_role : fetch-output-openshift]
2025-10-02 19:28:56.873661 | controller | skipping: Conditional result was False
2025-10-02 19:28:56.883301 | 
2025-10-02 19:28:56.883441 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-02 19:28:57.371379 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.019899
2025-10-02 19:28:57.587419 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008650
2025-10-02 19:28:57.630407 | 
2025-10-02 19:28:57.630578 | PLAY [all]
2025-10-02 19:28:57.650333 | 
2025-10-02 19:28:57.650421 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-02 19:28:58.093522 | controller | changed
2025-10-02 19:28:58.131837 | 
2025-10-02 19:28:58.131908 | PLAY RECAP
2025-10-02 19:28:58.131963 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-02 19:28:58.131991 | 
2025-10-02 19:28:58.228483 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-02 19:28:58.229336 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-02 19:28:58.847035 | 
2025-10-02 19:28:58.847179 | PLAY [localhost]
2025-10-02 19:28:58.865144 | 
2025-10-02 19:28:58.865221 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-02 19:28:59.227478 | localhost | changed
2025-10-02 19:28:59.232166 | 
2025-10-02 19:28:59.232242 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-02 19:28:59.261717 | localhost | ok
2025-10-02 19:28:59.270221 | 
2025-10-02 19:28:59.270307 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-02 19:28:59.658397 | localhost | changed
2025-10-02 19:28:59.663706 | 
2025-10-02 19:28:59.663778 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-02 19:29:00.265556 | localhost | changed
2025-10-02 19:29:00.273566 | 
2025-10-02 19:29:00.273769 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-02 19:29:00.712377 | localhost | Identity added: /var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/tmp/ansible.9_k1jr1b (/var/lib/zuul/builds/02a096d1c5df42e09cfae514e695d67b/work/tmp/ansible.9_k1jr1b)
2025-10-02 19:29:00.712569 | localhost | ok: Runtime: 0:00:00.019873
2025-10-02 19:29:00.717118 | 
2025-10-02 19:29:00.717184 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-02 19:29:00.998475 | localhost | ok: Runtime: 0:00:00.005545
2025-10-02 19:29:01.003363 | 
2025-10-02 19:29:01.003427 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-02 19:29:01.083203 | localhost | changed
2025-10-02 19:29:01.087691 | 
2025-10-02 19:29:01.087757 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-02 19:29:01.470102 | localhost | changed
2025-10-02 19:29:01.490481 | 
2025-10-02 19:29:01.490596 | PLAY [localhost]
2025-10-02 19:29:01.502395 | 
2025-10-02 19:29:01.502561 | TASK [Generate bulk log download script]
2025-10-02 19:29:01.532443 | localhost | ok
2025-10-02 19:29:01.548295 | 
2025-10-02 19:29:01.548418 | TASK [local-log-download : Check API endpoint is defined]
2025-10-02 19:29:01.587989 | localhost | ok: All assertions passed
2025-10-02 19:29:01.592477 | 
2025-10-02 19:29:01.592539 | TASK [local-log-download : Create download script]
2025-10-02 19:29:02.055751 | localhost -> localhost | changed
2025-10-02 19:29:02.078103 | 
2025-10-02 19:29:02.078270 | TASK [Register quick-download link]
2025-10-02 19:29:02.115359 | localhost | ok
2025-10-02 19:29:02.180797 | 
2025-10-02 19:29:02.180905 | PLAY [logserver.rdoproject.org]
2025-10-02 19:29:02.201002 | 
2025-10-02 19:29:02.201190 | TASK [Set zuul-log-path fact]
2025-10-02 19:29:02.222763 | logserver.rdoproject.org | ok
2025-10-02 19:29:02.245870 | 
2025-10-02 19:29:02.246006 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 19:29:02.277824 | logserver.rdoproject.org | ok
2025-10-02 19:29:02.289321 | 
2025-10-02 19:29:02.289454 | TASK [upload-logs : Create log directories]
2025-10-02 19:29:03.199243 | logserver.rdoproject.org | changed
2025-10-02 19:29:03.205886 | 
2025-10-02 19:29:03.206024 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-02 19:29:03.528012 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009026
2025-10-02 19:29:03.532957 | 
2025-10-02 19:29:03.533021 | TASK [upload-logs : Upload logs to log server]
2025-10-02 19:29:04.243030 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-02 19:29:04.246261 | 
2025-10-02 19:29:04.246330 | LOOP [upload-logs : Compress console log and json output]
2025-10-02 19:29:04.320261 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 19:29:04.332405 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 19:29:04.341967 | 
2025-10-02 19:29:04.342074 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-02 19:29:04.388248 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 19:29:04.388490 | 
2025-10-02 19:29:04.390584 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 19:29:04.403749 | 
2025-10-02 19:29:04.403843 | LOOP [upload-logs : Upload console log and json output]