2025-12-01 09:13:47.845198 | Job console starting...
2025-12-01 09:13:47.859107 | Updating repositories
2025-12-01 09:13:47.890910 | Preparing job workspace
2025-12-01 09:13:51.781344 | Running Ansible setup...
2025-12-01 09:13:55.439837 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-01 09:13:56.039251 | 
2025-12-01 09:13:56.039376 | PLAY [localhost]
2025-12-01 09:13:56.048713 | 
2025-12-01 09:13:56.048803 | TASK [Gathering Facts]
2025-12-01 09:13:57.055691 | localhost | ok
2025-12-01 09:13:57.075297 | 
2025-12-01 09:13:57.075428 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-01 09:13:57.497928 | localhost -> localhost | changed
2025-12-01 09:13:57.506082 | 
2025-12-01 09:13:57.506201 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-01 09:13:58.307932 | localhost -> localhost | changed
2025-12-01 09:13:58.316954 | 
2025-12-01 09:13:58.317069 | TASK [Setup log path fact]
2025-12-01 09:13:58.335598 | localhost | ok
2025-12-01 09:13:58.347138 | 
2025-12-01 09:13:58.347220 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-01 09:13:58.366400 | localhost | ok
2025-12-01 09:13:58.374014 | 
2025-12-01 09:13:58.374177 | TASK [emit-job-header : Print job information]
2025-12-01 09:13:58.421498 | # Job Information
2025-12-01 09:13:58.421640 | Ansible Version: 2.15.12
2025-12-01 09:13:58.421666 | Job: cifmw-molecule-cifmw_setup
2025-12-01 09:13:58.421686 | Pipeline: github-check
2025-12-01 09:13:58.421704 | Executor: ze01.softwarefactory-project.io
2025-12-01 09:13:58.421722 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3505
2025-12-01 09:13:58.421742 | Log URL (when completed): https://logserver.rdoproject.org/cad/rdoproject.org/cad564d42b2f4dfe82e1fab8abb1d2ad/
2025-12-01 09:13:58.421760 | Event ID: e4b0b400-ce95-11f0-8b84-59f72cfb69de
2025-12-01 09:13:58.425587 | 
2025-12-01 09:13:58.425649 | LOOP [emit-job-header : Print node information]
2025-12-01 09:13:58.515330 | localhost | ok:
2025-12-01 09:13:58.515598 | localhost | # Node Information
2025-12-01 09:13:58.515634 | localhost | Inventory Hostname: controller
2025-12-01 09:13:58.515661 | localhost | Hostname: np0005540834
2025-12-01 09:13:58.515684 | localhost | Username: zuul
2025-12-01 09:13:58.515708 | localhost | Distro: CentOS 9
2025-12-01 09:13:58.515729 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-01 09:13:58.515750 | localhost | Region: RegionOne
2025-12-01 09:13:58.515776 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-01 09:13:58.515808 | localhost | Product Name: OpenStack Nova
2025-12-01 09:13:58.515829 | localhost | Interface IP: 38.102.83.66
2025-12-01 09:13:58.539220 | 
2025-12-01 09:13:58.539312 | PLAY [all]
2025-12-01 09:13:58.545648 | 
2025-12-01 09:13:58.545712 | TASK [Gather network facts]
2025-12-01 09:13:59.097789 | controller | ok
2025-12-01 09:13:59.128590 | 
2025-12-01 09:13:59.128696 | TASK [include_role : start-zuul-console]
2025-12-01 09:13:59.149743 | controller | ok
2025-12-01 09:13:59.167868 | 
2025-12-01 09:13:59.168001 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-01 09:13:59.578380 | controller | ok
2025-12-01 09:13:59.591575 | 
2025-12-01 09:13:59.591670 | TASK [include_role : add-build-sshkey]
2025-12-01 09:13:59.611479 | controller | ok
2025-12-01 09:13:59.624697 | 
2025-12-01 09:13:59.624769 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-01 09:13:59.903469 | controller -> localhost | ok
2025-12-01 09:13:59.909108 | 
2025-12-01 09:13:59.909175 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-01 09:13:59.939678 | controller | ok
2025-12-01 09:13:59.952507 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-01 09:13:59.958416 | 
2025-12-01 09:13:59.958480 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-01 09:14:00.739318 | controller -> localhost | Generating public/private rsa key pair.
2025-12-01 09:14:00.739765 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/cad564d42b2f4dfe82e1fab8abb1d2ad_id_rsa.
2025-12-01 09:14:00.739847 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/cad564d42b2f4dfe82e1fab8abb1d2ad_id_rsa.pub.
2025-12-01 09:14:00.739908 | controller -> localhost | The key fingerprint is:
2025-12-01 09:14:00.739962 | controller -> localhost | SHA256:kPEPzKNm31rHRi+43MNtu3aBw1NSFF1Sc4Y0HUjOMRE zuul-build-sshkey
2025-12-01 09:14:00.740021 | controller -> localhost | The key's randomart image is:
2025-12-01 09:14:00.740124 | controller -> localhost | +---[RSA 3072]----+
2025-12-01 09:14:00.740180 | controller -> localhost | |      .     .EOOX|
2025-12-01 09:14:00.740233 | controller -> localhost | |       *    o.+==|
2025-12-01 09:14:00.740284 | controller -> localhost | |      o *    o.  |
2025-12-01 09:14:00.740336 | controller -> localhost | |       o +   . . |
2025-12-01 09:14:00.740388 | controller -> localhost | |      + S . o +  |
2025-12-01 09:14:00.740437 | controller -> localhost | |     o . . + * . |
2025-12-01 09:14:00.740486 | controller -> localhost | |        . +.=.+ .|
2025-12-01 09:14:00.740536 | controller -> localhost | |         + =o.+ .|
2025-12-01 09:14:00.740585 | controller -> localhost | |        . o .+o+ |
2025-12-01 09:14:00.740635 | controller -> localhost | +----[SHA256]-----+
2025-12-01 09:14:00.740761 | controller -> localhost | ok: Runtime: 0:00:00.305288
2025-12-01 09:14:00.755590 | 
2025-12-01 09:14:00.755745 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-01 09:14:00.793452 | controller | ok
2025-12-01 09:14:00.814942 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-01 09:14:00.830173 | 
2025-12-01 09:14:00.830303 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-01 09:14:00.856204 | controller | skipping: Conditional result was False
2025-12-01 09:14:00.864476 | 
2025-12-01 09:14:00.864575 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-01 09:14:01.371510 | controller | changed
2025-12-01 09:14:01.382368 | 
2025-12-01 09:14:01.382501 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-01 09:14:01.688842 | controller | ok
2025-12-01 09:14:01.701472 | 
2025-12-01 09:14:01.701694 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-01 09:14:02.694989 | controller | changed
2025-12-01 09:14:02.707250 | 
2025-12-01 09:14:02.707434 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-01 09:14:03.689731 | controller | changed
2025-12-01 09:14:03.700997 | 
2025-12-01 09:14:03.701205 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-01 09:14:03.728454 | controller | skipping: Conditional result was False
2025-12-01 09:14:03.740896 | 
2025-12-01 09:14:03.741111 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-01 09:14:04.124607 | controller -> localhost | changed
2025-12-01 09:14:04.146356 | 
2025-12-01 09:14:04.146550 | TASK [add-build-sshkey : Add back temp key]
2025-12-01 09:14:04.460743 | controller -> localhost | Identity added: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/cad564d42b2f4dfe82e1fab8abb1d2ad_id_rsa (zuul-build-sshkey)
2025-12-01 09:14:04.461036 | controller -> localhost | ok: Runtime: 0:00:00.011056
2025-12-01 09:14:04.472085 | 
2025-12-01 09:14:04.472177 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-01 09:14:04.854603 | controller | ok
2025-12-01 09:14:04.865232 | 
2025-12-01 09:14:04.865374 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-01 09:14:04.892192 | controller | skipping: Conditional result was False
2025-12-01 09:14:04.913224 | 
2025-12-01 09:14:04.913356 | TASK [include_role : validate-host]
2025-12-01 09:14:04.939368 | controller | ok
2025-12-01 09:14:04.970809 | 
2025-12-01 09:14:04.970925 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-01 09:14:05.002839 | controller | ok
2025-12-01 09:14:05.009770 | 
2025-12-01 09:14:05.009858 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-01 09:14:05.229805 | controller -> localhost | ok
2025-12-01 09:14:05.242900 | 
2025-12-01 09:14:05.243141 | TASK [validate-host : Collect information about the host]
2025-12-01 09:14:06.147795 | controller | ok
2025-12-01 09:14:06.169782 | 
2025-12-01 09:14:06.169939 | TASK [validate-host : Sanitize hostname]
2025-12-01 09:14:06.247836 | controller | ok
2025-12-01 09:14:06.258837 | 
2025-12-01 09:14:06.258987 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-01 09:14:06.714631 | controller -> localhost | changed
2025-12-01 09:14:06.727620 | 
2025-12-01 09:14:06.727781 | TASK [validate-host : Collect information about zuul worker]
2025-12-01 09:14:07.161378 | controller | ok
2025-12-01 09:14:07.173138 | 
2025-12-01 09:14:07.173293 | TASK [validate-host : Write out all zuul information for each host]
2025-12-01 09:14:07.567931 | controller -> localhost | changed
2025-12-01 09:14:07.591385 | 
2025-12-01 09:14:07.591567 | TASK [include_role : prepare-workspace-openshift]
2025-12-01 09:14:07.608180 | controller | skipping: Conditional result was False
2025-12-01 09:14:07.621101 | 
2025-12-01 09:14:07.621261 | TASK [include_role : remove-zuul-sshkey]
2025-12-01 09:14:07.638535 | controller | skipping: Conditional result was False
2025-12-01 09:14:07.650846 | 
2025-12-01 09:14:07.650983 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-01 09:14:07.928312 | controller | ok: "logs"
2025-12-01 09:14:07.928779 | controller | ok: All items complete
2025-12-01 09:14:07.928849 | 
2025-12-01 09:14:08.148422 | controller | ok: "artifacts"
2025-12-01 09:14:08.366864 | controller | ok: "docs"
2025-12-01 09:14:08.386124 | 
2025-12-01 09:14:08.386289 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-01 09:14:08.691159 | controller | changed: "logs"
2025-12-01 09:14:08.928489 | controller | changed: "artifacts"
2025-12-01 09:14:09.198142 | controller | changed: "docs"
2025-12-01 09:14:09.256211 | 
2025-12-01 09:14:09.256328 | PLAY RECAP
2025-12-01 09:14:09.256384 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-01 09:14:09.256420 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-01 09:14:09.256445 | 
2025-12-01 09:14:09.369073 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-01 09:14:09.370680 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-01 09:14:09.966313 | 
2025-12-01 09:14:09.966426 | PLAY [localhost]
2025-12-01 09:14:09.982324 | 
2025-12-01 09:14:09.982400 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-01 09:14:10.397857 | localhost | ok
2025-12-01 09:14:10.403603 | 
2025-12-01 09:14:10.403683 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-01 09:14:11.151397 | localhost | changed
2025-12-01 09:14:11.171103 | 
2025-12-01 09:14:11.171161 | PLAY [all]
2025-12-01 09:14:11.186638 | 
2025-12-01 09:14:11.186722 | TASK [include_role : prepare-workspace]
2025-12-01 09:14:11.215719 | controller | ok
2025-12-01 09:14:11.229627 | 
2025-12-01 09:14:11.229700 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-01 09:14:11.653999 | controller | ok
2025-12-01 09:14:11.668339 | 
2025-12-01 09:14:11.668483 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-01 09:14:13.600972 | controller | Output suppressed because no_log was given
2025-12-01 09:14:13.621100 | 
2025-12-01 09:14:13.621252 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-01 09:14:13.870376 | controller | changed: "logs"
2025-12-01 09:14:14.096980 | controller | changed: "artifacts"
2025-12-01 09:14:14.316540 | controller | changed: "docs"
2025-12-01 09:14:14.338238 | 
2025-12-01 09:14:14.338448 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-01 09:14:14.633212 | controller | changed: "logs"
2025-12-01 09:14:14.633633 | controller | changed: All items complete
2025-12-01 09:14:14.633701 | 
2025-12-01 09:14:14.898414 | controller | changed: "artifacts"
2025-12-01 09:14:15.126658 | controller | changed: "docs"
2025-12-01 09:14:15.157074 | 
2025-12-01 09:14:15.157287 | TASK [Check if worker can sudo]
2025-12-01 09:14:15.713334 | controller | ok: Runtime: 0:00:00.043478
2025-12-01 09:14:15.721121 | 
2025-12-01 09:14:15.721210 | TASK [configure-mirrors : Gather needed facts]
2025-12-01 09:14:15.798791 | controller | skipping: Conditional result was False
2025-12-01 09:14:15.814933 | 
2025-12-01 09:14:15.815173 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-01 09:14:15.888386 | controller | ok
2025-12-01 09:14:15.906283 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-01 09:14:15.950220 | 
2025-12-01 09:14:15.950356 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-01 09:14:16.232126 | controller | ok
2025-12-01 09:14:16.244517 | 
2025-12-01 09:14:16.244674 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-01 09:14:16.341934 | controller | ok: "/var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-01 09:14:16.357420 | 
2025-12-01 09:14:16.357567 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-01 09:14:17.405010 | controller | changed
2025-12-01 09:14:17.416805 | 
2025-12-01 09:14:17.416933 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-01 09:14:17.504691 | controller | ok: "/var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-01 09:14:17.505097 | controller | ok: All items complete
2025-12-01 09:14:17.505164 | 
2025-12-01 09:14:17.578882 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-01 09:14:17.588116 | 
2025-12-01 09:14:17.588197 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-01 09:14:18.808207 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-01 09:14:19.884871 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-01 09:14:19.906682 | 
2025-12-01 09:14:19.906836 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-01 09:14:20.351680 | controller | changed: section and option added
2025-12-01 09:14:20.378819 | 
2025-12-01 09:14:20.378927 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-01 09:14:21.073775 | controller | 29 files removed
2025-12-01 09:14:21.074227 | controller | ok: Item: dnf clean all Runtime: 0:00:00.293227
2025-12-01 09:14:21.074321 | controller | changed: All items complete
2025-12-01 09:14:21.074371 | 
2025-12-01 09:14:32.244056 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-12-01 09:14:32.244227 | controller | DNF version: 4.14.0
2025-12-01 09:14:32.244285 | controller | cachedir: /var/cache/dnf
2025-12-01 09:14:32.244333 | controller | Making cache files for all metadata files.
2025-12-01 09:14:32.244376 | controller | baseos: has expired and will be refreshed.
2025-12-01 09:14:32.244416 | controller | appstream: has expired and will be refreshed.
2025-12-01 09:14:32.244455 | controller | crb: has expired and will be refreshed.
2025-12-01 09:14:32.244510 | controller | extras-common: has expired and will be refreshed.
2025-12-01 09:14:32.244550 | controller | repo: downloading from remote: baseos
2025-12-01 09:14:32.244589 | controller | CentOS Stream 9 - BaseOS                         20 MB/s | 8.8 MB     00:00
2025-12-01 09:14:32.244628 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST.
2025-12-01 09:14:32.244666 | controller | repo: downloading from remote: appstream
2025-12-01 09:14:32.244703 | controller | CentOS Stream 9 - AppStream                      43 MB/s |  25 MB     00:00
2025-12-01 09:14:32.244741 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST.
2025-12-01 09:14:32.244779 | controller | repo: downloading from remote: crb
2025-12-01 09:14:32.244816 | controller | CentOS Stream 9 - CRB                            53 MB/s | 7.3 MB     00:00
2025-12-01 09:14:32.244855 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST.
2025-12-01 09:14:32.244893 | controller | repo: downloading from remote: extras-common
2025-12-01 09:14:32.244932 | controller | CentOS Stream 9 - Extras packages               1.6 MB/s |  20 kB     00:00
2025-12-01 09:14:32.244971 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-01 09:14:32.245009 | controller | Last metadata expiration check: 0:00:01 ago on Mon 01 Dec 2025 04:14:30 AM EST.
2025-12-01 09:14:32.245279 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-01 09:14:32.245329 | controller | Completion plugin: Generating completion cache...
2025-12-01 09:14:32.245372 | controller | Metadata cache created.
2025-12-01 09:14:32.245430 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.876597
2025-12-01 09:14:32.275221 | 
2025-12-01 09:14:32.275374 | PLAY RECAP
2025-12-01 09:14:32.275458 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-01 09:14:32.275513 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-01 09:14:32.275551 | 
2025-12-01 09:14:32.395728 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-01 09:14:32.396590 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-01 09:14:32.953576 | 
2025-12-01 09:14:32.953695 | PLAY [all]
2025-12-01 09:14:32.975741 | 
2025-12-01 09:14:32.975875 | TASK [Install binary dependencies]
2025-12-01 09:14:33.025533 | controller | ok
2025-12-01 09:14:33.045286 | 
2025-12-01 09:14:33.045419 | TASK [bindep : Include find tasks]
2025-12-01 09:14:33.085178 | controller | ok
2025-12-01 09:14:33.093034 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-01 09:14:33.098941 | 
2025-12-01 09:14:33.099105 | TASK [bindep : Look for bindep.txt]
2025-12-01 09:14:33.593047 | controller | ok
2025-12-01 09:14:33.607549 | 
2025-12-01 09:14:33.607695 | TASK [bindep : Define bindep_file fact]
2025-12-01 09:14:33.656483 | controller | ok
2025-12-01 09:14:33.668397 | 
2025-12-01 09:14:33.668579 | TASK [bindep : Look for other-requirements.txt]
2025-12-01 09:14:33.695758 | controller | skipping: Conditional result was False
2025-12-01 09:14:33.708869 | 
2025-12-01 09:14:33.709058 | TASK [bindep : Define bindep_file fact]
2025-12-01 09:14:33.746529 | controller | skipping: Conditional result was False
2025-12-01 09:14:33.759282 | 
2025-12-01 09:14:33.759447 | TASK [bindep : Look for bindep fallback file]
2025-12-01 09:14:33.796652 | controller | skipping: Conditional result was False
2025-12-01 09:14:33.809635 | 
2025-12-01 09:14:33.809807 | TASK [bindep : Define bindep_file fact]
2025-12-01 09:14:33.837168 | controller | skipping: Conditional result was False
2025-12-01 09:14:33.850256 | 
2025-12-01 09:14:33.850394 | TASK [bindep : Include bindep tasks]
2025-12-01 09:14:33.901479 | controller | ok
2025-12-01 09:14:33.916701 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-01 09:14:33.930067 | 
2025-12-01 09:14:33.930161 | TASK [bindep : Look for bindep command]
2025-12-01 09:14:33.955872 | controller | skipping: Conditional result was False
2025-12-01 09:14:33.969534 | 
2025-12-01 09:14:33.969701 | TASK [bindep : Check for system bindep]
2025-12-01 09:14:34.517707 | controller | ok: Runtime: 0:00:00.007793
2025-12-01 09:14:34.531219 | 
2025-12-01 09:14:34.531371 | TASK [bindep : Define bindep_command fact]
2025-12-01 09:14:34.559088 | controller | skipping: Conditional result was False
2025-12-01 09:14:34.572866 | 
2025-12-01 09:14:34.573009 | TASK [bindep : Include install tasks]
2025-12-01 09:14:34.612759 | controller | ok
2025-12-01 09:14:34.631761 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-01 09:14:34.648262 | 
2025-12-01 09:14:34.648354 | TASK [bindep : Create temp dir for bindep]
2025-12-01 09:14:35.065107 | controller | changed
2025-12-01 09:14:35.072403 | 
2025-12-01 09:14:35.072496 | TASK [Ensure we have pip dependencies]
2025-12-01 09:14:35.095463 | controller | ok
2025-12-01 09:14:35.129847 | 
2025-12-01 09:14:35.129995 | TASK [ensure-pip : Check if pip is installed]
2025-12-01 04:14:35.439177 | controller | /usr/bin/pip3
2025-12-01 04:14:35.482103 | controller | /usr/bin/python3: No module named wheel
2025-12-01 09:14:35.661670 | controller | ok: Runtime: 0:00:00.056028
2025-12-01 09:14:35.674968 | 
2025-12-01 09:14:35.675147 | LOOP [ensure-pip : Install pip from packages]
2025-12-01 09:14:35.722732 | controller | ok: "/var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-01 09:14:35.744205 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-01 09:14:35.767867 | 
2025-12-01 09:14:35.768075 | TASK [ensure-pip : Install Python 3 pip]
2025-12-01 09:14:37.544200 | controller | changed
2025-12-01 09:14:37.551643 | 
2025-12-01 09:14:37.551728 | TASK [ensure-pip : Check for EPEL repository]
2025-12-01 09:14:37.618636 | controller | skipping: Conditional result was False
2025-12-01 09:14:37.634701 | 
2025-12-01 09:14:37.634874 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-01 09:14:37.694415 | controller | skipping: Conditional result was False
2025-12-01 09:14:37.708521 | 
2025-12-01 09:14:37.708665 | TASK [ensure-pip : Install Python 2 pip]
2025-12-01 09:14:37.756157 | controller | skipping: Conditional result was False
2025-12-01 09:14:37.770060 | 
2025-12-01 09:14:37.770223 | TASK [ensure-pip : Ensure setuptools]
2025-12-01 09:14:37.798187 | controller | skipping: Conditional result was False
2025-12-01 09:14:37.810865 | 
2025-12-01 09:14:37.811009 | TASK [ensure-pip : Check for ensurepip module]
2025-12-01 09:14:38.365591 | controller | skipping: Conditional result was False
2025-12-01 09:14:38.377976 | 
2025-12-01 09:14:38.378148 | TASK [ensure-pip : Ensure python3-venv]
2025-12-01 09:14:38.404725 | controller | skipping: Conditional result was False
2025-12-01 09:14:38.419052 | 
2025-12-01 09:14:38.419204 | TASK [ensure-pip : Install pip from source]
2025-12-01 09:14:38.446314 | controller | skipping: Conditional result was False
2025-12-01 09:14:38.458264 | 
2025-12-01 09:14:38.458397 | TASK [ensure-pip : Probe for venv python full path]
2025-12-01 04:14:38.796163 | controller | /usr/bin/python3
2025-12-01 09:14:39.005916 | controller | ok: Runtime: 0:00:00.007849
2025-12-01 09:14:39.018480 | 
2025-12-01 09:14:39.018639 | TASK [ensure-pip : Set host default]
2025-12-01 09:14:39.076116 | controller | ok
2025-12-01 09:14:39.086905 | 
2025-12-01 09:14:39.087071 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-01 09:14:39.146635 | controller | ok
2025-12-01 09:14:39.168880 | 
2025-12-01 09:14:39.169064 | TASK [bindep : Install bindep into temporary venv]
2025-12-01 09:14:43.484353 | controller | changed
2025-12-01 09:14:43.495956 | 
2025-12-01 09:14:43.496144 | TASK [bindep : Define bindep_command]
2025-12-01 09:14:43.544260 | controller | ok
2025-12-01 09:14:43.554928 | 
2025-12-01 09:14:43.555082 | LOOP [bindep : Include package tasks]
2025-12-01 09:14:43.631663 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-01 09:14:43.631937 | controller | ok: All items complete
2025-12-01 09:14:43.631974 | 
2025-12-01 09:14:43.644138 | controller | included: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-01 09:14:43.658627 | 
2025-12-01 09:14:43.658717 | TASK [bindep : Define bindep_run fact]
2025-12-01 09:14:43.701530 | controller | ok
2025-12-01 09:14:43.708677 | 
2025-12-01 09:14:43.708758 | TASK [bindep : Get list of packages to install from bindep]
2025-12-01 04:14:45.158689 | controller | podman
2025-12-01 04:14:45.193350 | controller | python3-jmespath
2025-12-01 04:14:45.193525 | controller | python3-libvirt
2025-12-01 04:14:45.193545 | controller | python3-lxml
2025-12-01 04:14:45.193566 | controller | python3-netaddr
2025-12-01 09:14:45.257556 | controller | ok: Runtime: 0:00:01.166214
2025-12-01 09:14:45.270331 | 
2025-12-01 09:14:45.270472 | TASK [bindep : Install distro packages from bindep]
2025-12-01 09:15:45.065010 | controller | changed
2025-12-01 09:15:45.082965 | 
2025-12-01 09:15:45.083133 | TASK [bindep : Check that packages are installed]
2025-12-01 09:15:47.131404 | controller | ok: Runtime: 0:00:01.307338
2025-12-01 09:15:47.144125 | 
2025-12-01 09:15:47.144296 | TASK [bindep : Fail if we cannot install all packages]
2025-12-01 09:15:47.181596 | controller | skipping: Conditional result was False
2025-12-01 09:15:47.205120 | 
2025-12-01 09:15:47.205270 | TASK [Run test-setup role]
2025-12-01 09:15:47.232683 | controller | ok
2025-12-01 09:15:47.260174 | 
2025-12-01 09:15:47.260320 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-01 09:15:47.511662 | controller | ok
2025-12-01 09:15:47.522386 | 
2025-12-01 09:15:47.522508 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-01 09:15:48.073906 | controller | skipping: Conditional result was False
2025-12-01 09:15:48.115943 | 
2025-12-01 09:15:48.116153 | TASK [bindep : Remove bindep temp dir]
2025-12-01 09:15:48.499268 | controller | ok
2025-12-01 09:15:48.523401 | 
2025-12-01 09:15:48.523546 | PLAY RECAP
2025-12-01 09:15:48.523630 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-01 09:15:48.523674 | 
2025-12-01 09:15:48.646087 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-01 09:15:48.647247 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-01 09:15:49.168998 | 
2025-12-01 09:15:49.169168 | PLAY [all]
2025-12-01 09:15:49.188908 | 
2025-12-01 09:15:49.189003 | TASK [Abort when test_command variable is undefined]
2025-12-01 09:15:49.223720 | controller | skipping: Conditional result was False
2025-12-01 09:15:49.229902 | 
2025-12-01 09:15:49.229978 | TASK [Convert test_command to list]
2025-12-01 09:15:49.284771 | controller | skipping: Conditional result was False
2025-12-01 09:15:49.298877 | 
2025-12-01 09:15:49.299059 | TASK [Use test_command list]
2025-12-01 09:15:49.367612 | controller | ok
2025-12-01 09:15:49.379637 | 
2025-12-01 09:15:49.379780 | LOOP [Run test_command]
2025-12-01 09:15:49.806330 | controller | no check to run
2025-12-01 09:15:49.806543 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004923
2025-12-01 09:15:49.836634 | 
2025-12-01 09:15:49.836781 | PLAY RECAP
2025-12-01 09:15:49.836819 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-01 09:15:49.836840 | 
2025-12-01 09:15:49.922799 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-01 09:15:49.923704 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-01 09:15:50.488699 | 
2025-12-01 09:15:50.488813 | PLAY [all]
2025-12-01 09:15:50.509237 | 
2025-12-01 09:15:50.509350 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-01 09:15:51.004217 | controller | changed: non-zero return code
2025-12-01 09:15:51.015980 | 
2025-12-01 09:15:51.016171 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-01 09:15:51.033582 | controller | skipping: Conditional result was False
2025-12-01 09:15:51.045647 | 
2025-12-01 09:15:51.045803 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-01 09:15:51.075609 | 
2025-12-01 09:15:51.075869 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-01 09:15:51.100380 | 
2025-12-01 09:15:51.100564 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-01 09:15:51.115354 | controller | skipping: Conditional result was False
2025-12-01 09:15:51.123672 | 
2025-12-01 09:15:51.123764 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-01 09:15:51.158725 | 
2025-12-01 09:15:51.159051 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-01 09:15:51.195931 | controller | skipping: Conditional result was False
2025-12-01 09:15:51.205746 | 
2025-12-01 09:15:51.205867 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-01 09:15:51.231149 | controller | skipping: Conditional result was False
2025-12-01 09:15:51.238932 | 
2025-12-01 09:15:51.239049 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-01 09:15:51.253682 | controller | skipping: Conditional result was False
2025-12-01 09:15:51.283819 | 
2025-12-01 09:15:51.283887 | PLAY RECAP
2025-12-01 09:15:51.283933 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-01 09:15:51.283960 | 
2025-12-01 09:15:51.371650 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-01 09:15:51.372496 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-01 09:15:51.929438 | 
2025-12-01 09:15:51.929551 | PLAY [all]
2025-12-01 09:15:51.948829 | 
2025-12-01 09:15:51.948915 | TASK [include_role : fetch-output]
2025-12-01 09:15:51.978289 | controller | ok
2025-12-01 09:15:51.995128 | 
2025-12-01 09:15:51.995233 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-01 09:15:52.062477 | controller | skipping: Conditional result was False
2025-12-01 09:15:52.068383 | 
2025-12-01 09:15:52.068451 | TASK [fetch-output : Set log path for single node]
2025-12-01 09:15:52.107260 | controller | ok
2025-12-01 09:15:52.113305 | 
2025-12-01 09:15:52.113373 | LOOP [fetch-output : Ensure local output dirs]
2025-12-01 09:15:52.506186 | controller -> localhost | ok: "/var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/logs"
2025-12-01 09:15:52.744206 | controller -> localhost | changed: "/var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/artifacts"
2025-12-01 09:15:52.953426 | controller -> localhost | changed: "/var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/docs"
2025-12-01 09:15:52.975092 | 
2025-12-01 09:15:52.975296 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-01 09:15:53.660969 | controller | changed: .d..t...... ./
2025-12-01 09:15:53.661362 | controller | changed: All items complete
2025-12-01 09:15:53.661425 | 
2025-12-01 09:15:54.202993 | controller | changed: .d..t...... ./
2025-12-01 09:15:54.696790 | controller | changed: .d..t...... ./
2025-12-01 09:15:54.709494 | 
2025-12-01 09:15:54.709650 | TASK [include_role : fetch-output-openshift]
2025-12-01 09:15:54.733972 | controller | skipping: Conditional result was False
2025-12-01 09:15:54.743546 | 
2025-12-01 09:15:54.743642 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-01 09:15:55.191664 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013315
2025-12-01 09:15:55.464734 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009003
2025-12-01 09:15:55.516059 | 
2025-12-01 09:15:55.516252 | PLAY [all]
2025-12-01 09:15:55.538124 | 
2025-12-01 09:15:55.538343 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-01 09:15:55.995895 | controller | changed
2025-12-01 09:15:56.038114 | 
2025-12-01 09:15:56.038181 | PLAY RECAP
2025-12-01 09:15:56.038234 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-01 09:15:56.038262 | 
2025-12-01 09:15:56.133441 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-01 09:15:56.134292 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-01 09:15:56.773520 | 
2025-12-01 09:15:56.773638 | PLAY [localhost]
2025-12-01 09:15:56.792917 | 
2025-12-01 09:15:56.793066 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-01 09:15:57.227230 | localhost | changed
2025-12-01 09:15:57.231894 | 
2025-12-01 09:15:57.231970 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-01 09:15:57.270330 | localhost | ok
2025-12-01 09:15:57.278350 | 
2025-12-01 09:15:57.278421 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-01 09:15:57.641263 | localhost | changed
2025-12-01 09:15:57.646845 | 
2025-12-01 09:15:57.646920 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-01 09:15:58.368442 | localhost | changed
2025-12-01 09:15:58.375922 | 
2025-12-01 09:15:58.376119 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-01 09:15:58.814898 | localhost | Identity added: /var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/tmp/ansible.2_coevs7 (/var/lib/zuul/builds/cad564d42b2f4dfe82e1fab8abb1d2ad/work/tmp/ansible.2_coevs7)
2025-12-01 09:15:58.815245 | localhost | ok: Runtime: 0:00:00.015142
2025-12-01 09:15:58.819538 | 
2025-12-01 09:15:58.819602 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-01 09:15:59.144962 | localhost | ok: Runtime: 0:00:00.008955
2025-12-01 09:15:59.149809 | 
2025-12-01 09:15:59.149877 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-01 09:15:59.237843 | localhost | changed
2025-12-01 09:15:59.247107 | 
2025-12-01 09:15:59.247248 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-01 09:15:59.740485 | localhost | changed
2025-12-01 09:15:59.773824 | 
2025-12-01 09:15:59.773921 | PLAY [localhost]
2025-12-01 09:15:59.791459 | 
2025-12-01 09:15:59.791543 | TASK [Generate bulk log download script]
2025-12-01 09:15:59.812612 | localhost | ok
2025-12-01 09:15:59.829693 | 
2025-12-01 09:15:59.829812 | TASK [local-log-download : Check API endpoint is defined]
2025-12-01 09:15:59.872174 | localhost | ok: All assertions passed
2025-12-01 09:15:59.879169 | 
2025-12-01 09:15:59.879259 | TASK [local-log-download : Create download script]
2025-12-01 09:16:00.317898 | localhost -> localhost | changed
2025-12-01 09:16:00.327245 | 
2025-12-01 09:16:00.327401 | TASK [Register quick-download link]
2025-12-01 09:16:00.356181 | localhost | ok
2025-12-01 09:16:00.403525 | 
2025-12-01 09:16:00.403666 | PLAY [logserver.rdoproject.org]
2025-12-01 09:16:00.413439 | 
2025-12-01 09:16:00.413497 | TASK [Set zuul-log-path fact]
2025-12-01 09:16:00.440634 | logserver.rdoproject.org | ok
2025-12-01 09:16:00.449846 | 
2025-12-01 09:16:00.449913 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-01 09:16:00.477502 | logserver.rdoproject.org | ok
2025-12-01 09:16:00.482704 | 
2025-12-01 09:16:00.482926 | TASK [upload-logs : Create log directories]
2025-12-01 09:16:01.366540 | logserver.rdoproject.org | changed
2025-12-01 09:16:01.383890 | 
2025-12-01 09:16:01.384072 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-01 09:16:01.736320 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.010018
2025-12-01 09:16:01.741565 | 
2025-12-01 09:16:01.741639 | TASK [upload-logs : Upload logs to log server]
2025-12-01 09:16:02.401635 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-01 09:16:02.415364 | 
2025-12-01 09:16:02.415481 | LOOP [upload-logs : Compress console log and json output]
2025-12-01 09:16:02.470589 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 09:16:02.478903 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 09:16:02.487273 | 
2025-12-01 09:16:02.487351 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-01 09:16:02.524050 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 09:16:02.524332 | 
2025-12-01 09:16:02.527831 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 09:16:02.535870 | 
2025-12-01 09:16:02.535986 | LOOP [upload-logs : Upload console log and json output]