2025-10-07 14:33:14.047467 | Job console starting...
2025-10-07 14:33:14.059164 | Updating repositories
2025-10-07 14:33:14.658911 | Preparing job workspace
2025-10-07 14:33:18.889804 | Running Ansible setup...
2025-10-07 14:33:23.720366 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-07 14:33:26.910425 | 
2025-10-07 14:33:26.910552 | PLAY [localhost]
2025-10-07 14:33:26.919204 | 
2025-10-07 14:33:26.919273 | TASK [Gathering Facts]
2025-10-07 14:33:27.852305 | localhost | ok
2025-10-07 14:33:27.869754 | 
2025-10-07 14:33:27.869890 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-07 14:33:28.360634 | localhost -> localhost | changed
2025-10-07 14:33:28.369944 | 
2025-10-07 14:33:28.370074 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-07 14:33:29.535215 | localhost -> localhost | changed
2025-10-07 14:33:29.544321 | 
2025-10-07 14:33:29.544397 | TASK [Setup log path fact]
2025-10-07 14:33:29.562675 | localhost | ok
2025-10-07 14:33:29.587411 | 
2025-10-07 14:33:29.587569 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-07 14:33:29.619863 | localhost | ok
2025-10-07 14:33:29.628057 | 
2025-10-07 14:33:29.628163 | TASK [emit-job-header : Print job information]
2025-10-07 14:33:29.657468 | # Job Information
2025-10-07 14:33:29.657616 | Ansible Version: 2.15.12
2025-10-07 14:33:29.657643 | Job: cifmw-molecule-cleanup_openstack
2025-10-07 14:33:29.657678 | Pipeline: github-check
2025-10-07 14:33:29.657702 | Executor: ze02.softwarefactory-project.io
2025-10-07 14:33:29.657721 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366
2025-10-07 14:33:29.657740 | Log URL (when completed): https://logserver.rdoproject.org/744/rdoproject.org/744c9a60a6804960992c267dc4d39188/
2025-10-07 14:33:29.657758 | Event ID: 640e52c0-a38a-11f0-87db-ca38cb57bc1b
2025-10-07 14:33:29.662363 | 
2025-10-07 14:33:29.662439 | LOOP [emit-job-header : Print node information]
2025-10-07 14:33:29.801568 | localhost | ok:
2025-10-07 14:33:29.801841 | localhost | # Node Information
2025-10-07 14:33:29.801884 | localhost | Inventory Hostname: controller
2025-10-07 14:33:29.801917 | localhost | Hostname: np0005474062
2025-10-07 14:33:29.801946 | localhost | Username: zuul
2025-10-07 14:33:29.801975 | localhost | Distro: CentOS 9
2025-10-07 14:33:29.802003 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-07 14:33:29.802029 | localhost | Region: RegionOne
2025-10-07 14:33:29.802054 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-07 14:33:29.802078 | localhost | Product Name: OpenStack Nova
2025-10-07 14:33:29.802102 | localhost | Interface IP: 38.129.56.29
2025-10-07 14:33:29.827333 | 
2025-10-07 14:33:29.827477 | PLAY [all]
2025-10-07 14:33:29.833753 | 
2025-10-07 14:33:29.833815 | TASK [Gather network facts]
2025-10-07 14:33:30.334290 | controller | ok
2025-10-07 14:33:30.350707 | 
2025-10-07 14:33:30.350797 | TASK [include_role : start-zuul-console]
2025-10-07 14:33:30.369587 | controller | ok
2025-10-07 14:33:30.381440 | 
2025-10-07 14:33:30.381510 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-07 14:33:30.795329 | controller | ok
2025-10-07 14:33:30.804889 | 
2025-10-07 14:33:30.804958 | TASK [include_role : add-build-sshkey]
2025-10-07 14:33:30.833804 | controller | ok
2025-10-07 14:33:30.853030 | 
2025-10-07 14:33:30.853208 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-07 14:33:31.114295 | controller -> localhost | ok
2025-10-07 14:33:31.121400 | 
2025-10-07 14:33:31.121474 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-07 14:33:31.155953 | controller | ok
2025-10-07 14:33:31.170343 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-07 14:33:31.176411 | 
2025-10-07 14:33:31.176483 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-07 14:33:32.313274 | controller -> localhost | Generating public/private rsa key pair.
2025-10-07 14:33:32.313564 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/744c9a60a6804960992c267dc4d39188_id_rsa.
2025-10-07 14:33:32.313598 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/744c9a60a6804960992c267dc4d39188_id_rsa.pub.
2025-10-07 14:33:32.313621 | controller -> localhost | The key fingerprint is:
2025-10-07 14:33:32.313642 | controller -> localhost | SHA256:REUjAMKYxojbWT7WT+dVGeIAevnXMhn+4gWp2+woxvI zuul-build-sshkey
2025-10-07 14:33:32.313689 | controller -> localhost | The key's randomart image is:
2025-10-07 14:33:32.313716 | controller -> localhost | +---[RSA 3072]----+
2025-10-07 14:33:32.313735 | controller -> localhost | |++. ....++= . .o |
2025-10-07 14:33:32.313754 | controller -> localhost | |=o...  o o + .o  |
2025-10-07 14:33:32.313772 | controller -> localhost | |.o + .. +   o.   |
2025-10-07 14:33:32.313790 | controller -> localhost | |. o + .o.....=   |
2025-10-07 14:33:32.313807 | controller -> localhost | |   . . oSo..O .  |
2025-10-07 14:33:32.313825 | controller -> localhost | |        . .o =   |
2025-10-07 14:33:32.313843 | controller -> localhost | |       .  . . o  |
2025-10-07 14:33:32.313861 | controller -> localhost | |      . +  * o   |
2025-10-07 14:33:32.313879 | controller -> localhost | |       +E.o.=    |
2025-10-07 14:33:32.313897 | controller -> localhost | +----[SHA256]-----+
2025-10-07 14:33:32.313940 | controller -> localhost | ok: Runtime: 0:00:00.724595
2025-10-07 14:33:32.320394 | 
2025-10-07 14:33:32.320476 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-07 14:33:32.361030 | controller | ok
2025-10-07 14:33:32.373429 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-07 14:33:32.382873 | 
2025-10-07 14:33:32.382968 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-07 14:33:32.419781 | controller | skipping: Conditional result was False
2025-10-07 14:33:32.435777 | 
2025-10-07 14:33:32.435872 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-07 14:33:32.946425 | controller | changed
2025-10-07 14:33:32.955251 | 
2025-10-07 14:33:32.955324 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-07 14:33:33.268749 | controller | ok
2025-10-07 14:33:33.279885 | 
2025-10-07 14:33:33.280043 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-07 14:33:34.334461 | controller | changed
2025-10-07 14:33:34.340056 | 
2025-10-07 14:33:34.340151 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-07 14:33:35.259392 | controller | changed
2025-10-07 14:33:35.264814 | 
2025-10-07 14:33:35.264910 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-07 14:33:35.316949 | controller | skipping: Conditional result was False
2025-10-07 14:33:35.323215 | 
2025-10-07 14:33:35.323290 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-07 14:33:35.782544 | controller -> localhost | changed
2025-10-07 14:33:35.793768 | 
2025-10-07 14:33:35.793864 | TASK [add-build-sshkey : Add back temp key]
2025-10-07 14:33:36.140965 | controller -> localhost | Identity added: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/744c9a60a6804960992c267dc4d39188_id_rsa (zuul-build-sshkey)
2025-10-07 14:33:36.141236 | controller -> localhost | ok: Runtime: 0:00:00.009602
2025-10-07 14:33:36.147168 | 
2025-10-07 14:33:36.147284 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-07 14:33:36.573610 | controller | ok
2025-10-07 14:33:36.578542 | 
2025-10-07 14:33:36.578602 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-07 14:33:36.613476 | controller | skipping: Conditional result was False
2025-10-07 14:33:36.628956 | 
2025-10-07 14:33:36.629103 | TASK [include_role : validate-host]
2025-10-07 14:33:36.661859 | controller | ok
2025-10-07 14:33:36.681364 | 
2025-10-07 14:33:36.681442 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-07 14:33:36.726822 | controller | ok
2025-10-07 14:33:36.746351 | 
2025-10-07 14:33:36.746487 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-07 14:33:37.239013 | controller -> localhost | ok
2025-10-07 14:33:37.245114 | 
2025-10-07 14:33:37.245182 | TASK [validate-host : Collect information about the host]
2025-10-07 14:33:38.066528 | controller | ok
2025-10-07 14:33:38.083890 | 
2025-10-07 14:33:38.084018 | TASK [validate-host : Sanitize hostname]
2025-10-07 14:33:38.155714 | controller | ok
2025-10-07 14:33:38.161412 | 
2025-10-07 14:33:38.161493 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-07 14:33:38.818684 | controller -> localhost | changed
2025-10-07 14:33:38.826401 | 
2025-10-07 14:33:38.826495 | TASK [validate-host : Collect information about zuul worker]
2025-10-07 14:33:39.272773 | controller | ok
2025-10-07 14:33:39.280581 | 
2025-10-07 14:33:39.280654 | TASK [validate-host : Write out all zuul information for each host]
2025-10-07 14:33:40.209344 | controller -> localhost | changed
2025-10-07 14:33:40.226970 | 
2025-10-07 14:33:40.227047 | TASK [include_role : prepare-workspace-openshift]
2025-10-07 14:33:40.269393 | controller | skipping: Conditional result was False
2025-10-07 14:33:40.275324 | 
2025-10-07 14:33:40.275548 | TASK [include_role : remove-zuul-sshkey]
2025-10-07 14:33:40.290280 | controller | skipping: Conditional result was False
2025-10-07 14:33:40.298407 | 
2025-10-07 14:33:40.298495 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-07 14:33:40.599603 | controller | ok: "logs"
2025-10-07 14:33:40.599935 | controller | ok: All items complete
2025-10-07 14:33:40.599966 | 
2025-10-07 14:33:40.886424 | controller | ok: "artifacts"
2025-10-07 14:33:41.136491 | controller | ok: "docs"
2025-10-07 14:33:41.144137 | 
2025-10-07 14:33:41.144211 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-07 14:33:41.459689 | controller | changed: "logs"
2025-10-07 14:33:41.776711 | controller | changed: "artifacts"
2025-10-07 14:33:42.002982 | controller | changed: "docs"
2025-10-07 14:33:42.051055 | 
2025-10-07 14:33:42.051192 | PLAY RECAP
2025-10-07 14:33:42.051242 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-07 14:33:42.051268 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-07 14:33:42.051287 | 
2025-10-07 14:33:42.462379 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-07 14:33:42.463358 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-07 14:33:43.891756 | 
2025-10-07 14:33:43.891884 | PLAY [localhost]
2025-10-07 14:33:43.916999 | 
2025-10-07 14:33:43.917148 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-07 14:33:44.398581 | localhost | ok
2025-10-07 14:33:44.404787 | 
2025-10-07 14:33:44.404875 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-07 14:33:45.573791 | localhost | changed
2025-10-07 14:33:45.597620 | 
2025-10-07 14:33:45.597745 | PLAY [all]
2025-10-07 14:33:45.640271 | 
2025-10-07 14:33:45.640425 | TASK [include_role : prepare-workspace]
2025-10-07 14:33:45.662099 | controller | ok
2025-10-07 14:33:45.680472 | 
2025-10-07 14:33:45.680593 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-07 14:33:46.273962 | controller | ok
2025-10-07 14:33:46.282066 | 
2025-10-07 14:33:46.282154 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-07 14:33:48.666946 | controller | Output suppressed because no_log was given
2025-10-07 14:33:48.677911 | 
2025-10-07 14:33:48.677992 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-07 14:33:48.995725 | controller | changed: "logs"
2025-10-07 14:33:49.227128 | controller | changed: "artifacts"
2025-10-07 14:33:49.489164 | controller | changed: "docs"
2025-10-07 14:33:49.578920 | 
2025-10-07 14:33:49.579077 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-07 14:33:49.912137 | controller | changed: "logs"
2025-10-07 14:33:49.913590 | controller | changed: All items complete
2025-10-07 14:33:49.913628 | 
2025-10-07 14:33:50.173624 | controller | changed: "artifacts"
2025-10-07 14:33:50.367546 | controller | changed: "docs"
2025-10-07 14:33:50.412306 | 
2025-10-07 14:33:50.412458 | TASK [Check if worker can sudo]
2025-10-07 14:33:51.524228 | controller | ok: Runtime: 0:00:00.042771
2025-10-07 14:33:51.532733 | 
2025-10-07 14:33:51.532867 | TASK [configure-mirrors : Gather needed facts]
2025-10-07 14:33:51.663356 | controller | skipping: Conditional result was False
2025-10-07 14:33:51.671730 | 
2025-10-07 14:33:51.671867 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-07 14:33:51.785435 | controller | ok
2025-10-07 14:33:51.832645 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-07 14:33:51.839079 | 
2025-10-07 14:33:51.839160 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-07 14:33:52.119028 | controller | ok
2025-10-07 14:33:52.131848 | 
2025-10-07 14:33:52.132014 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-07 14:33:52.230951 | controller | ok: "/var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-07 14:33:52.248865 | 
2025-10-07 14:33:52.249049 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-07 14:33:53.211086 | controller | changed
2025-10-07 14:33:53.220630 | 
2025-10-07 14:33:53.220758 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-07 14:33:53.288212 | controller | ok: "/var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-07 14:33:53.288588 | controller | ok: All items complete
2025-10-07 14:33:53.288623 | 
2025-10-07 14:33:53.370919 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-07 14:33:53.378123 | 
2025-10-07 14:33:53.378264 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-07 14:33:54.287772 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-07 14:33:55.217487 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-07 14:33:55.226013 | 
2025-10-07 14:33:55.226144 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-07 14:33:55.908903 | controller | changed: section and option added
2025-10-07 14:33:55.965060 | 
2025-10-07 14:33:55.965200 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-07 14:33:56.800283 | controller | 29 files removed
2025-10-07 14:33:56.800546 | controller | ok: Item: dnf clean all Runtime: 0:00:00.488995
2025-10-07 14:33:56.800589 | controller | changed: All items complete
2025-10-07 14:33:56.800612 | 
2025-10-07 14:34:09.634392 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-10-07 14:34:09.634650 | controller | DNF version: 4.14.0
2025-10-07 14:34:09.634705 | controller | cachedir: /var/cache/dnf
2025-10-07 14:34:09.634728 | controller | Making cache files for all metadata files.
2025-10-07 14:34:09.634746 | controller | baseos: has expired and will be refreshed.
2025-10-07 14:34:09.634763 | controller | appstream: has expired and will be refreshed.
2025-10-07 14:34:09.634780 | controller | crb: has expired and will be refreshed.
2025-10-07 14:34:09.634810 | controller | extras-common: has expired and will be refreshed.
2025-10-07 14:34:09.634827 | controller | repo: downloading from remote: baseos
2025-10-07 14:34:09.634843 | controller | CentOS Stream 9 - BaseOS                         59 MB/s | 8.8 MB     00:00
2025-10-07 14:34:09.634859 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-07 14:34:09.634875 | controller | repo: downloading from remote: appstream
2025-10-07 14:34:09.634891 | controller | CentOS Stream 9 - AppStream                      48 MB/s |  25 MB     00:00
2025-10-07 14:34:09.634907 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-07 14:34:09.634923 | controller | repo: downloading from remote: crb
2025-10-07 14:34:09.634938 | controller | CentOS Stream 9 - CRB                           6.3 MB/s | 7.1 MB     00:01
2025-10-07 14:34:09.634955 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-07 14:34:09.634971 | controller | repo: downloading from remote: extras-common
2025-10-07 14:34:09.634987 | controller | CentOS Stream 9 - Extras packages               103 kB/s |  20 kB     00:00
2025-10-07 14:34:09.635004 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-07 14:34:09.635019 | controller | Last metadata expiration check: 0:00:01 ago on Tue 07 Oct 2025 10:34:07 AM EDT.
2025-10-07 14:34:09.635035 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-07 14:34:09.635050 | controller | Completion plugin: Generating completion cache...
2025-10-07 14:34:09.635067 | controller | Metadata cache created.
2025-10-07 14:34:09.635094 | controller | ok: Item: dnf makecache -v Runtime: 0:00:12.459178
2025-10-07 14:34:09.660775 | 
2025-10-07 14:34:09.660896 | PLAY RECAP
2025-10-07 14:34:09.660937 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-07 14:34:09.660962 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-07 14:34:09.660979 | 
2025-10-07 14:34:09.843749 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-07 14:34:09.849892 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-07 14:34:10.560240 | 
2025-10-07 14:34:10.560364 | PLAY [all]
2025-10-07 14:34:10.582822 | 
2025-10-07 14:34:10.582920 | TASK [Install binary dependencies]
2025-10-07 14:34:10.654983 | controller | ok
2025-10-07 14:34:10.687034 | 
2025-10-07 14:34:10.687196 | TASK [bindep : Include find tasks]
2025-10-07 14:34:10.755219 | controller | ok
2025-10-07 14:34:10.772577 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-07 14:34:10.779510 | 
2025-10-07 14:34:10.779578 | TASK [bindep : Look for bindep.txt]
2025-10-07 14:34:11.585856 | controller | ok
2025-10-07 14:34:11.620327 | 
2025-10-07 14:34:11.620464 | TASK [bindep : Define bindep_file fact]
2025-10-07 14:34:11.723815 | controller | ok
2025-10-07 14:34:11.729484 | 
2025-10-07 14:34:11.729549 | TASK [bindep : Look for other-requirements.txt]
2025-10-07 14:34:11.782421 | controller | skipping: Conditional result was False
2025-10-07 14:34:11.800897 | 
2025-10-07 14:34:11.801006 | TASK [bindep : Define bindep_file fact]
2025-10-07 14:34:11.928197 | controller | skipping: Conditional result was False
2025-10-07 14:34:11.936778 | 
2025-10-07 14:34:11.936883 | TASK [bindep : Look for bindep fallback file]
2025-10-07 14:34:11.991458 | controller | skipping: Conditional result was False
2025-10-07 14:34:11.998193 | 
2025-10-07 14:34:11.998265 | TASK [bindep : Define bindep_file fact]
2025-10-07 14:34:12.023110 | controller | skipping: Conditional result was False
2025-10-07 14:34:12.038997 | 
2025-10-07 14:34:12.039115 | TASK [bindep : Include bindep tasks]
2025-10-07 14:34:12.078439 | controller | ok
2025-10-07 14:34:12.091462 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-07 14:34:12.110244 | 
2025-10-07 14:34:12.110363 | TASK [bindep : Look for bindep command]
2025-10-07 14:34:12.173402 | controller | skipping: Conditional result was False
2025-10-07 14:34:12.181800 | 
2025-10-07 14:34:12.181934 | TASK [bindep : Check for system bindep]
2025-10-07 14:34:12.725224 | controller | ok: Runtime: 0:00:00.006065
2025-10-07 14:34:12.731336 | 
2025-10-07 14:34:12.731409 | TASK [bindep : Define bindep_command fact]
2025-10-07 14:34:12.766438 | controller | skipping: Conditional result was False
2025-10-07 14:34:12.772832 | 
2025-10-07 14:34:12.772905 | TASK [bindep : Include install tasks]
2025-10-07 14:34:12.814865 | controller | ok
2025-10-07 14:34:12.826051 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-07 14:34:12.845925 | 
2025-10-07 14:34:12.846021 | TASK [bindep : Create temp dir for bindep]
2025-10-07 14:34:13.294261 | controller | changed
2025-10-07 14:34:13.308144 | 
2025-10-07 14:34:13.308230 | TASK [Ensure we have pip dependencies]
2025-10-07 14:34:13.350084 | controller | ok
2025-10-07 14:34:13.390854 | 
2025-10-07 14:34:13.390993 | TASK [ensure-pip : Check if pip is installed]
2025-10-07 10:34:13.690611 | controller | /usr/bin/pip3
2025-10-07 10:34:13.730227 | controller | /usr/bin/python3: No module named wheel
2025-10-07 14:34:13.957764 | controller | ok: Runtime: 0:00:00.055151
2025-10-07 14:34:13.963638 | 
2025-10-07 14:34:13.963749 | LOOP [ensure-pip : Install pip from packages]
2025-10-07 14:34:14.017375 | controller | ok: "/var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-07 14:34:14.026556 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-07 14:34:14.042529 | 
2025-10-07 14:34:14.042601 | TASK [ensure-pip : Install Python 3 pip]
2025-10-07 14:34:16.680213 | controller | changed
2025-10-07 14:34:16.694317 | 
2025-10-07 14:34:16.694498 | TASK [ensure-pip : Check for EPEL repository]
2025-10-07 14:34:16.742698 | controller | skipping: Conditional result was False
2025-10-07 14:34:16.757341 | 
2025-10-07 14:34:16.757516 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-07 14:34:16.795190 | controller | skipping: Conditional result was False
2025-10-07 14:34:16.812541 | 
2025-10-07 14:34:16.812770 | TASK [ensure-pip : Install Python 2 pip]
2025-10-07 14:34:16.871892 | controller | skipping: Conditional result was False
2025-10-07 14:34:16.884571 | 
2025-10-07 14:34:16.884749 | TASK [ensure-pip : Ensure setuptools]
2025-10-07 14:34:16.911028 | controller | skipping: Conditional result was False
2025-10-07 14:34:16.920159 | 
2025-10-07 14:34:16.920264 | TASK [ensure-pip : Check for ensurepip module]
2025-10-07 14:34:17.487994 | controller | skipping: Conditional result was False
2025-10-07 14:34:17.501627 | 
2025-10-07 14:34:17.501798 | TASK [ensure-pip : Ensure python3-venv]
2025-10-07 14:34:17.518703 | controller | skipping: Conditional result was False
2025-10-07 14:34:17.531813 | 
2025-10-07 14:34:17.531955 | TASK [ensure-pip : Install pip from source]
2025-10-07 14:34:17.548947 | controller | skipping: Conditional result was False
2025-10-07 14:34:17.561635 | 
2025-10-07 14:34:17.561800 | TASK [ensure-pip : Probe for venv python full path]
2025-10-07 10:34:17.888947 | controller | /usr/bin/python3
2025-10-07 14:34:18.113149 | controller | ok: Runtime: 0:00:00.004500
2025-10-07 14:34:18.119458 | 
2025-10-07 14:34:18.119528 | TASK [ensure-pip : Set host default]
2025-10-07 14:34:18.190843 | controller | ok
2025-10-07 14:34:18.195967 | 
2025-10-07 14:34:18.196028 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-07 14:34:18.263011 | controller | ok
2025-10-07 14:34:18.272526 | 
2025-10-07 14:34:18.272588 | TASK [bindep : Install bindep into temporary venv]
2025-10-07 14:34:22.639311 | controller | changed
2025-10-07 14:34:22.656044 | 
2025-10-07 14:34:22.656256 | TASK [bindep : Define bindep_command]
2025-10-07 14:34:22.706155 | controller | ok
2025-10-07 14:34:22.721631 | 
2025-10-07 14:34:22.721826 | LOOP [bindep : Include package tasks]
2025-10-07 14:34:22.801261 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-07 14:34:22.801424 | controller | ok: All items complete
2025-10-07 14:34:22.801449 | 
2025-10-07 14:34:22.818401 | controller | included: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-07 14:34:22.834807 | 
2025-10-07 14:34:22.834937 | TASK [bindep : Define bindep_run fact]
2025-10-07 14:34:22.883032 | controller | ok
2025-10-07 14:34:22.888260 | 
2025-10-07 14:34:22.888325 | TASK [bindep : Get list of packages to install from bindep]
2025-10-07 10:34:24.257477 | controller | podman
2025-10-07 10:34:24.294794 | controller | python3-jmespath
2025-10-07 10:34:24.294996 | controller | python3-libvirt
2025-10-07 10:34:24.295011 | controller | python3-lxml
2025-10-07 10:34:24.295024 | controller | python3-netaddr
2025-10-07 14:34:24.454916 | controller | ok: Runtime: 0:00:01.110056
2025-10-07 14:34:24.463615 | 
2025-10-07 14:34:24.463732 | TASK [bindep : Install distro packages from bindep]
2025-10-07 14:35:33.788816 | controller | changed
2025-10-07 14:35:33.797104 | 
2025-10-07 14:35:33.797190 | TASK [bindep : Check that packages are installed]
2025-10-07 14:35:35.343926 | controller | ok: Runtime: 0:00:01.126545
2025-10-07 14:35:35.355459 | 
2025-10-07 14:35:35.355590 | TASK [bindep : Fail if we cannot install all packages]
2025-10-07 14:35:35.393177 | controller | skipping: Conditional result was False
2025-10-07 14:35:35.416403 | 
2025-10-07 14:35:35.416535 | TASK [Run test-setup role]
2025-10-07 14:35:35.445458 | controller | ok
2025-10-07 14:35:35.474178 | 
2025-10-07 14:35:35.474267 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-07 14:35:35.734265 | controller | ok
2025-10-07 14:35:35.745360 | 
2025-10-07 14:35:35.745495 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-07 14:35:36.291317 | controller | skipping: Conditional result was False
2025-10-07 14:35:36.334149 | 
2025-10-07 14:35:36.334304 | TASK [bindep : Remove bindep temp dir]
2025-10-07 14:35:36.778867 | controller | ok
2025-10-07 14:35:36.810928 | 
2025-10-07 14:35:36.811048 | PLAY RECAP
2025-10-07 14:35:36.811136 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-07 14:35:36.811184 | 
2025-10-07 14:35:36.927741 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-07 14:35:36.930369 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-07 14:35:37.522270 | 
2025-10-07 14:35:37.522399 | PLAY [all]
2025-10-07 14:35:37.541705 | 
2025-10-07 14:35:37.541780 | TASK [Abort when test_command variable is undefined]
2025-10-07 14:35:37.566821 | controller | skipping: Conditional result was False
2025-10-07 14:35:37.572232 | 
2025-10-07 14:35:37.572303 | TASK [Convert test_command to list]
2025-10-07 14:35:37.606364 | controller | skipping: Conditional result was False
2025-10-07 14:35:37.612912 | 
2025-10-07 14:35:37.612976 | TASK [Use test_command list]
2025-10-07 14:35:37.678164 | controller | ok
2025-10-07 14:35:37.689850 | 
2025-10-07 14:35:37.689981 | LOOP [Run test_command]
2025-10-07 14:35:38.203984 | controller | no check to run
2025-10-07 14:35:38.204344 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.028198
2025-10-07 14:35:38.253050 | 
2025-10-07 14:35:38.253232 | PLAY RECAP
2025-10-07 14:35:38.253326 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-07 14:35:38.253389 | 
2025-10-07 14:35:38.371718 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-07 14:35:38.373138 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-07 14:35:39.015797 | 
2025-10-07 14:35:39.015941 | PLAY [all]
2025-10-07 14:35:39.037783 | 
2025-10-07 14:35:39.037923 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-07 14:35:39.413896 | controller | changed: non-zero return code
2025-10-07 14:35:39.419251 | 
2025-10-07 14:35:39.419325 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-07 14:35:39.434415 | controller | skipping: Conditional result was False
2025-10-07 14:35:39.440420 | 
2025-10-07 14:35:39.440494 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-07 14:35:39.462795 | 
2025-10-07 14:35:39.462953 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-07 14:35:39.503324 | 
2025-10-07 14:35:39.503679 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-07 14:35:39.531013 | controller | skipping: Conditional result was False
2025-10-07 14:35:39.538389 | 
2025-10-07 14:35:39.538529 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-07 14:35:39.571767 | 
2025-10-07 14:35:39.571988 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-07 14:35:39.598577 | controller | skipping: Conditional result was False
2025-10-07 14:35:39.605082 | 
2025-10-07 14:35:39.605159 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-07 14:35:39.619766 | controller | skipping: Conditional result was False
2025-10-07 14:35:39.625528 | 
2025-10-07 14:35:39.625596 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-07 14:35:39.639197 | controller | skipping: Conditional result was False
2025-10-07 14:35:39.664730 | 
2025-10-07 14:35:39.664812 | PLAY RECAP
2025-10-07 14:35:39.664852 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-07 14:35:39.664873 | 
2025-10-07 14:35:39.764215 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-07 14:35:39.765741 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-07 14:35:40.370452 | 
2025-10-07 14:35:40.370579 | PLAY [all]
2025-10-07 14:35:40.391959 | 
2025-10-07 14:35:40.392097 | TASK [include_role : fetch-output]
2025-10-07 14:35:40.442243 | controller | ok
2025-10-07 14:35:40.462406 | 
2025-10-07 14:35:40.462528 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-07 14:35:40.527786 | controller | skipping: Conditional result was False
2025-10-07 14:35:40.536889 | 
2025-10-07 14:35:40.536995 | TASK [fetch-output : Set log path for single node]
2025-10-07 14:35:40.600653 | controller | ok
2025-10-07 14:35:40.609026 | 
2025-10-07 14:35:40.609135 | LOOP [fetch-output : Ensure local output dirs]
2025-10-07 14:35:41.011646 | controller -> localhost | ok: "/var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/logs"
2025-10-07 14:35:41.257319 | controller -> localhost | changed: "/var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/artifacts"
2025-10-07 14:35:41.528499 | controller -> localhost | changed: "/var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/docs"
2025-10-07 14:35:41.542974 | 
2025-10-07 14:35:41.543274 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-07 14:35:42.210970 | controller | changed: .d..t...... ./
2025-10-07 14:35:42.211167 | controller | changed: All items complete
2025-10-07 14:35:42.211195 | 
2025-10-07 14:35:42.652785 | controller | changed: .d..t...... ./
2025-10-07 14:35:43.114119 | controller | changed: .d..t...... ./
2025-10-07 14:35:43.145773 | 
2025-10-07 14:35:43.145910 | TASK [include_role : fetch-output-openshift]
2025-10-07 14:35:43.164702 | controller | skipping: Conditional result was False
2025-10-07 14:35:43.179192 | 
2025-10-07 14:35:43.179401 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-07 14:35:43.612208 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010117
2025-10-07 14:35:43.879296 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.010677
2025-10-07 14:35:43.926543 | 
2025-10-07 14:35:43.926713 | PLAY [all]
2025-10-07 14:35:43.941842 | 
2025-10-07 14:35:43.941912 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-07 14:35:44.366569 | controller | changed
2025-10-07 14:35:44.408269 | 
2025-10-07 14:35:44.408346 | PLAY RECAP
2025-10-07 14:35:44.408401 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-07 14:35:44.408429 | 
2025-10-07 14:35:44.523522 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-07 14:35:44.524407 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-07 14:35:45.132937 | 
2025-10-07 14:35:45.133045 | PLAY [localhost]
2025-10-07 14:35:45.150969 | 
2025-10-07 14:35:45.151097 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-07 14:35:45.580326 | localhost | changed
2025-10-07 14:35:45.590261 | 
2025-10-07 14:35:45.590422 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-07 14:35:45.626103 | localhost | ok
2025-10-07 14:35:45.643513 | 
2025-10-07 14:35:45.643653 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-07 14:35:46.051955 | localhost | changed
2025-10-07 14:35:46.058165 | 
2025-10-07 14:35:46.058234 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-07 14:35:46.699011 | localhost | changed
2025-10-07 14:35:46.704212 | 
2025-10-07 14:35:46.704275 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-07 14:35:47.109850 | localhost | Identity added: /var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/tmp/ansible.jccjjadr (/var/lib/zuul/builds/744c9a60a6804960992c267dc4d39188/work/tmp/ansible.jccjjadr)
2025-10-07 14:35:47.110051 | localhost | ok: Runtime: 0:00:00.017819
2025-10-07 14:35:47.114861 | 
2025-10-07 14:35:47.114926 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-07 14:35:47.402711 | localhost | ok: Runtime: 0:00:00.006072
2025-10-07 14:35:47.409393 | 
2025-10-07 14:35:47.409460 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-07 14:35:47.469364 | localhost | changed
2025-10-07 14:35:47.474053 | 
2025-10-07 14:35:47.474120 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-07 14:35:47.837494 | localhost | changed
2025-10-07 14:35:47.859245 | 
2025-10-07 14:35:47.859322 | PLAY [localhost]
2025-10-07 14:35:47.871431 | 
2025-10-07 14:35:47.871490 | TASK [Generate bulk log download script]
2025-10-07 14:35:47.891493 | localhost | ok
2025-10-07 14:35:47.905527 | 
2025-10-07 14:35:47.905612 | TASK [local-log-download : Check API endpoint is defined]
2025-10-07 14:35:47.945123 | localhost | ok: All assertions passed
2025-10-07 14:35:47.950007 | 
2025-10-07 14:35:47.950090 | TASK [local-log-download : Create download script]
2025-10-07 14:35:48.370463 | localhost -> localhost | changed
2025-10-07 14:35:48.379766 | 
2025-10-07 14:35:48.379830 | TASK [Register quick-download link]
2025-10-07 14:35:48.408348 | localhost | ok
2025-10-07 14:35:48.469570 | 
2025-10-07 14:35:48.469694 | PLAY [logserver.rdoproject.org]
2025-10-07 14:35:48.479780 | 
2025-10-07 14:35:48.479839 | TASK [Set zuul-log-path fact]
2025-10-07 14:35:48.507899 | logserver.rdoproject.org | ok
2025-10-07 14:35:48.517974 | 
2025-10-07 14:35:48.518046 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-07 14:35:48.545243 | logserver.rdoproject.org | ok
2025-10-07 14:35:48.551209 | 
2025-10-07 14:35:48.551271 | TASK [upload-logs : Create log directories]
2025-10-07 14:35:49.207897 | logserver.rdoproject.org | changed
2025-10-07 14:35:49.211224 | 
2025-10-07 14:35:49.211287 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-07 14:35:49.479026 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009546
2025-10-07 14:35:49.484408 | 
2025-10-07 14:35:49.484474 | TASK [upload-logs : Upload logs to log server]
2025-10-07 14:35:50.129931 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-07 14:35:50.133390 | 
2025-10-07 14:35:50.133454 | LOOP [upload-logs : Compress console log and json output]
2025-10-07 14:35:50.216206 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:35:50.226466 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:35:50.237625 | 
2025-10-07 14:35:50.237768 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-07 14:35:50.281405 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:35:50.281659 | 
2025-10-07 14:35:50.286240 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-07 14:35:50.296216 | 
2025-10-07 14:35:50.296316 | LOOP [upload-logs : Upload console log and json output]