2025-10-01 10:43:01.759431 | Job console starting...
2025-10-01 10:43:01.768451 | Updating repositories
2025-10-01 10:43:01.819565 | Preparing job workspace
2025-10-01 10:43:07.370087 | Running Ansible setup...
2025-10-01 10:43:13.667528 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-01 10:43:15.162244 | 
2025-10-01 10:43:15.162377 | PLAY [localhost]
2025-10-01 10:43:15.190661 | 
2025-10-01 10:43:15.208413 | TASK [Gathering Facts]
2025-10-01 10:43:16.946749 | localhost | ok
2025-10-01 10:43:16.994632 | 
2025-10-01 10:43:16.994759 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-01 10:43:18.096631 | localhost -> localhost | changed
2025-10-01 10:43:18.102388 | 
2025-10-01 10:43:18.102460 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-01 10:43:20.125647 | localhost -> localhost | changed
2025-10-01 10:43:20.135164 | 
2025-10-01 10:43:20.135271 | TASK [Setup log path fact]
2025-10-01 10:43:20.190489 | localhost | ok
2025-10-01 10:43:20.219273 | 
2025-10-01 10:43:20.219388 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-01 10:43:20.282417 | localhost | ok
2025-10-01 10:43:20.290605 | 
2025-10-01 10:43:20.290734 | TASK [emit-job-header : Print job information]
2025-10-01 10:43:20.360270 | # Job Information
2025-10-01 10:43:20.360428 | Ansible Version: 2.15.12
2025-10-01 10:43:20.360455 | Job: cifmw-molecule-cifmw_nfs
2025-10-01 10:43:20.360476 | Pipeline: github-check
2025-10-01 10:43:20.360496 | Executor: ze01.softwarefactory-project.io
2025-10-01 10:43:20.360514 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-01 10:43:20.360532 | Log URL (when completed): https://logserver.rdoproject.org/897/rdoproject.org/897a110f8a234d39a4d745fbb9e80635/
2025-10-01 10:43:20.360550 | Event ID: 2c962f60-9eb3-11f0-844e-f06c90bcb25f
2025-10-01 10:43:20.365579 | 
2025-10-01 10:43:20.365655 | LOOP [emit-job-header : Print node information]
2025-10-01 10:43:20.641337 | localhost | ok:
2025-10-01 10:43:20.641500 | localhost | # Node Information
2025-10-01 10:43:20.641526 | localhost | Inventory Hostname: controller
2025-10-01 10:43:20.641552 | localhost | Hostname: np0005464332
2025-10-01 10:43:20.641572 | localhost | Username: zuul
2025-10-01 10:43:20.641591 | localhost | Distro: CentOS 9
2025-10-01 10:43:20.641764 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-01 10:43:20.641793 | localhost | Region: RegionOne
2025-10-01 10:43:20.641816 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-01 10:43:20.641837 | localhost | Product Name: OpenStack Nova
2025-10-01 10:43:20.641855 | localhost | Interface IP: 38.129.56.61
2025-10-01 10:43:20.745229 | 
2025-10-01 10:43:20.745331 | PLAY [all]
2025-10-01 10:43:20.779936 | 
2025-10-01 10:43:20.780080 | TASK [Gather network facts]
2025-10-01 10:43:21.361603 | controller | ok
2025-10-01 10:43:21.437882 | 
2025-10-01 10:43:21.437995 | TASK [include_role : start-zuul-console]
2025-10-01 10:43:21.502183 | controller | ok
2025-10-01 10:43:21.515852 | 
2025-10-01 10:43:21.515961 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-01 10:43:22.151275 | controller | ok
2025-10-01 10:43:22.174515 | 
2025-10-01 10:43:22.174628 | TASK [include_role : add-build-sshkey]
2025-10-01 10:43:22.236661 | controller | ok
2025-10-01 10:43:22.254459 | 
2025-10-01 10:43:22.254561 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-01 10:43:22.861446 | controller -> localhost | ok
2025-10-01 10:43:22.868036 | 
2025-10-01 10:43:22.868129 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-01 10:43:22.936083 | controller | ok
2025-10-01 10:43:23.003087 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-01 10:43:23.042112 | 
2025-10-01 10:43:23.042264 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-01 10:43:24.179131 | controller -> localhost | Generating public/private rsa key pair.
2025-10-01 10:43:24.179399 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/897a110f8a234d39a4d745fbb9e80635_id_rsa.
2025-10-01 10:43:24.179436 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/897a110f8a234d39a4d745fbb9e80635_id_rsa.pub.
2025-10-01 10:43:24.179459 | controller -> localhost | The key fingerprint is:
2025-10-01 10:43:24.179480 | controller -> localhost | SHA256:wRsW3QfTbyoKxNo+Y0nU376cPGp2VBmdkRD6K8YAhMQ zuul-build-sshkey
2025-10-01 10:43:24.179502 | controller -> localhost | The key's randomart image is:
2025-10-01 10:43:24.179521 | controller -> localhost | +---[RSA 3072]----+
2025-10-01 10:43:24.179540 | controller -> localhost | |    o..... .o=o.=|
2025-10-01 10:43:24.179559 | controller -> localhost | |     E.. .. o.o+.|
2025-10-01 10:43:24.179578 | controller -> localhost | |       o=. . . .o|
2025-10-01 10:43:24.179596 | controller -> localhost | |       .=+. .  .+|
2025-10-01 10:43:24.179614 | controller -> localhost | |       =S. . o + |
2025-10-01 10:43:24.179631 | controller -> localhost | |      . + o o =  |
2025-10-01 10:43:24.179649 | controller -> localhost | |       o o = =   |
2025-10-01 10:43:24.179669 | controller -> localhost | |        * o +o+. |
2025-10-01 10:43:24.179687 | controller -> localhost | |       . o o.o=o |
2025-10-01 10:43:24.179704 | controller -> localhost | +----[SHA256]-----+
2025-10-01 10:43:24.179752 | controller -> localhost | ok: Runtime: 0:00:00.344788
2025-10-01 10:43:24.185596 | 
2025-10-01 10:43:24.185668 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-01 10:43:24.256107 | controller | ok
2025-10-01 10:43:24.275990 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-01 10:43:24.291411 | 
2025-10-01 10:43:24.291509 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-01 10:43:24.336202 | controller | skipping: Conditional result was False
2025-10-01 10:43:24.343668 | 
2025-10-01 10:43:24.343754 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-01 10:43:25.182487 | controller | changed
2025-10-01 10:43:25.187921 | 
2025-10-01 10:43:25.187986 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-01 10:43:25.542333 | controller | ok
2025-10-01 10:43:25.547446 | 
2025-10-01 10:43:25.547506 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-01 10:43:26.682248 | controller | changed
2025-10-01 10:43:26.699489 | 
2025-10-01 10:43:26.699620 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-01 10:43:27.925540 | controller | changed
2025-10-01 10:43:27.930837 | 
2025-10-01 10:43:27.930905 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-01 10:43:28.037385 | controller | skipping: Conditional result was False
2025-10-01 10:43:28.044076 | 
2025-10-01 10:43:28.044190 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-01 10:43:28.972863 | controller -> localhost | changed
2025-10-01 10:43:29.073413 | 
2025-10-01 10:43:29.073538 | TASK [add-build-sshkey : Add back temp key]
2025-10-01 10:43:29.767795 | controller -> localhost | Identity added: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/897a110f8a234d39a4d745fbb9e80635_id_rsa (zuul-build-sshkey)
2025-10-01 10:43:29.767994 | controller -> localhost | ok: Runtime: 0:00:00.023108
2025-10-01 10:43:29.773719 | 
2025-10-01 10:43:29.773784 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-01 10:43:30.334841 | controller | ok
2025-10-01 10:43:30.339725 | 
2025-10-01 10:43:30.339818 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-01 10:43:30.407093 | controller | skipping: Conditional result was False
2025-10-01 10:43:30.418386 | 
2025-10-01 10:43:30.418483 | TASK [include_role : validate-host]
2025-10-01 10:43:30.454323 | controller | ok
2025-10-01 10:43:30.482683 | 
2025-10-01 10:43:30.482800 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-01 10:43:30.532322 | controller | ok
2025-10-01 10:43:30.537099 | 
2025-10-01 10:43:30.537161 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-01 10:43:31.041562 | controller -> localhost | ok
2025-10-01 10:43:31.050276 | 
2025-10-01 10:43:31.050385 | TASK [validate-host : Collect information about the host]
2025-10-01 10:43:31.932823 | controller | ok
2025-10-01 10:43:31.975661 | 
2025-10-01 10:43:31.975772 | TASK [validate-host : Sanitize hostname]
2025-10-01 10:43:32.059951 | controller | ok
2025-10-01 10:43:32.118237 | 
2025-10-01 10:43:32.118351 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-01 10:43:34.020641 | controller -> localhost | changed
2025-10-01 10:43:34.027080 | 
2025-10-01 10:43:34.027178 | TASK [validate-host : Collect information about zuul worker]
2025-10-01 10:43:34.798277 | controller | ok
2025-10-01 10:43:34.806420 | 
2025-10-01 10:43:34.806537 | TASK [validate-host : Write out all zuul information for each host]
2025-10-01 10:43:36.259307 | controller -> localhost | changed
2025-10-01 10:43:36.268845 | 
2025-10-01 10:43:36.268946 | TASK [include_role : prepare-workspace-openshift]
2025-10-01 10:43:36.325852 | controller | skipping: Conditional result was False
2025-10-01 10:43:36.330886 | 
2025-10-01 10:43:36.330957 | TASK [include_role : remove-zuul-sshkey]
2025-10-01 10:43:36.355793 | controller | skipping: Conditional result was False
2025-10-01 10:43:36.372877 | 
2025-10-01 10:43:36.373040 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-01 10:43:36.645458 | controller | ok: "logs"
2025-10-01 10:43:36.645668 | controller | ok: All items complete
2025-10-01 10:43:36.645696 | 
2025-10-01 10:43:36.890601 | controller | ok: "artifacts"
2025-10-01 10:43:37.151271 | controller | ok: "docs"
2025-10-01 10:43:37.164137 | 
2025-10-01 10:43:37.164252 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-01 10:43:37.517206 | controller | changed: "logs"
2025-10-01 10:43:37.772429 | controller | changed: "artifacts"
2025-10-01 10:43:38.005946 | controller | changed: "docs"
2025-10-01 10:43:38.090195 | 
2025-10-01 10:43:38.090305 | PLAY RECAP
2025-10-01 10:43:38.090350 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-01 10:43:38.090377 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-01 10:43:38.090395 | 
2025-10-01 10:43:38.418512 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-01 10:43:38.419434 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-01 10:43:40.450918 | 
2025-10-01 10:43:40.451080 | PLAY [localhost]
2025-10-01 10:43:40.480104 | 
2025-10-01 10:43:40.480238 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-01 10:43:41.327473 | localhost | ok
2025-10-01 10:43:41.334250 | 
2025-10-01 10:43:41.334361 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-01 10:43:42.441287 | localhost | changed
2025-10-01 10:43:42.489256 | 
2025-10-01 10:43:42.489356 | PLAY [all]
2025-10-01 10:43:42.528349 | 
2025-10-01 10:43:42.528463 | TASK [include_role : prepare-workspace]
2025-10-01 10:43:42.572429 | controller | ok
2025-10-01 10:43:42.610237 | 
2025-10-01 10:43:42.610408 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-01 10:43:43.210139 | controller | ok
2025-10-01 10:43:43.226982 | 
2025-10-01 10:43:43.227296 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-01 10:43:47.156883 | controller | Output suppressed because no_log was given
2025-10-01 10:43:47.181462 | 
2025-10-01 10:43:47.181593 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-01 10:43:47.531577 | controller | changed: "logs"
2025-10-01 10:43:47.758233 | controller | changed: "artifacts"
2025-10-01 10:43:48.004614 | controller | changed: "docs"
2025-10-01 10:43:48.021573 | 
2025-10-01 10:43:48.021690 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-01 10:43:48.307543 | controller | changed: "logs"
2025-10-01 10:43:48.307765 | controller | changed: All items complete
2025-10-01 10:43:48.307793 | 
2025-10-01 10:43:48.570299 | controller | changed: "artifacts"
2025-10-01 10:43:48.800480 | controller | changed: "docs"
2025-10-01 10:43:48.827969 | 
2025-10-01 10:43:48.828160 | TASK [Check if worker can sudo]
2025-10-01 10:43:49.903733 | controller | ok: Runtime: 0:00:00.060799
2025-10-01 10:43:49.909675 | 
2025-10-01 10:43:49.909746 | TASK [configure-mirrors : Gather needed facts]
2025-10-01 10:43:50.060492 | controller | skipping: Conditional result was False
2025-10-01 10:43:50.066703 | 
2025-10-01 10:43:50.066771 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-01 10:43:50.151835 | controller | ok
2025-10-01 10:43:50.159919 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-01 10:43:50.166521 | 
2025-10-01 10:43:50.166597 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-01 10:43:50.456331 | controller | ok
2025-10-01 10:43:50.464687 | 
2025-10-01 10:43:50.464751 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-01 10:43:50.606666 | controller | ok: "/var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-01 10:43:50.618766 | 
2025-10-01 10:43:50.618877 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-01 10:43:51.736435 | controller | changed
2025-10-01 10:43:51.742549 | 
2025-10-01 10:43:51.742630 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-01 10:43:51.859679 | controller | ok: "/var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-01 10:43:51.859867 | controller | ok: All items complete
2025-10-01 10:43:51.859895 | 
2025-10-01 10:43:52.020415 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-01 10:43:52.049923 | 
2025-10-01 10:43:52.050065 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-01 10:43:53.203369 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-01 10:43:54.248968 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-01 10:43:54.265542 | 
2025-10-01 10:43:54.265668 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-01 10:43:55.434172 | controller | changed: section and option added
2025-10-01 10:43:55.519758 | 
2025-10-01 10:43:55.519880 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-01 10:43:56.516666 | controller | 29 files removed
2025-10-01 10:43:56.516930 | controller | ok: Item: dnf clean all Runtime: 0:00:00.477023
2025-10-01 10:43:56.516972 | controller | changed: All items complete
2025-10-01 10:43:56.516994 | 
2025-10-01 10:44:07.780846 | 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-01 10:44:07.780952 | controller | DNF version: 4.14.0
2025-10-01 10:44:07.780976 | controller | cachedir: /var/cache/dnf
2025-10-01 10:44:07.780995 | controller | Making cache files for all metadata files.
2025-10-01 10:44:07.781028 | controller | baseos: has expired and will be refreshed.
2025-10-01 10:44:07.783323 | controller | appstream: has expired and will be refreshed.
2025-10-01 10:44:07.783365 | controller | crb: has expired and will be refreshed.
2025-10-01 10:44:07.783397 | controller | extras-common: has expired and will be refreshed.
2025-10-01 10:44:07.783416 | controller | repo: downloading from remote: baseos
2025-10-01 10:44:07.783433 | controller | CentOS Stream 9 - BaseOS                         54 MB/s | 8.8 MB     00:00
2025-10-01 10:44:07.783450 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-01 10:44:07.783466 | controller | repo: downloading from remote: appstream
2025-10-01 10:44:07.783482 | controller | CentOS Stream 9 - AppStream                      84 MB/s |  25 MB     00:00
2025-10-01 10:44:07.783498 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-01 10:44:07.783514 | controller | repo: downloading from remote: crb
2025-10-01 10:44:07.783530 | controller | CentOS Stream 9 - CRB                            35 MB/s | 7.1 MB     00:00
2025-10-01 10:44:07.783547 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-01 10:44:07.783563 | controller | repo: downloading from remote: extras-common
2025-10-01 10:44:07.783580 | controller | CentOS Stream 9 - Extras packages               1.1 MB/s |  20 kB     00:00
2025-10-01 10:44:07.783596 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-01 10:44:07.783613 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-01 10:44:07.783630 | controller | Completion plugin: Generating completion cache...
2025-10-01 10:44:07.783646 | controller | Metadata cache created.
2025-10-01 10:44:07.783673 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.980590
2025-10-01 10:44:07.807353 | 
2025-10-01 10:44:07.807457 | PLAY RECAP
2025-10-01 10:44:07.807502 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-01 10:44:07.807529 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-01 10:44:07.807547 | 
2025-10-01 10:44:07.926573 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-01 10:44:07.927354 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-01 10:44:08.800862 | 
2025-10-01 10:44:08.800969 | PLAY [all]
2025-10-01 10:44:08.822952 | 
2025-10-01 10:44:08.823085 | TASK [Install binary dependencies]
2025-10-01 10:44:08.941396 | controller | ok
2025-10-01 10:44:09.002355 | 
2025-10-01 10:44:09.002490 | TASK [bindep : Include find tasks]
2025-10-01 10:44:09.056806 | controller | ok
2025-10-01 10:44:09.093130 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-01 10:44:09.099974 | 
2025-10-01 10:44:09.100116 | TASK [bindep : Look for bindep.txt]
2025-10-01 10:44:09.805731 | controller | ok
2025-10-01 10:44:09.828842 | 
2025-10-01 10:44:09.828961 | TASK [bindep : Define bindep_file fact]
2025-10-01 10:44:09.887127 | controller | ok
2025-10-01 10:44:09.895533 | 
2025-10-01 10:44:09.895690 | TASK [bindep : Look for other-requirements.txt]
2025-10-01 10:44:09.919695 | controller | skipping: Conditional result was False
2025-10-01 10:44:09.926684 | 
2025-10-01 10:44:09.926780 | TASK [bindep : Define bindep_file fact]
2025-10-01 10:44:09.989601 | controller | skipping: Conditional result was False
2025-10-01 10:44:09.995782 | 
2025-10-01 10:44:09.995850 | TASK [bindep : Look for bindep fallback file]
2025-10-01 10:44:10.050163 | controller | skipping: Conditional result was False
2025-10-01 10:44:10.056065 | 
2025-10-01 10:44:10.056136 | TASK [bindep : Define bindep_file fact]
2025-10-01 10:44:10.111439 | controller | skipping: Conditional result was False
2025-10-01 10:44:10.118725 | 
2025-10-01 10:44:10.118820 | TASK [bindep : Include bindep tasks]
2025-10-01 10:44:10.169682 | controller | ok
2025-10-01 10:44:10.177658 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-01 10:44:10.191384 | 
2025-10-01 10:44:10.191467 | TASK [bindep : Look for bindep command]
2025-10-01 10:44:10.256055 | controller | skipping: Conditional result was False
2025-10-01 10:44:10.262549 | 
2025-10-01 10:44:10.262613 | TASK [bindep : Check for system bindep]
2025-10-01 10:44:11.345378 | controller | ok: Runtime: 0:00:00.006990
2025-10-01 10:44:11.351158 | 
2025-10-01 10:44:11.351229 | TASK [bindep : Define bindep_command fact]
2025-10-01 10:44:11.420224 | controller | skipping: Conditional result was False
2025-10-01 10:44:11.429214 | 
2025-10-01 10:44:11.429332 | TASK [bindep : Include install tasks]
2025-10-01 10:44:11.485168 | controller | ok
2025-10-01 10:44:11.492703 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-01 10:44:11.503080 | 
2025-10-01 10:44:11.503153 | TASK [bindep : Create temp dir for bindep]
2025-10-01 10:44:12.188228 | controller | changed
2025-10-01 10:44:12.200502 | 
2025-10-01 10:44:12.200622 | TASK [Ensure we have pip dependencies]
2025-10-01 10:44:12.259572 | controller | ok
2025-10-01 10:44:12.349570 | 
2025-10-01 10:44:12.349685 | TASK [ensure-pip : Check if pip is installed]
2025-10-01 06:44:12.770140 | controller | /usr/bin/pip3
2025-10-01 06:44:12.790339 | controller | /usr/bin/python3: No module named wheel
2025-10-01 10:44:12.938325 | controller | ok: Runtime: 0:00:00.030662
2025-10-01 10:44:12.944659 | 
2025-10-01 10:44:12.944730 | LOOP [ensure-pip : Install pip from packages]
2025-10-01 10:44:12.984999 | controller | ok: "/var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-01 10:44:13.007055 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-01 10:44:13.123134 | 
2025-10-01 10:44:13.123292 | TASK [ensure-pip : Install Python 3 pip]
2025-10-01 10:44:15.979089 | controller | changed
2025-10-01 10:44:15.986642 | 
2025-10-01 10:44:15.986729 | TASK [ensure-pip : Check for EPEL repository]
2025-10-01 10:44:16.042549 | controller | skipping: Conditional result was False
2025-10-01 10:44:16.050372 | 
2025-10-01 10:44:16.050593 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-01 10:44:16.088164 | controller | skipping: Conditional result was False
2025-10-01 10:44:16.097681 | 
2025-10-01 10:44:16.097820 | TASK [ensure-pip : Install Python 2 pip]
2025-10-01 10:44:16.151992 | controller | skipping: Conditional result was False
2025-10-01 10:44:16.161002 | 
2025-10-01 10:44:16.161158 | TASK [ensure-pip : Ensure setuptools]
2025-10-01 10:44:16.189136 | controller | skipping: Conditional result was False
2025-10-01 10:44:16.203390 | 
2025-10-01 10:44:16.203542 | TASK [ensure-pip : Check for ensurepip module]
2025-10-01 10:44:16.757211 | controller | skipping: Conditional result was False
2025-10-01 10:44:16.764136 | 
2025-10-01 10:44:16.764254 | TASK [ensure-pip : Ensure python3-venv]
2025-10-01 10:44:16.810776 | controller | skipping: Conditional result was False
2025-10-01 10:44:16.824010 | 
2025-10-01 10:44:16.824174 | TASK [ensure-pip : Install pip from source]
2025-10-01 10:44:16.840409 | controller | skipping: Conditional result was False
2025-10-01 10:44:16.848866 | 
2025-10-01 10:44:16.848969 | TASK [ensure-pip : Probe for venv python full path]
2025-10-01 06:44:17.140467 | controller | /usr/bin/python3
2025-10-01 10:44:17.400852 | controller | ok: Runtime: 0:00:00.005016
2025-10-01 10:44:17.406565 | 
2025-10-01 10:44:17.406645 | TASK [ensure-pip : Set host default]
2025-10-01 10:44:17.451598 | controller | ok
2025-10-01 10:44:17.457216 | 
2025-10-01 10:44:17.457279 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-01 10:44:17.522410 | controller | ok
2025-10-01 10:44:17.537461 | 
2025-10-01 10:44:17.537549 | TASK [bindep : Install bindep into temporary venv]
2025-10-01 10:44:21.894693 | controller | changed
2025-10-01 10:44:21.911529 | 
2025-10-01 10:44:21.911753 | TASK [bindep : Define bindep_command]
2025-10-01 10:44:21.965041 | controller | ok
2025-10-01 10:44:21.973607 | 
2025-10-01 10:44:21.973694 | LOOP [bindep : Include package tasks]
2025-10-01 10:44:22.064439 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-01 10:44:22.064680 | controller | ok: All items complete
2025-10-01 10:44:22.064717 | 
2025-10-01 10:44:22.077172 | controller | included: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-01 10:44:22.091146 | 
2025-10-01 10:44:22.091322 | TASK [bindep : Define bindep_run fact]
2025-10-01 10:44:22.134783 | controller | ok
2025-10-01 10:44:22.143163 | 
2025-10-01 10:44:22.143413 | TASK [bindep : Get list of packages to install from bindep]
2025-10-01 06:44:23.674367 | controller | podman
2025-10-01 06:44:23.723248 | controller | python3-jmespath
2025-10-01 06:44:23.723452 | controller | python3-libvirt
2025-10-01 06:44:23.723465 | controller | python3-lxml
2025-10-01 06:44:23.723479 | controller | python3-netaddr
2025-10-01 10:44:24.194621 | controller | ok: Runtime: 0:00:01.296123
2025-10-01 10:44:24.200898 | 
2025-10-01 10:44:24.201044 | TASK [bindep : Install distro packages from bindep]
2025-10-01 10:45:31.669618 | controller | changed
2025-10-01 10:45:31.683116 | 
2025-10-01 10:45:31.683265 | TASK [bindep : Check that packages are installed]
2025-10-01 10:45:33.736079 | controller | ok: Runtime: 0:00:01.526677
2025-10-01 10:45:33.743784 | 
2025-10-01 10:45:33.743926 | TASK [bindep : Fail if we cannot install all packages]
2025-10-01 10:45:33.779483 | controller | skipping: Conditional result was False
2025-10-01 10:45:33.794509 | 
2025-10-01 10:45:33.794647 | TASK [Run test-setup role]
2025-10-01 10:45:33.827948 | controller | ok
2025-10-01 10:45:33.852432 | 
2025-10-01 10:45:33.852582 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-01 10:45:34.129915 | controller | ok
2025-10-01 10:45:34.137613 | 
2025-10-01 10:45:34.137750 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-01 10:45:34.678747 | controller | skipping: Conditional result was False
2025-10-01 10:45:34.710790 | 
2025-10-01 10:45:34.710940 | TASK [bindep : Remove bindep temp dir]
2025-10-01 10:45:35.064765 | controller | ok
2025-10-01 10:45:35.075562 | 
2025-10-01 10:45:35.075663 | PLAY RECAP
2025-10-01 10:45:35.075705 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-01 10:45:35.075727 | 
2025-10-01 10:45:35.195440 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-01 10:45:35.196320 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-01 10:45:35.786355 | 
2025-10-01 10:45:35.786486 | PLAY [all]
2025-10-01 10:45:35.817752 | 
2025-10-01 10:45:35.817922 | TASK [Abort when test_command variable is undefined]
2025-10-01 10:45:35.863424 | controller | skipping: Conditional result was False
2025-10-01 10:45:35.870167 | 
2025-10-01 10:45:35.870327 | TASK [Convert test_command to list]
2025-10-01 10:45:35.933474 | controller | skipping: Conditional result was False
2025-10-01 10:45:35.941261 | 
2025-10-01 10:45:35.941377 | TASK [Use test_command list]
2025-10-01 10:45:35.997817 | controller | ok
2025-10-01 10:45:36.005684 | 
2025-10-01 10:45:36.005843 | LOOP [Run test_command]
2025-10-01 10:45:36.410646 | controller | no check to run
2025-10-01 10:45:36.410845 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006295
2025-10-01 10:45:36.446493 | 
2025-10-01 10:45:36.446613 | PLAY RECAP
2025-10-01 10:45:36.446665 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-01 10:45:36.446711 | 
2025-10-01 10:45:36.560620 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-01 10:45:36.561434 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-01 10:45:37.135105 | 
2025-10-01 10:45:37.135229 | PLAY [all]
2025-10-01 10:45:37.158005 | 
2025-10-01 10:45:37.158160 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-01 10:45:37.567428 | controller | changed: non-zero return code
2025-10-01 10:45:37.576279 | 
2025-10-01 10:45:37.576415 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-01 10:45:37.602732 | controller | skipping: Conditional result was False
2025-10-01 10:45:37.610109 | 
2025-10-01 10:45:37.610212 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-01 10:45:37.632946 | 
2025-10-01 10:45:37.633234 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-01 10:45:37.667543 | 
2025-10-01 10:45:37.667713 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-01 10:45:37.685435 | controller | skipping: Conditional result was False
2025-10-01 10:45:37.696257 | 
2025-10-01 10:45:37.696360 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-01 10:45:37.718161 | 
2025-10-01 10:45:37.718440 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-01 10:45:37.735605 | controller | skipping: Conditional result was False
2025-10-01 10:45:37.742471 | 
2025-10-01 10:45:37.742574 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-01 10:45:37.769690 | controller | skipping: Conditional result was False
2025-10-01 10:45:37.776054 | 
2025-10-01 10:45:37.776126 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-01 10:45:37.809857 | controller | skipping: Conditional result was False
2025-10-01 10:45:37.843118 | 
2025-10-01 10:45:37.843203 | PLAY RECAP
2025-10-01 10:45:37.843245 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-01 10:45:37.843266 | 
2025-10-01 10:45:37.947057 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-01 10:45:37.947825 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-01 10:45:38.621476 | 
2025-10-01 10:45:38.621596 | PLAY [all]
2025-10-01 10:45:38.643569 | 
2025-10-01 10:45:38.643722 | TASK [include_role : fetch-output]
2025-10-01 10:45:38.677237 | controller | ok
2025-10-01 10:45:38.705289 | 
2025-10-01 10:45:38.705456 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-01 10:45:38.752802 | controller | skipping: Conditional result was False
2025-10-01 10:45:38.761527 | 
2025-10-01 10:45:38.761690 | TASK [fetch-output : Set log path for single node]
2025-10-01 10:45:38.792447 | controller | ok
2025-10-01 10:45:38.797964 | 
2025-10-01 10:45:38.798115 | LOOP [fetch-output : Ensure local output dirs]
2025-10-01 10:45:39.214816 | controller -> localhost | ok: "/var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/logs"
2025-10-01 10:45:39.473267 | controller -> localhost | changed: "/var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/artifacts"
2025-10-01 10:45:39.716069 | controller -> localhost | changed: "/var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/docs"
2025-10-01 10:45:39.731377 | 
2025-10-01 10:45:39.731497 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-01 10:45:40.400194 | controller | changed: .d..t...... ./
2025-10-01 10:45:40.400387 | controller | changed: All items complete
2025-10-01 10:45:40.400414 | 
2025-10-01 10:45:40.854697 | controller | changed: .d..t...... ./
2025-10-01 10:45:41.353769 | controller | changed: .d..t...... ./
2025-10-01 10:45:41.372752 | 
2025-10-01 10:45:41.372864 | TASK [include_role : fetch-output-openshift]
2025-10-01 10:45:41.396930 | controller | skipping: Conditional result was False
2025-10-01 10:45:41.404809 | 
2025-10-01 10:45:41.404900 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-01 10:45:41.841728 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.025937
2025-10-01 10:45:42.175645 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012814
2025-10-01 10:45:42.215988 | 
2025-10-01 10:45:42.216151 | PLAY [all]
2025-10-01 10:45:42.238540 | 
2025-10-01 10:45:42.238671 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-01 10:45:42.761862 | controller | changed
2025-10-01 10:45:42.817549 | 
2025-10-01 10:45:42.817655 | PLAY RECAP
2025-10-01 10:45:42.817698 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-01 10:45:42.817720 | 
2025-10-01 10:45:43.024749 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-01 10:45:43.025546 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-01 10:45:43.851926 | 
2025-10-01 10:45:43.852072 | PLAY [localhost]
2025-10-01 10:45:43.879814 | 
2025-10-01 10:45:43.879930 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-01 10:45:44.289489 | localhost | changed
2025-10-01 10:45:44.294475 | 
2025-10-01 10:45:44.294559 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-01 10:45:44.352652 | localhost | ok
2025-10-01 10:45:44.360794 | 
2025-10-01 10:45:44.360858 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-01 10:45:44.866411 | localhost | changed
2025-10-01 10:45:44.871931 | 
2025-10-01 10:45:44.872002 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-01 10:45:45.673594 | localhost | changed
2025-10-01 10:45:45.678764 | 
2025-10-01 10:45:45.681092 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-01 10:45:46.280484 | localhost | Identity added: /var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/tmp/ansible.6dejzjza (/var/lib/zuul/builds/897a110f8a234d39a4d745fbb9e80635/work/tmp/ansible.6dejzjza)
2025-10-01 10:45:46.280685 | localhost | ok: Runtime: 0:00:00.008826
2025-10-01 10:45:46.288081 | 
2025-10-01 10:45:46.288193 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-01 10:45:46.683076 | localhost | ok: Runtime: 0:00:00.008159
2025-10-01 10:45:46.698677 | 
2025-10-01 10:45:46.698787 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-01 10:45:46.832304 | localhost | changed
2025-10-01 10:45:46.837477 | 
2025-10-01 10:45:46.837548 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-01 10:45:47.327703 | localhost | changed
2025-10-01 10:45:47.373034 | 
2025-10-01 10:45:47.373131 | PLAY [localhost]
2025-10-01 10:45:47.400302 | 
2025-10-01 10:45:47.400420 | TASK [Generate bulk log download script]
2025-10-01 10:45:47.429980 | localhost | ok
2025-10-01 10:45:47.446254 | 
2025-10-01 10:45:47.446345 | TASK [local-log-download : Check API endpoint is defined]
2025-10-01 10:45:47.485168 | localhost | ok: All assertions passed
2025-10-01 10:45:47.490557 | 
2025-10-01 10:45:47.490622 | TASK [local-log-download : Create download script]
2025-10-01 10:45:48.120082 | localhost -> localhost | changed
2025-10-01 10:45:48.135688 | 
2025-10-01 10:45:48.135806 | TASK [Register quick-download link]
2025-10-01 10:45:48.214818 | localhost | ok
2025-10-01 10:45:48.231006 | 
2025-10-01 10:45:48.231102 | PLAY [logserver.rdoproject.org]
2025-10-01 10:45:48.240894 | 
2025-10-01 10:45:48.240958 | TASK [Set zuul-log-path fact]
2025-10-01 10:45:48.257712 | logserver.rdoproject.org | ok
2025-10-01 10:45:48.269118 | 
2025-10-01 10:45:48.269195 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-01 10:45:48.298254 | logserver.rdoproject.org | ok
2025-10-01 10:45:48.303773 | 
2025-10-01 10:45:48.303836 | TASK [upload-logs : Create log directories]
2025-10-01 10:45:49.004126 | logserver.rdoproject.org | changed
2025-10-01 10:45:49.007213 | 
2025-10-01 10:45:49.007273 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-01 10:45:49.482347 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.012469
2025-10-01 10:45:49.487715 | 
2025-10-01 10:45:49.487784 | TASK [upload-logs : Upload logs to log server]
2025-10-01 10:45:50.292274 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-01 10:45:50.296335 | 
2025-10-01 10:45:50.296456 | LOOP [upload-logs : Compress console log and json output]
2025-10-01 10:45:50.353732 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 10:45:50.354508 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 10:45:50.365499 | 
2025-10-01 10:45:50.365615 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-01 10:45:50.439700 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 10:45:50.439939 | 
2025-10-01 10:45:50.440496 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 10:45:50.454677 | 
2025-10-01 10:45:50.454790 | LOOP [upload-logs : Upload console log and json output]