2025-11-26 07:30:09.851581 | Job console starting...
2025-11-26 07:30:09.867759 | Updating repositories
2025-11-26 07:30:09.907536 | Preparing job workspace
2025-11-26 07:30:13.897125 | Running Ansible setup...
2025-11-26 07:30:17.953708 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-26 07:30:18.544958 | 
2025-11-26 07:30:18.545068 | PLAY [localhost]
2025-11-26 07:30:18.553783 | 
2025-11-26 07:30:18.553881 | TASK [Gathering Facts]
2025-11-26 07:30:19.458476 | localhost | ok
2025-11-26 07:30:19.473041 | 
2025-11-26 07:30:19.473182 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-26 07:30:19.899433 | localhost -> localhost | changed
2025-11-26 07:30:19.905792 | 
2025-11-26 07:30:19.905875 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-26 07:30:20.773743 | localhost -> localhost | changed
2025-11-26 07:30:20.782030 | 
2025-11-26 07:30:20.782100 | TASK [Setup log path fact]
2025-11-26 07:30:20.800395 | localhost | ok
2025-11-26 07:30:20.823028 | 
2025-11-26 07:30:20.823142 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-26 07:30:20.850767 | localhost | ok
2025-11-26 07:30:20.858274 | 
2025-11-26 07:30:20.858336 | TASK [emit-job-header : Print job information]
2025-11-26 07:30:20.885319 | # Job Information
2025-11-26 07:30:20.885459 | Ansible Version: 2.15.12
2025-11-26 07:30:20.885484 | Job: cifmw-molecule-polarion
2025-11-26 07:30:20.885503 | Pipeline: github-check
2025-11-26 07:30:20.885521 | Executor: ze03.softwarefactory-project.io
2025-11-26 07:30:20.885538 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3505
2025-11-26 07:30:20.885556 | Log URL (when completed): https://logserver.rdoproject.org/5f0/rdoproject.org/5f0bba9539834248952e04e43f1bf2ea/
2025-11-26 07:30:20.885574 | Event ID: 8adaaf80-ca99-11f0-898f-2010a17eda0e
2025-11-26 07:30:20.889241 | 
2025-11-26 07:30:20.889301 | LOOP [emit-job-header : Print node information]
2025-11-26 07:30:20.981539 | localhost | ok:
2025-11-26 07:30:20.981767 | localhost | # Node Information
2025-11-26 07:30:20.981810 | localhost | Inventory Hostname: controller
2025-11-26 07:30:20.981843 | localhost | Hostname: np0005536208
2025-11-26 07:30:20.981871 | localhost | Username: zuul
2025-11-26 07:30:20.981901 | localhost | Distro: CentOS 9
2025-11-26 07:30:20.981927 | localhost | Provider: vexxhost-nodepool-tripleo
2025-11-26 07:30:20.981951 | localhost | Region: RegionOne
2025-11-26 07:30:20.981976 | localhost | Label: cloud-centos-9-stream-tripleo
2025-11-26 07:30:20.982000 | localhost | Product Name: OpenStack Nova
2025-11-26 07:30:20.982024 | localhost | Interface IP: 38.129.56.213
2025-11-26 07:30:21.015968 | 
2025-11-26 07:30:21.016099 | PLAY [all]
2025-11-26 07:30:21.025479 | 
2025-11-26 07:30:21.025561 | TASK [Gather network facts]
2025-11-26 07:30:21.497323 | controller | ok
2025-11-26 07:30:21.518583 | 
2025-11-26 07:30:21.518683 | TASK [include_role : start-zuul-console]
2025-11-26 07:30:21.539770 | controller | ok
2025-11-26 07:30:21.557994 | 
2025-11-26 07:30:21.558142 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-26 07:30:21.969230 | controller | ok
2025-11-26 07:30:21.986805 | 
2025-11-26 07:30:21.986914 | TASK [include_role : add-build-sshkey]
2025-11-26 07:30:22.008997 | controller | ok
2025-11-26 07:30:22.027697 | 
2025-11-26 07:30:22.027856 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-26 07:30:22.277435 | controller -> localhost | ok
2025-11-26 07:30:22.284645 | 
2025-11-26 07:30:22.284766 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-26 07:30:22.337900 | controller | ok
2025-11-26 07:30:22.366096 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-26 07:30:22.372269 | 
2025-11-26 07:30:22.372336 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-26 07:30:23.330912 | controller -> localhost | Generating public/private rsa key pair.
2025-11-26 07:30:23.331125 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/5f0bba9539834248952e04e43f1bf2ea_id_rsa.
2025-11-26 07:30:23.331155 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/5f0bba9539834248952e04e43f1bf2ea_id_rsa.pub.
2025-11-26 07:30:23.331175 | controller -> localhost | The key fingerprint is:
2025-11-26 07:30:23.331193 | controller -> localhost | SHA256:jRn1lJV0kZFCdFAHar/2aNIXLqd64rS7IROFaQWNRCg zuul-build-sshkey
2025-11-26 07:30:23.331211 | controller -> localhost | The key's randomart image is:
2025-11-26 07:30:23.331229 | controller -> localhost | +---[RSA 3072]----+
2025-11-26 07:30:23.331245 | controller -> localhost | |        ++=.+B*BB|
2025-11-26 07:30:23.331265 | controller -> localhost | |     E . o++.oo+.|
2025-11-26 07:30:23.331284 | controller -> localhost | |      . .+ .+ .  |
2025-11-26 07:30:23.331301 | controller -> localhost | |        .=.. .   |
2025-11-26 07:30:23.331318 | controller -> localhost | |        S..   .  |
2025-11-26 07:30:23.331335 | controller -> localhost | |          .    o |
2025-11-26 07:30:23.331352 | controller -> localhost | |         o o .+ .|
2025-11-26 07:30:23.331369 | controller -> localhost | |          +.++o=.|
2025-11-26 07:30:23.331386 | controller -> localhost | |          .**+=..|
2025-11-26 07:30:23.331402 | controller -> localhost | +----[SHA256]-----+
2025-11-26 07:30:23.331444 | controller -> localhost | ok: Runtime: 0:00:00.554233
2025-11-26 07:30:23.337442 | 
2025-11-26 07:30:23.337518 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-26 07:30:23.365934 | controller | ok
2025-11-26 07:30:23.375798 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-26 07:30:23.384104 | 
2025-11-26 07:30:23.384177 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-26 07:30:23.408478 | controller | skipping: Conditional result was False
2025-11-26 07:30:23.414808 | 
2025-11-26 07:30:23.414947 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-26 07:30:23.903713 | controller | changed
2025-11-26 07:30:23.923461 | 
2025-11-26 07:30:23.923775 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-26 07:30:24.225899 | controller | ok
2025-11-26 07:30:24.232616 | 
2025-11-26 07:30:24.232688 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-26 07:30:25.113038 | controller | changed
2025-11-26 07:30:25.118538 | 
2025-11-26 07:30:25.118600 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-26 07:30:26.056901 | controller | changed
2025-11-26 07:30:26.061838 | 
2025-11-26 07:30:26.061898 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-26 07:30:26.104180 | controller | skipping: Conditional result was False
2025-11-26 07:30:26.123174 | 
2025-11-26 07:30:26.123323 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-26 07:30:26.533135 | controller -> localhost | changed
2025-11-26 07:30:26.544206 | 
2025-11-26 07:30:26.544307 | TASK [add-build-sshkey : Add back temp key]
2025-11-26 07:30:26.950209 | controller -> localhost | Identity added: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/5f0bba9539834248952e04e43f1bf2ea_id_rsa (zuul-build-sshkey)
2025-11-26 07:30:26.950408 | controller -> localhost | ok: Runtime: 0:00:00.010807
2025-11-26 07:30:26.957498 | 
2025-11-26 07:30:26.957574 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-26 07:30:27.372820 | controller | ok
2025-11-26 07:30:27.385965 | 
2025-11-26 07:30:27.386064 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-26 07:30:27.431005 | controller | skipping: Conditional result was False
2025-11-26 07:30:27.446237 | 
2025-11-26 07:30:27.446375 | TASK [include_role : validate-host]
2025-11-26 07:30:27.480182 | controller | ok
2025-11-26 07:30:27.504832 | 
2025-11-26 07:30:27.504963 | TASK [validate-host : Define zuul_info_dir fact]
2025-11-26 07:30:27.535075 | controller | ok
2025-11-26 07:30:27.542449 | 
2025-11-26 07:30:27.542531 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-11-26 07:30:27.841572 | controller -> localhost | ok
2025-11-26 07:30:27.848320 | 
2025-11-26 07:30:27.848396 | TASK [validate-host : Collect information about the host]
2025-11-26 07:30:28.676384 | controller | ok
2025-11-26 07:30:28.688485 | 
2025-11-26 07:30:28.688609 | TASK [validate-host : Sanitize hostname]
2025-11-26 07:30:28.753370 | controller | ok
2025-11-26 07:30:28.769184 | 
2025-11-26 07:30:28.769304 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-11-26 07:30:29.421887 | controller -> localhost | changed
2025-11-26 07:30:29.428047 | 
2025-11-26 07:30:29.428119 | TASK [validate-host : Collect information about zuul worker]
2025-11-26 07:30:29.830878 | controller | ok
2025-11-26 07:30:29.843773 | 
2025-11-26 07:30:29.843892 | TASK [validate-host : Write out all zuul information for each host]
2025-11-26 07:30:30.457072 | controller -> localhost | changed
2025-11-26 07:30:30.479650 | 
2025-11-26 07:30:30.479861 | TASK [include_role : prepare-workspace-openshift]
2025-11-26 07:30:30.499195 | controller | skipping: Conditional result was False
2025-11-26 07:30:30.514919 | 
2025-11-26 07:30:30.515139 | TASK [include_role : remove-zuul-sshkey]
2025-11-26 07:30:30.546518 | controller | skipping: Conditional result was False
2025-11-26 07:30:30.552352 | 
2025-11-26 07:30:30.552428 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-26 07:30:30.786585 | controller | ok: "logs"
2025-11-26 07:30:30.786880 | controller | ok: All items complete
2025-11-26 07:30:30.786921 | 
2025-11-26 07:30:30.986618 | controller | ok: "artifacts"
2025-11-26 07:30:31.210970 | controller | ok: "docs"
2025-11-26 07:30:31.218589 | 
2025-11-26 07:30:31.218720 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-26 07:30:31.465994 | controller | changed: "logs"
2025-11-26 07:30:31.717434 | controller | changed: "artifacts"
2025-11-26 07:30:31.927980 | controller | changed: "docs"
2025-11-26 07:30:31.980621 | 
2025-11-26 07:30:31.980721 | PLAY RECAP
2025-11-26 07:30:31.980781 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-26 07:30:31.980807 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-26 07:30:31.980826 | 
2025-11-26 07:30:32.157762 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-26 07:30:32.158577 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-11-26 07:30:32.777348 | 
2025-11-26 07:30:32.777475 | PLAY [localhost]
2025-11-26 07:30:32.800502 | 
2025-11-26 07:30:32.800607 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-11-26 07:30:33.308568 | localhost | ok
2025-11-26 07:30:33.314767 | 
2025-11-26 07:30:33.314845 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-11-26 07:30:33.985230 | localhost | changed
2025-11-26 07:30:34.005806 | 
2025-11-26 07:30:34.005902 | PLAY [all]
2025-11-26 07:30:34.022156 | 
2025-11-26 07:30:34.022269 | TASK [include_role : prepare-workspace]
2025-11-26 07:30:34.054354 | controller | ok
2025-11-26 07:30:34.069216 | 
2025-11-26 07:30:34.069307 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-26 07:30:34.508108 | controller | ok
2025-11-26 07:30:34.515106 | 
2025-11-26 07:30:34.515180 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-26 07:30:36.407076 | controller | Output suppressed because no_log was given
2025-11-26 07:30:36.420402 | 
2025-11-26 07:30:36.420466 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-26 07:30:36.733027 | controller | changed: "logs"
2025-11-26 07:30:36.987463 | controller | changed: "artifacts"
2025-11-26 07:30:37.244878 | controller | changed: "docs"
2025-11-26 07:30:37.253662 | 
2025-11-26 07:30:37.253801 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-26 07:30:37.507842 | controller | changed: "logs"
2025-11-26 07:30:37.508292 | controller | changed: All items complete
2025-11-26 07:30:37.508352 | 
2025-11-26 07:30:37.728251 | controller | changed: "artifacts"
2025-11-26 07:30:37.936695 | controller | changed: "docs"
2025-11-26 07:30:37.977281 | 
2025-11-26 07:30:37.977472 | TASK [Check if worker can sudo]
2025-11-26 07:30:38.522543 | controller | ok: Runtime: 0:00:00.034019
2025-11-26 07:30:38.540484 | 
2025-11-26 07:30:38.540705 | TASK [configure-mirrors : Gather needed facts]
2025-11-26 07:30:38.612106 | controller | skipping: Conditional result was False
2025-11-26 07:30:38.629538 | 
2025-11-26 07:30:38.629940 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-11-26 07:30:38.703843 | controller | ok
2025-11-26 07:30:38.723894 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-11-26 07:30:38.735684 | 
2025-11-26 07:30:38.735809 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-11-26 07:30:39.066124 | controller | ok
2025-11-26 07:30:39.074676 | 
2025-11-26 07:30:39.074848 | LOOP [configure-mirrors : Include OS-specific variables]
2025-11-26 07:30:39.174786 | controller | ok: "/var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-11-26 07:30:39.208527 | 
2025-11-26 07:30:39.208641 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-11-26 07:30:40.093186 | controller | changed
2025-11-26 07:30:40.102284 | 
2025-11-26 07:30:40.102373 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-11-26 07:30:40.203684 | controller | ok: "/var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-11-26 07:30:40.204080 | controller | ok: All items complete
2025-11-26 07:30:40.204124 | 
2025-11-26 07:30:40.253505 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-11-26 07:30:40.261337 | 
2025-11-26 07:30:40.261409 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-11-26 07:30:41.189276 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-11-26 07:30:42.093777 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-11-26 07:30:42.117619 | 
2025-11-26 07:30:42.117830 | TASK [configure-mirrors : Disable deltrarpm]
2025-11-26 07:30:42.630362 | controller | changed: section and option added
2025-11-26 07:30:42.667132 | 
2025-11-26 07:30:42.667257 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-11-26 07:30:43.455520 | controller | 29 files removed
2025-11-26 07:30:43.455766 | controller | ok: Item: dnf clean all Runtime: 0:00:00.469879
2025-11-26 07:30:43.455811 | controller | changed: All items complete
2025-11-26 07:30:43.455832 | 
2025-11-26 07:30:55.248411 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-11-26 07:30:55.248542 | controller | DNF version: 4.14.0
2025-11-26 07:30:55.248568 | controller | cachedir: /var/cache/dnf
2025-11-26 07:30:55.248587 | controller | Making cache files for all metadata files.
2025-11-26 07:30:55.248604 | controller | baseos: has expired and will be refreshed.
2025-11-26 07:30:55.248621 | controller | appstream: has expired and will be refreshed.
2025-11-26 07:30:55.248637 | controller | crb: has expired and will be refreshed.
2025-11-26 07:30:55.248665 | controller | extras-common: has expired and will be refreshed.
2025-11-26 07:30:55.248681 | controller | repo: downloading from remote: baseos
2025-11-26 07:30:55.248697 | controller | CentOS Stream 9 - BaseOS                         18 MB/s | 8.8 MB     00:00
2025-11-26 07:30:55.248713 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST.
2025-11-26 07:30:55.248753 | controller | repo: downloading from remote: appstream
2025-11-26 07:30:55.248772 | controller | CentOS Stream 9 - AppStream                      37 MB/s |  25 MB     00:00
2025-11-26 07:30:55.248788 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST.
2025-11-26 07:30:55.248804 | controller | repo: downloading from remote: crb
2025-11-26 07:30:55.248820 | controller | CentOS Stream 9 - CRB                            38 MB/s | 7.3 MB     00:00
2025-11-26 07:30:55.248836 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST.
2025-11-26 07:30:55.248852 | controller | repo: downloading from remote: extras-common
2025-11-26 07:30:55.248868 | controller | CentOS Stream 9 - Extras packages               1.8 MB/s |  20 kB     00:00
2025-11-26 07:30:55.248884 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-11-26 07:30:55.248900 | controller | Last metadata expiration check: 0:00:01 ago on Wed 26 Nov 2025 02:30:53 AM EST.
2025-11-26 07:30:55.248916 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-11-26 07:30:55.248932 | controller | Completion plugin: Generating completion cache...
2025-11-26 07:30:55.248948 | controller | Metadata cache created.
2025-11-26 07:30:55.248973 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.547944
2025-11-26 07:30:55.282569 | 
2025-11-26 07:30:55.282810 | PLAY RECAP
2025-11-26 07:30:55.282889 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-26 07:30:55.282936 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-26 07:30:55.282969 | 
2025-11-26 07:30:55.416681 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-11-26 07:30:55.418155 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-26 07:30:55.993474 | 
2025-11-26 07:30:55.993601 | PLAY [all]
2025-11-26 07:30:56.015094 | 
2025-11-26 07:30:56.015220 | TASK [Install binary dependencies]
2025-11-26 07:30:56.097876 | controller | ok
2025-11-26 07:30:56.124829 | 
2025-11-26 07:30:56.125012 | TASK [bindep : Include find tasks]
2025-11-26 07:30:56.158489 | controller | ok
2025-11-26 07:30:56.170659 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-26 07:30:56.179349 | 
2025-11-26 07:30:56.179462 | TASK [bindep : Look for bindep.txt]
2025-11-26 07:30:56.597820 | controller | ok
2025-11-26 07:30:56.604583 | 
2025-11-26 07:30:56.604670 | TASK [bindep : Define bindep_file fact]
2025-11-26 07:30:56.634249 | controller | ok
2025-11-26 07:30:56.640765 | 
2025-11-26 07:30:56.640860 | TASK [bindep : Look for other-requirements.txt]
2025-11-26 07:30:56.665363 | controller | skipping: Conditional result was False
2025-11-26 07:30:56.673712 | 
2025-11-26 07:30:56.673892 | TASK [bindep : Define bindep_file fact]
2025-11-26 07:30:56.699538 | controller | skipping: Conditional result was False
2025-11-26 07:30:56.705688 | 
2025-11-26 07:30:56.705775 | TASK [bindep : Look for bindep fallback file]
2025-11-26 07:30:56.740096 | controller | skipping: Conditional result was False
2025-11-26 07:30:56.749473 | 
2025-11-26 07:30:56.749629 | TASK [bindep : Define bindep_file fact]
2025-11-26 07:30:56.777906 | controller | skipping: Conditional result was False
2025-11-26 07:30:56.788984 | 
2025-11-26 07:30:56.789081 | TASK [bindep : Include bindep tasks]
2025-11-26 07:30:56.846210 | controller | ok
2025-11-26 07:30:56.856645 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-11-26 07:30:56.867627 | 
2025-11-26 07:30:56.867755 | TASK [bindep : Look for bindep command]
2025-11-26 07:30:56.904301 | controller | skipping: Conditional result was False
2025-11-26 07:30:56.913459 | 
2025-11-26 07:30:56.913556 | TASK [bindep : Check for system bindep]
2025-11-26 07:30:57.457015 | controller | ok: Runtime: 0:00:00.006647
2025-11-26 07:30:57.470912 | 
2025-11-26 07:30:57.471077 | TASK [bindep : Define bindep_command fact]
2025-11-26 07:30:57.498548 | controller | skipping: Conditional result was False
2025-11-26 07:30:57.511929 | 
2025-11-26 07:30:57.512110 | TASK [bindep : Include install tasks]
2025-11-26 07:30:57.570416 | controller | ok
2025-11-26 07:30:57.586362 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-11-26 07:30:57.605603 | 
2025-11-26 07:30:57.605805 | TASK [bindep : Create temp dir for bindep]
2025-11-26 07:30:58.060688 | controller | changed
2025-11-26 07:30:58.073754 | 
2025-11-26 07:30:58.073889 | TASK [Ensure we have pip dependencies]
2025-11-26 07:30:58.102367 | controller | ok
2025-11-26 07:30:58.141783 | 
2025-11-26 07:30:58.141915 | TASK [ensure-pip : Check if pip is installed]
2025-11-26 02:30:58.458380 | controller | /usr/bin/pip3
2025-11-26 02:30:58.480438 | controller | /usr/bin/python3: No module named wheel
2025-11-26 07:30:58.683653 | controller | ok: Runtime: 0:00:00.034802
2025-11-26 07:30:58.722596 | 
2025-11-26 07:30:58.722826 | LOOP [ensure-pip : Install pip from packages]
2025-11-26 07:30:58.781590 | controller | ok: "/var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-11-26 07:30:58.803750 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-11-26 07:30:58.824744 | 
2025-11-26 07:30:58.824888 | TASK [ensure-pip : Install Python 3 pip]
2025-11-26 07:31:01.541928 | controller | changed
2025-11-26 07:31:01.559689 | 
2025-11-26 07:31:01.559869 | TASK [ensure-pip : Check for EPEL repository]
2025-11-26 07:31:01.642087 | controller | skipping: Conditional result was False
2025-11-26 07:31:01.672522 | 
2025-11-26 07:31:01.672700 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-11-26 07:31:01.730637 | controller | skipping: Conditional result was False
2025-11-26 07:31:01.758036 | 
2025-11-26 07:31:01.758247 | TASK [ensure-pip : Install Python 2 pip]
2025-11-26 07:31:01.807206 | controller | skipping: Conditional result was False
2025-11-26 07:31:01.816636 | 
2025-11-26 07:31:01.816798 | TASK [ensure-pip : Ensure setuptools]
2025-11-26 07:31:01.833096 | controller | skipping: Conditional result was False
2025-11-26 07:31:01.842712 | 
2025-11-26 07:31:01.842858 | TASK [ensure-pip : Check for ensurepip module]
2025-11-26 07:31:02.384407 | controller | skipping: Conditional result was False
2025-11-26 07:31:02.391217 | 
2025-11-26 07:31:02.391297 | TASK [ensure-pip : Ensure python3-venv]
2025-11-26 07:31:02.415214 | controller | skipping: Conditional result was False
2025-11-26 07:31:02.422878 | 
2025-11-26 07:31:02.423004 | TASK [ensure-pip : Install pip from source]
2025-11-26 07:31:02.447774 | controller | skipping: Conditional result was False
2025-11-26 07:31:02.455243 | 
2025-11-26 07:31:02.455326 | TASK [ensure-pip : Probe for venv python full path]
2025-11-26 02:31:02.725269 | controller | /usr/bin/python3
2025-11-26 07:31:02.999489 | controller | ok: Runtime: 0:00:00.004828
2025-11-26 07:31:03.006008 | 
2025-11-26 07:31:03.006127 | TASK [ensure-pip : Set host default]
2025-11-26 07:31:03.067023 | controller | ok
2025-11-26 07:31:03.072179 | 
2025-11-26 07:31:03.072245 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-11-26 07:31:03.136076 | controller | ok
2025-11-26 07:31:03.146780 | 
2025-11-26 07:31:03.146846 | TASK [bindep : Install bindep into temporary venv]
2025-11-26 07:31:07.796156 | controller | changed
2025-11-26 07:31:07.810814 | 
2025-11-26 07:31:07.810919 | TASK [bindep : Define bindep_command]
2025-11-26 07:31:07.854171 | controller | ok
2025-11-26 07:31:07.861519 | 
2025-11-26 07:31:07.861607 | LOOP [bindep : Include package tasks]
2025-11-26 07:31:07.914055 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-11-26 07:31:07.914411 | controller | ok: All items complete
2025-11-26 07:31:07.914447 | 
2025-11-26 07:31:07.936376 | controller | included: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-11-26 07:31:07.951385 | 
2025-11-26 07:31:07.951681 | TASK [bindep : Define bindep_run fact]
2025-11-26 07:31:07.983385 | controller | ok
2025-11-26 07:31:07.988450 | 
2025-11-26 07:31:07.988516 | TASK [bindep : Get list of packages to install from bindep]
2025-11-26 02:31:09.624198 | controller | podman
2025-11-26 02:31:09.677670 | controller | python3-jmespath
2025-11-26 02:31:09.677785 | controller | python3-libvirt
2025-11-26 02:31:09.677796 | controller | python3-lxml
2025-11-26 02:31:09.678018 | controller | python3-netaddr
2025-11-26 07:31:10.022473 | controller | ok: Runtime: 0:00:01.458234
2025-11-26 07:31:10.028476 | 
2025-11-26 07:31:10.028541 | TASK [bindep : Install distro packages from bindep]
2025-11-26 07:32:22.472180 | controller | changed
2025-11-26 07:32:22.485780 | 
2025-11-26 07:32:22.485947 | TASK [bindep : Check that packages are installed]
2025-11-26 07:32:24.539710 | controller | ok: Runtime: 0:00:01.447174
2025-11-26 07:32:24.552775 | 
2025-11-26 07:32:24.552977 | TASK [bindep : Fail if we cannot install all packages]
2025-11-26 07:32:24.590082 | controller | skipping: Conditional result was False
2025-11-26 07:32:24.614492 | 
2025-11-26 07:32:24.614927 | TASK [Run test-setup role]
2025-11-26 07:32:24.643919 | controller | ok
2025-11-26 07:32:24.695183 | 
2025-11-26 07:32:24.695337 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-26 07:32:24.932156 | controller | ok
2025-11-26 07:32:24.939128 | 
2025-11-26 07:32:24.939210 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-26 07:32:25.478947 | controller | skipping: Conditional result was False
2025-11-26 07:32:25.524262 | 
2025-11-26 07:32:25.524615 | TASK [bindep : Remove bindep temp dir]
2025-11-26 07:32:25.995545 | controller | ok
2025-11-26 07:32:26.016381 | 
2025-11-26 07:32:26.016483 | PLAY RECAP
2025-11-26 07:32:26.016570 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-11-26 07:32:26.016605 | 
2025-11-26 07:32:26.141757 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-26 07:32:26.143472 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-11-26 07:32:26.731563 | 
2025-11-26 07:32:26.731672 | PLAY [all]
2025-11-26 07:32:26.751220 | 
2025-11-26 07:32:26.751306 | TASK [Abort when test_command variable is undefined]
2025-11-26 07:32:26.786127 | controller | skipping: Conditional result was False
2025-11-26 07:32:26.791819 | 
2025-11-26 07:32:26.791892 | TASK [Convert test_command to list]
2025-11-26 07:32:26.837842 | controller | skipping: Conditional result was False
2025-11-26 07:32:26.851703 | 
2025-11-26 07:32:26.851894 | TASK [Use test_command list]
2025-11-26 07:32:26.930367 | controller | ok
2025-11-26 07:32:26.942142 | 
2025-11-26 07:32:26.942276 | LOOP [Run test_command]
2025-11-26 07:32:27.424866 | controller | no check to run
2025-11-26 07:32:27.425209 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006595
2025-11-26 07:32:27.471276 | 
2025-11-26 07:32:27.471433 | PLAY RECAP
2025-11-26 07:32:27.471516 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-26 07:32:27.471560 | 
2025-11-26 07:32:27.573893 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-11-26 07:32:27.574799 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-26 07:32:28.191130 | 
2025-11-26 07:32:28.191253 | PLAY [all]
2025-11-26 07:32:28.212614 | 
2025-11-26 07:32:28.212745 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-26 07:32:28.614522 | controller | changed: non-zero return code
2025-11-26 07:32:28.627030 | 
2025-11-26 07:32:28.627201 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-26 07:32:28.655198 | controller | skipping: Conditional result was False
2025-11-26 07:32:28.668197 | 
2025-11-26 07:32:28.668350 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-26 07:32:28.709587 | 
2025-11-26 07:32:28.709890 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-26 07:32:28.750464 | 
2025-11-26 07:32:28.750775 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-26 07:32:28.778894 | controller | skipping: Conditional result was False
2025-11-26 07:32:28.792606 | 
2025-11-26 07:32:28.792804 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-26 07:32:28.836030 | 
2025-11-26 07:32:28.836328 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-26 07:32:28.863557 | controller | skipping: Conditional result was False
2025-11-26 07:32:28.872787 | 
2025-11-26 07:32:28.872917 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-26 07:32:28.898425 | controller | skipping: Conditional result was False
2025-11-26 07:32:28.907830 | 
2025-11-26 07:32:28.907962 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-26 07:32:28.933452 | controller | skipping: Conditional result was False
2025-11-26 07:32:28.971551 | 
2025-11-26 07:32:28.972229 | PLAY RECAP
2025-11-26 07:32:28.972315 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-26 07:32:28.972350 | 
2025-11-26 07:32:29.079198 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-26 07:32:29.080890 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-26 07:32:29.684075 | 
2025-11-26 07:32:29.684188 | PLAY [all]
2025-11-26 07:32:29.703018 | 
2025-11-26 07:32:29.703102 | TASK [include_role : fetch-output]
2025-11-26 07:32:29.742092 | controller | ok
2025-11-26 07:32:29.761454 | 
2025-11-26 07:32:29.761536 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-26 07:32:29.852569 | controller | skipping: Conditional result was False
2025-11-26 07:32:29.869322 | 
2025-11-26 07:32:29.869598 | TASK [fetch-output : Set log path for single node]
2025-11-26 07:32:29.905261 | controller | ok
2025-11-26 07:32:29.913062 | 
2025-11-26 07:32:29.913164 | LOOP [fetch-output : Ensure local output dirs]
2025-11-26 07:32:30.325269 | controller -> localhost | ok: "/var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/logs"
2025-11-26 07:32:30.626773 | controller -> localhost | changed: "/var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/artifacts"
2025-11-26 07:32:30.900605 | controller -> localhost | changed: "/var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/docs"
2025-11-26 07:32:30.914338 | 
2025-11-26 07:32:30.914467 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-26 07:32:31.547059 | controller | changed: .d..t...... ./
2025-11-26 07:32:31.547306 | controller | changed: All items complete
2025-11-26 07:32:31.547346 | 
2025-11-26 07:32:32.082336 | controller | changed: .d..t...... ./
2025-11-26 07:32:32.570174 | controller | changed: .d..t...... ./
2025-11-26 07:32:32.585326 | 
2025-11-26 07:32:32.585494 | TASK [include_role : fetch-output-openshift]
2025-11-26 07:32:32.610361 | controller | skipping: Conditional result was False
2025-11-26 07:32:32.619432 | 
2025-11-26 07:32:32.619572 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-26 07:32:33.050488 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012192
2025-11-26 07:32:33.301102 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008771
2025-11-26 07:32:33.332702 | 
2025-11-26 07:32:33.332836 | PLAY [all]
2025-11-26 07:32:33.347107 | 
2025-11-26 07:32:33.347170 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-11-26 07:32:33.868256 | controller | changed
2025-11-26 07:32:33.898501 | 
2025-11-26 07:32:33.898621 | PLAY RECAP
2025-11-26 07:32:33.898678 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-26 07:32:33.898701 | 
2025-11-26 07:32:34.011112 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-26 07:32:34.012850 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-11-26 07:32:34.637942 | 
2025-11-26 07:32:34.638063 | PLAY [localhost]
2025-11-26 07:32:34.655676 | 
2025-11-26 07:32:34.655807 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-26 07:32:34.989285 | localhost | changed
2025-11-26 07:32:34.995517 | 
2025-11-26 07:32:34.995616 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-26 07:32:35.039302 | localhost | ok
2025-11-26 07:32:35.056615 | 
2025-11-26 07:32:35.056787 | TASK [add-fileserver : Create SSH private key tempfile]
2025-11-26 07:32:35.477750 | localhost | changed
2025-11-26 07:32:35.486782 | 
2025-11-26 07:32:35.486890 | TASK [add-fileserver : Create SSH private key from secret]
2025-11-26 07:32:36.290064 | localhost | changed
2025-11-26 07:32:36.295354 | 
2025-11-26 07:32:36.295421 | TASK [add-fileserver : Add fileserver ssh key]
2025-11-26 07:32:36.753508 | localhost | Identity added: /var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/tmp/ansible.ozf64mv9 (/var/lib/zuul/builds/5f0bba9539834248952e04e43f1bf2ea/work/tmp/ansible.ozf64mv9)
2025-11-26 07:32:36.753870 | localhost | ok: Runtime: 0:00:00.013418
2025-11-26 07:32:36.766029 | 
2025-11-26 07:32:36.766207 | TASK [add-fileserver : Remove SSH private key from disk]
2025-11-26 07:32:37.056489 | localhost | ok: Runtime: 0:00:00.009938
2025-11-26 07:32:37.061292 | 
2025-11-26 07:32:37.061357 | TASK [add-fileserver : Add fileserver to inventory]
2025-11-26 07:32:37.143823 | localhost | changed
2025-11-26 07:32:37.150144 | 
2025-11-26 07:32:37.150254 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-11-26 07:32:37.529701 | localhost | changed
2025-11-26 07:32:37.558458 | 
2025-11-26 07:32:37.558602 | PLAY [localhost]
2025-11-26 07:32:37.570873 | 
2025-11-26 07:32:37.570964 | TASK [Generate bulk log download script]
2025-11-26 07:32:37.589329 | localhost | ok
2025-11-26 07:32:37.601665 | 
2025-11-26 07:32:37.601770 | TASK [local-log-download : Check API endpoint is defined]
2025-11-26 07:32:37.630038 | localhost | ok: All assertions passed
2025-11-26 07:32:37.634576 | 
2025-11-26 07:32:37.634637 | TASK [local-log-download : Create download script]
2025-11-26 07:32:38.047325 | localhost -> localhost | changed
2025-11-26 07:32:38.071163 | 
2025-11-26 07:32:38.071398 | TASK [Register quick-download link]
2025-11-26 07:32:38.094437 | localhost | ok
2025-11-26 07:32:38.142909 | 
2025-11-26 07:32:38.143007 | PLAY [logserver.rdoproject.org]
2025-11-26 07:32:38.152715 | 
2025-11-26 07:32:38.152798 | TASK [Set zuul-log-path fact]
2025-11-26 07:32:38.169097 | logserver.rdoproject.org | ok
2025-11-26 07:32:38.179260 | 
2025-11-26 07:32:38.179346 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-26 07:32:38.205946 | logserver.rdoproject.org | ok
2025-11-26 07:32:38.211553 | 
2025-11-26 07:32:38.211617 | TASK [upload-logs : Create log directories]
2025-11-26 07:32:38.866857 | logserver.rdoproject.org | changed
2025-11-26 07:32:38.873644 | 
2025-11-26 07:32:38.873821 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-11-26 07:32:39.207474 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.014304
2025-11-26 07:32:39.213991 | 
2025-11-26 07:32:39.214076 | TASK [upload-logs : Upload logs to log server]
2025-11-26 07:32:39.900033 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-11-26 07:32:39.906393 | 
2025-11-26 07:32:39.906524 | LOOP [upload-logs : Compress console log and json output]
2025-11-26 07:32:39.969175 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-26 07:32:39.977879 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-26 07:32:39.992368 | 
2025-11-26 07:32:39.992556 | LOOP [upload-logs : Upload compressed console log and json output]
2025-11-26 07:32:40.032998 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-26 07:32:40.033436 | 
2025-11-26 07:32:40.035357 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-26 07:32:40.050503 | 
2025-11-26 07:32:40.050648 | LOOP [upload-logs : Upload console log and json output]