2025-10-09 10:36:35.032938 | Job console starting...
2025-10-09 10:36:35.050367 | Updating repositories
2025-10-09 10:36:35.073796 | Preparing job workspace
2025-10-09 10:36:38.720021 | Running Ansible setup...
2025-10-09 10:36:42.616449 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-09 10:36:43.271966 | 
2025-10-09 10:36:43.272193 | PLAY [localhost]
2025-10-09 10:36:43.284270 | 
2025-10-09 10:36:43.284399 | TASK [Gathering Facts]
2025-10-09 10:36:44.323542 | localhost | ok
2025-10-09 10:36:44.337839 | 
2025-10-09 10:36:44.337927 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-09 10:36:44.730397 | localhost -> localhost | changed
2025-10-09 10:36:44.749195 | 
2025-10-09 10:36:44.749434 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-09 10:36:45.704320 | localhost -> localhost | changed
2025-10-09 10:36:45.714978 | 
2025-10-09 10:36:45.715229 | TASK [Setup log path fact]
2025-10-09 10:36:45.735358 | localhost | ok
2025-10-09 10:36:45.754693 | 
2025-10-09 10:36:45.754896 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-09 10:36:45.786847 | localhost | ok
2025-10-09 10:36:45.799861 | 
2025-10-09 10:36:45.800005 | TASK [emit-job-header : Print job information]
2025-10-09 10:36:45.855350 | # Job Information
2025-10-09 10:36:45.855636 | Ansible Version: 2.15.12
2025-10-09 10:36:45.855692 | Job: cifmw-molecule-cifmw_setup
2025-10-09 10:36:45.855991 | Pipeline: github-check
2025-10-09 10:36:45.856046 | Executor: ze03.softwarefactory-project.io
2025-10-09 10:36:45.856086 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3389
2025-10-09 10:36:45.856127 | Log URL (when completed): https://logserver.rdoproject.org/6c0/rdoproject.org/6c0ebd95a047455d8205adcf1c1bedcd/
2025-10-09 10:36:45.856166 | Event ID: 94afef70-a4fb-11f0-9554-64b4b240af0e
2025-10-09 10:36:45.865477 | 
2025-10-09 10:36:45.865673 | LOOP [emit-job-header : Print node information]
2025-10-09 10:36:45.983490 | localhost | ok:
2025-10-09 10:36:45.983999 | localhost | # Node Information
2025-10-09 10:36:45.984067 | localhost | Inventory Hostname: controller
2025-10-09 10:36:45.984122 | localhost | Hostname: np0005478450
2025-10-09 10:36:45.984169 | localhost | Username: zuul
2025-10-09 10:36:45.984218 | localhost | Distro: CentOS 9
2025-10-09 10:36:45.984262 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-09 10:36:45.984304 | localhost | Region: RegionOne
2025-10-09 10:36:45.984345 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-09 10:36:45.984385 | localhost | Product Name: OpenStack Nova
2025-10-09 10:36:45.984425 | localhost | Interface IP: 38.129.56.206
2025-10-09 10:36:46.033373 | 
2025-10-09 10:36:46.033529 | PLAY [all]
2025-10-09 10:36:46.044797 | 
2025-10-09 10:36:46.044969 | TASK [Gather network facts]
2025-10-09 10:36:46.568237 | controller | ok
2025-10-09 10:36:46.600498 | 
2025-10-09 10:36:46.600636 | TASK [include_role : start-zuul-console]
2025-10-09 10:36:46.624181 | controller | ok
2025-10-09 10:36:46.641387 | 
2025-10-09 10:36:46.641504 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-09 10:36:47.063649 | controller | ok
2025-10-09 10:36:47.074157 | 
2025-10-09 10:36:47.074248 | TASK [include_role : add-build-sshkey]
2025-10-09 10:36:47.110553 | controller | ok
2025-10-09 10:36:47.126858 | 
2025-10-09 10:36:47.127049 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-09 10:36:47.433225 | controller -> localhost | ok
2025-10-09 10:36:47.441942 | 
2025-10-09 10:36:47.442028 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-09 10:36:47.482749 | controller | ok
2025-10-09 10:36:47.497881 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-09 10:36:47.504329 | 
2025-10-09 10:36:47.504420 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-09 10:36:48.328279 | controller -> localhost | Generating public/private rsa key pair.
2025-10-09 10:36:48.328562 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/6c0ebd95a047455d8205adcf1c1bedcd_id_rsa.
2025-10-09 10:36:48.328608 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/6c0ebd95a047455d8205adcf1c1bedcd_id_rsa.pub.
2025-10-09 10:36:48.328640 | controller -> localhost | The key fingerprint is:
2025-10-09 10:36:48.328669 | controller -> localhost | SHA256:yFGHqgNty35isrO9LApYikdFoySPNdoTK51IWs0H270 zuul-build-sshkey
2025-10-09 10:36:48.328700 | controller -> localhost | The key's randomart image is:
2025-10-09 10:36:48.328746 | controller -> localhost | +---[RSA 3072]----+
2025-10-09 10:36:48.328781 | controller -> localhost | |..*o+.  ...      |
2025-10-09 10:36:48.328810 | controller -> localhost | |o% Bo+.o..       |
2025-10-09 10:36:48.328837 | controller -> localhost | |* O.o.o..        |
2025-10-09 10:36:48.328864 | controller -> localhost | | ..oo..o .       |
2025-10-09 10:36:48.328890 | controller -> localhost | |  o+ oo E        |
2025-10-09 10:36:48.328916 | controller -> localhost | |o+  =            |
2025-10-09 10:36:48.328941 | controller -> localhost | |= .. .           |
2025-10-09 10:36:48.328967 | controller -> localhost | |..+o+ .          |
2025-10-09 10:36:48.328993 | controller -> localhost | |..oB++           |
2025-10-09 10:36:48.329017 | controller -> localhost | +----[SHA256]-----+
2025-10-09 10:36:48.329078 | controller -> localhost | ok: Runtime: 0:00:00.310299
2025-10-09 10:36:48.337289 | 
2025-10-09 10:36:48.337374 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-09 10:36:48.359159 | controller | ok
2025-10-09 10:36:48.372810 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-09 10:36:48.384131 | 
2025-10-09 10:36:48.384218 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-09 10:36:48.409403 | controller | skipping: Conditional result was False
2025-10-09 10:36:48.416490 | 
2025-10-09 10:36:48.416566 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-09 10:36:48.900132 | controller | changed
2025-10-09 10:36:48.912598 | 
2025-10-09 10:36:48.912785 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-09 10:36:49.199385 | controller | ok
2025-10-09 10:36:49.212028 | 
2025-10-09 10:36:49.212224 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-09 10:36:50.041820 | controller | changed
2025-10-09 10:36:50.055453 | 
2025-10-09 10:36:50.055599 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-09 10:36:50.877840 | controller | changed
2025-10-09 10:36:50.889356 | 
2025-10-09 10:36:50.889488 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-09 10:36:50.917866 | controller | skipping: Conditional result was False
2025-10-09 10:36:50.931482 | 
2025-10-09 10:36:50.931657 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-09 10:36:51.368787 | controller -> localhost | changed
2025-10-09 10:36:51.385018 | 
2025-10-09 10:36:51.385169 | TASK [add-build-sshkey : Add back temp key]
2025-10-09 10:36:51.675872 | controller -> localhost | Identity added: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/6c0ebd95a047455d8205adcf1c1bedcd_id_rsa (zuul-build-sshkey)
2025-10-09 10:36:51.676391 | controller -> localhost | ok: Runtime: 0:00:00.017080
2025-10-09 10:36:51.689976 | 
2025-10-09 10:36:51.690155 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-09 10:36:52.058964 | controller | ok
2025-10-09 10:36:52.069526 | 
2025-10-09 10:36:52.069695 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-09 10:36:52.106976 | controller | skipping: Conditional result was False
2025-10-09 10:36:52.129155 | 
2025-10-09 10:36:52.129389 | TASK [include_role : validate-host]
2025-10-09 10:36:52.168403 | controller | ok
2025-10-09 10:36:52.205822 | 
2025-10-09 10:36:52.205970 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-09 10:36:52.241145 | controller | ok
2025-10-09 10:36:52.251005 | 
2025-10-09 10:36:52.251150 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-09 10:36:52.541311 | controller -> localhost | ok
2025-10-09 10:36:52.559309 | 
2025-10-09 10:36:52.559507 | TASK [validate-host : Collect information about the host]
2025-10-09 10:36:53.298570 | controller | ok
2025-10-09 10:36:53.308445 | 
2025-10-09 10:36:53.308586 | TASK [validate-host : Sanitize hostname]
2025-10-09 10:36:53.404056 | controller | ok
2025-10-09 10:36:53.412213 | 
2025-10-09 10:36:53.412365 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-09 10:36:53.957174 | controller -> localhost | changed
2025-10-09 10:36:53.963450 | 
2025-10-09 10:36:53.963533 | TASK [validate-host : Collect information about zuul worker]
2025-10-09 10:36:54.349732 | controller | ok
2025-10-09 10:36:54.354694 | 
2025-10-09 10:36:54.354851 | TASK [validate-host : Write out all zuul information for each host]
2025-10-09 10:36:54.807371 | controller -> localhost | changed
2025-10-09 10:36:54.827877 | 
2025-10-09 10:36:54.828060 | TASK [include_role : prepare-workspace-openshift]
2025-10-09 10:36:54.845204 | controller | skipping: Conditional result was False
2025-10-09 10:36:54.856923 | 
2025-10-09 10:36:54.857125 | TASK [include_role : remove-zuul-sshkey]
2025-10-09 10:36:54.883372 | controller | skipping: Conditional result was False
2025-10-09 10:36:54.891870 | 
2025-10-09 10:36:54.891993 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-09 10:36:55.133268 | controller | ok: "logs"
2025-10-09 10:36:55.133561 | controller | ok: All items complete
2025-10-09 10:36:55.133594 | 
2025-10-09 10:36:55.332677 | controller | ok: "artifacts"
2025-10-09 10:36:55.524874 | controller | ok: "docs"
2025-10-09 10:36:55.543522 | 
2025-10-09 10:36:55.543681 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-09 10:36:55.834063 | controller | changed: "logs"
2025-10-09 10:36:56.046542 | controller | changed: "artifacts"
2025-10-09 10:36:56.296675 | controller | changed: "docs"
2025-10-09 10:36:56.351399 | 
2025-10-09 10:36:56.351599 | PLAY RECAP
2025-10-09 10:36:56.351687 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-09 10:36:56.351736 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-09 10:36:56.351796 | 
2025-10-09 10:36:56.530220 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-09 10:36:56.531099 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-09 10:36:57.151993 | 
2025-10-09 10:36:57.152192 | PLAY [localhost]
2025-10-09 10:36:57.169754 | 
2025-10-09 10:36:57.169885 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-09 10:36:57.600589 | localhost | ok
2025-10-09 10:36:57.606147 | 
2025-10-09 10:36:57.606227 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-09 10:36:58.293302 | localhost | changed
2025-10-09 10:36:58.315580 | 
2025-10-09 10:36:58.315759 | PLAY [all]
2025-10-09 10:36:58.333011 | 
2025-10-09 10:36:58.333141 | TASK [include_role : prepare-workspace]
2025-10-09 10:36:58.353162 | controller | ok
2025-10-09 10:36:58.368159 | 
2025-10-09 10:36:58.368284 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-09 10:36:58.739087 | controller | ok
2025-10-09 10:36:58.748401 | 
2025-10-09 10:36:58.748535 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-09 10:37:00.327139 | controller | Output suppressed because no_log was given
2025-10-09 10:37:00.346344 | 
2025-10-09 10:37:00.346447 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-09 10:37:00.576234 | controller | changed: "logs"
2025-10-09 10:37:00.762380 | controller | changed: "artifacts"
2025-10-09 10:37:01.000269 | controller | changed: "docs"
2025-10-09 10:37:01.018009 | 
2025-10-09 10:37:01.018151 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-09 10:37:01.309170 | controller | changed: "logs"
2025-10-09 10:37:01.309592 | controller | changed: All items complete
2025-10-09 10:37:01.309652 | 
2025-10-09 10:37:01.519839 | controller | changed: "artifacts"
2025-10-09 10:37:01.720184 | controller | changed: "docs"
2025-10-09 10:37:01.751665 | 
2025-10-09 10:37:01.751954 | TASK [Check if worker can sudo]
2025-10-09 10:37:02.306876 | controller | ok: Runtime: 0:00:00.036157
2025-10-09 10:37:02.313379 | 
2025-10-09 10:37:02.313499 | TASK [configure-mirrors : Gather needed facts]
2025-10-09 10:37:02.389414 | controller | skipping: Conditional result was False
2025-10-09 10:37:02.399009 | 
2025-10-09 10:37:02.399155 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-09 10:37:02.474437 | controller | ok
2025-10-09 10:37:02.485810 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-09 10:37:02.494408 | 
2025-10-09 10:37:02.494519 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-09 10:37:02.781279 | controller | ok
2025-10-09 10:37:02.837963 | 
2025-10-09 10:37:02.838113 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-09 10:37:02.949169 | controller | ok: "/var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-09 10:37:02.967802 | 
2025-10-09 10:37:02.968074 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-09 10:37:03.881578 | controller | changed
2025-10-09 10:37:03.896259 | 
2025-10-09 10:37:03.896412 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-09 10:37:03.948097 | controller | ok: "/var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-09 10:37:03.948302 | controller | ok: All items complete
2025-10-09 10:37:03.948328 | 
2025-10-09 10:37:04.022304 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-09 10:37:04.028906 | 
2025-10-09 10:37:04.028976 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-09 10:37:04.881923 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-09 10:37:05.636202 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-09 10:37:05.656187 | 
2025-10-09 10:37:05.656335 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-09 10:37:06.112313 | controller | changed: section and option added
2025-10-09 10:37:06.148586 | 
2025-10-09 10:37:06.148700 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-09 10:37:06.700766 | controller | 29 files removed
2025-10-09 10:37:06.701292 | controller | ok: Item: dnf clean all Runtime: 0:00:00.231459
2025-10-09 10:37:06.701411 | controller | changed: All items complete
2025-10-09 10:37:06.701469 | 
2025-10-09 10:37:17.334697 | 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-09 10:37:17.334820 | controller | DNF version: 4.14.0
2025-10-09 10:37:17.334845 | controller | cachedir: /var/cache/dnf
2025-10-09 10:37:17.334866 | controller | Making cache files for all metadata files.
2025-10-09 10:37:17.334885 | controller | baseos: has expired and will be refreshed.
2025-10-09 10:37:17.334903 | controller | appstream: has expired and will be refreshed.
2025-10-09 10:37:17.334920 | controller | crb: has expired and will be refreshed.
2025-10-09 10:37:17.334947 | controller | extras-common: has expired and will be refreshed.
2025-10-09 10:37:17.334965 | controller | repo: downloading from remote: baseos
2025-10-09 10:37:17.334983 | controller | CentOS Stream 9 - BaseOS                         65 MB/s | 8.8 MB     00:00
2025-10-09 10:37:17.335000 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-09 10:37:17.335017 | controller | repo: downloading from remote: appstream
2025-10-09 10:37:17.335034 | controller | CentOS Stream 9 - AppStream                      69 MB/s |  25 MB     00:00
2025-10-09 10:37:17.335051 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-09 10:37:17.335068 | controller | repo: downloading from remote: crb
2025-10-09 10:37:17.335085 | controller | CentOS Stream 9 - CRB                            43 MB/s | 7.2 MB     00:00
2025-10-09 10:37:17.335103 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-09 10:37:17.335120 | controller | repo: downloading from remote: extras-common
2025-10-09 10:37:17.335137 | controller | CentOS Stream 9 - Extras packages               912 kB/s |  20 kB     00:00
2025-10-09 10:37:17.335154 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-09 10:37:17.335172 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-09 10:37:17.335189 | controller | Completion plugin: Generating completion cache...
2025-10-09 10:37:17.335206 | controller | Metadata cache created.
2025-10-09 10:37:17.335232 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.372582
2025-10-09 10:37:17.350324 | 
2025-10-09 10:37:17.350404 | PLAY RECAP
2025-10-09 10:37:17.350445 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-09 10:37:17.350472 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-09 10:37:17.350493 | 
2025-10-09 10:37:17.465879 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-09 10:37:17.466682 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-09 10:37:18.082602 | 
2025-10-09 10:37:18.082788 | PLAY [all]
2025-10-09 10:37:18.109132 | 
2025-10-09 10:37:18.109228 | TASK [Install binary dependencies]
2025-10-09 10:37:18.159145 | controller | ok
2025-10-09 10:37:18.178306 | 
2025-10-09 10:37:18.178405 | TASK [bindep : Include find tasks]
2025-10-09 10:37:18.207614 | controller | ok
2025-10-09 10:37:18.215171 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-09 10:37:18.221369 | 
2025-10-09 10:37:18.221434 | TASK [bindep : Look for bindep.txt]
2025-10-09 10:37:18.583052 | controller | ok
2025-10-09 10:37:18.592085 | 
2025-10-09 10:37:18.592181 | TASK [bindep : Define bindep_file fact]
2025-10-09 10:37:18.639206 | controller | ok
2025-10-09 10:37:18.649546 | 
2025-10-09 10:37:18.649772 | TASK [bindep : Look for other-requirements.txt]
2025-10-09 10:37:18.677016 | controller | skipping: Conditional result was False
2025-10-09 10:37:18.686259 | 
2025-10-09 10:37:18.686374 | TASK [bindep : Define bindep_file fact]
2025-10-09 10:37:18.723266 | controller | skipping: Conditional result was False
2025-10-09 10:37:18.737336 | 
2025-10-09 10:37:18.737606 | TASK [bindep : Look for bindep fallback file]
2025-10-09 10:37:18.774340 | controller | skipping: Conditional result was False
2025-10-09 10:37:18.783644 | 
2025-10-09 10:37:18.783765 | TASK [bindep : Define bindep_file fact]
2025-10-09 10:37:18.819284 | controller | skipping: Conditional result was False
2025-10-09 10:37:18.829788 | 
2025-10-09 10:37:18.829959 | TASK [bindep : Include bindep tasks]
2025-10-09 10:37:18.874858 | controller | ok
2025-10-09 10:37:18.883962 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-09 10:37:18.895349 | 
2025-10-09 10:37:18.895495 | TASK [bindep : Look for bindep command]
2025-10-09 10:37:18.930851 | controller | skipping: Conditional result was False
2025-10-09 10:37:18.944641 | 
2025-10-09 10:37:18.944836 | TASK [bindep : Check for system bindep]
2025-10-09 10:37:19.487697 | controller | ok: Runtime: 0:00:00.008797
2025-10-09 10:37:19.500642 | 
2025-10-09 10:37:19.500856 | TASK [bindep : Define bindep_command fact]
2025-10-09 10:37:19.538807 | controller | skipping: Conditional result was False
2025-10-09 10:37:19.552247 | 
2025-10-09 10:37:19.552399 | TASK [bindep : Include install tasks]
2025-10-09 10:37:19.603137 | controller | ok
2025-10-09 10:37:19.619168 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-09 10:37:19.632337 | 
2025-10-09 10:37:19.632431 | TASK [bindep : Create temp dir for bindep]
2025-10-09 10:37:19.985622 | controller | changed
2025-10-09 10:37:19.998036 | 
2025-10-09 10:37:19.998216 | TASK [Ensure we have pip dependencies]
2025-10-09 10:37:20.029547 | controller | ok
2025-10-09 10:37:20.072213 | 
2025-10-09 10:37:20.072362 | TASK [ensure-pip : Check if pip is installed]
2025-10-09 06:37:20.324430 | controller | /usr/bin/pip3
2025-10-09 06:37:20.344436 | controller | /usr/bin/python3: No module named wheel
2025-10-09 10:37:20.606947 | controller | ok: Runtime: 0:00:00.030236
2025-10-09 10:37:20.618933 | 
2025-10-09 10:37:20.619068 | LOOP [ensure-pip : Install pip from packages]
2025-10-09 10:37:20.668432 | controller | ok: "/var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-09 10:37:20.696288 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-09 10:37:20.730532 | 
2025-10-09 10:37:20.730690 | TASK [ensure-pip : Install Python 3 pip]
2025-10-09 10:37:22.979454 | controller | changed
2025-10-09 10:37:22.991810 | 
2025-10-09 10:37:22.992050 | TASK [ensure-pip : Check for EPEL repository]
2025-10-09 10:37:23.052287 | controller | skipping: Conditional result was False
2025-10-09 10:37:23.066840 | 
2025-10-09 10:37:23.066994 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-09 10:37:23.124959 | controller | skipping: Conditional result was False
2025-10-09 10:37:23.138705 | 
2025-10-09 10:37:23.138890 | TASK [ensure-pip : Install Python 2 pip]
2025-10-09 10:37:23.187248 | controller | skipping: Conditional result was False
2025-10-09 10:37:23.203472 | 
2025-10-09 10:37:23.203838 | TASK [ensure-pip : Ensure setuptools]
2025-10-09 10:37:23.231598 | controller | skipping: Conditional result was False
2025-10-09 10:37:23.246011 | 
2025-10-09 10:37:23.246202 | TASK [ensure-pip : Check for ensurepip module]
2025-10-09 10:37:23.794588 | controller | skipping: Conditional result was False
2025-10-09 10:37:23.809136 | 
2025-10-09 10:37:23.809277 | TASK [ensure-pip : Ensure python3-venv]
2025-10-09 10:37:23.836528 | controller | skipping: Conditional result was False
2025-10-09 10:37:23.850357 | 
2025-10-09 10:37:23.850490 | TASK [ensure-pip : Install pip from source]
2025-10-09 10:37:23.877357 | controller | skipping: Conditional result was False
2025-10-09 10:37:23.890166 | 
2025-10-09 10:37:23.890389 | TASK [ensure-pip : Probe for venv python full path]
2025-10-09 06:37:24.213780 | controller | /usr/bin/python3
2025-10-09 10:37:24.443882 | controller | ok: Runtime: 0:00:00.005390
2025-10-09 10:37:24.457046 | 
2025-10-09 10:37:24.457188 | TASK [ensure-pip : Set host default]
2025-10-09 10:37:24.533454 | controller | ok
2025-10-09 10:37:24.540772 | 
2025-10-09 10:37:24.540860 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-09 10:37:24.596093 | controller | ok
2025-10-09 10:37:24.610450 | 
2025-10-09 10:37:24.610536 | TASK [bindep : Install bindep into temporary venv]
2025-10-09 10:37:28.916051 | controller | changed
2025-10-09 10:37:28.928778 | 
2025-10-09 10:37:28.928930 | TASK [bindep : Define bindep_command]
2025-10-09 10:37:28.969934 | controller | ok
2025-10-09 10:37:28.980677 | 
2025-10-09 10:37:28.980840 | LOOP [bindep : Include package tasks]
2025-10-09 10:37:29.054783 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-09 10:37:29.055067 | controller | ok: All items complete
2025-10-09 10:37:29.055124 | 
2025-10-09 10:37:29.074262 | controller | included: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-09 10:37:29.089163 | 
2025-10-09 10:37:29.089295 | TASK [bindep : Define bindep_run fact]
2025-10-09 10:37:29.131321 | controller | ok
2025-10-09 10:37:29.138693 | 
2025-10-09 10:37:29.138808 | TASK [bindep : Get list of packages to install from bindep]
2025-10-09 06:37:30.710465 | controller | podman
2025-10-09 06:37:30.747560 | controller | python3-jmespath
2025-10-09 06:37:30.747598 | controller | python3-libvirt
2025-10-09 06:37:30.747605 | controller | python3-lxml
2025-10-09 06:37:30.747613 | controller | python3-netaddr
2025-10-09 10:37:31.181464 | controller | ok: Runtime: 0:00:01.290001
2025-10-09 10:37:31.189326 | 
2025-10-09 10:37:31.189417 | TASK [bindep : Install distro packages from bindep]
2025-10-09 10:38:33.308168 | controller | changed
2025-10-09 10:38:33.321791 | 
2025-10-09 10:38:33.321968 | TASK [bindep : Check that packages are installed]
2025-10-09 10:38:34.870445 | controller | ok: Runtime: 0:00:01.110482
2025-10-09 10:38:34.877427 | 
2025-10-09 10:38:34.877532 | TASK [bindep : Fail if we cannot install all packages]
2025-10-09 10:38:34.912966 | controller | skipping: Conditional result was False
2025-10-09 10:38:34.941830 | 
2025-10-09 10:38:34.942046 | TASK [Run test-setup role]
2025-10-09 10:38:34.965969 | controller | ok
2025-10-09 10:38:34.990332 | 
2025-10-09 10:38:34.990472 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-09 10:38:35.238959 | controller | ok
2025-10-09 10:38:35.246449 | 
2025-10-09 10:38:35.246535 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-09 10:38:35.786372 | controller | skipping: Conditional result was False
2025-10-09 10:38:35.833590 | 
2025-10-09 10:38:35.833785 | TASK [bindep : Remove bindep temp dir]
2025-10-09 10:38:36.262308 | controller | ok
2025-10-09 10:38:36.287887 | 
2025-10-09 10:38:36.288046 | PLAY RECAP
2025-10-09 10:38:36.288163 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-09 10:38:36.288231 | 
2025-10-09 10:38:36.420335 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-09 10:38:36.421236 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-09 10:38:37.049090 | 
2025-10-09 10:38:37.049228 | PLAY [all]
2025-10-09 10:38:37.070130 | 
2025-10-09 10:38:37.070268 | TASK [Abort when test_command variable is undefined]
2025-10-09 10:38:37.095571 | controller | skipping: Conditional result was False
2025-10-09 10:38:37.102698 | 
2025-10-09 10:38:37.102811 | TASK [Convert test_command to list]
2025-10-09 10:38:37.138653 | controller | skipping: Conditional result was False
2025-10-09 10:38:37.147505 | 
2025-10-09 10:38:37.147601 | TASK [Use test_command list]
2025-10-09 10:38:37.203391 | controller | ok
2025-10-09 10:38:37.214636 | 
2025-10-09 10:38:37.214802 | LOOP [Run test_command]
2025-10-09 10:38:37.629636 | controller | no check to run
2025-10-09 10:38:37.630001 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006665
2025-10-09 10:38:37.661819 | 
2025-10-09 10:38:37.661936 | PLAY RECAP
2025-10-09 10:38:37.661988 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-09 10:38:37.662018 | 
2025-10-09 10:38:37.780673 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-09 10:38:37.781843 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-09 10:38:38.352944 | 
2025-10-09 10:38:38.353063 | PLAY [all]
2025-10-09 10:38:38.374623 | 
2025-10-09 10:38:38.374763 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-09 10:38:38.702243 | controller | changed: non-zero return code
2025-10-09 10:38:38.708188 | 
2025-10-09 10:38:38.708274 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-09 10:38:38.732785 | controller | skipping: Conditional result was False
2025-10-09 10:38:38.740019 | 
2025-10-09 10:38:38.740108 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-09 10:38:38.771821 | 
2025-10-09 10:38:38.771986 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-09 10:38:38.804466 | 
2025-10-09 10:38:38.804825 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-09 10:38:38.832152 | controller | skipping: Conditional result was False
2025-10-09 10:38:38.840517 | 
2025-10-09 10:38:38.840611 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-09 10:38:38.873127 | 
2025-10-09 10:38:38.873317 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-09 10:38:38.901251 | controller | skipping: Conditional result was False
2025-10-09 10:38:38.912711 | 
2025-10-09 10:38:38.912992 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-09 10:38:38.931319 | controller | skipping: Conditional result was False
2025-10-09 10:38:38.944706 | 
2025-10-09 10:38:38.945011 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-09 10:38:38.962242 | controller | skipping: Conditional result was False
2025-10-09 10:38:38.996417 | 
2025-10-09 10:38:38.996542 | PLAY RECAP
2025-10-09 10:38:38.996599 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-09 10:38:38.996628 | 
2025-10-09 10:38:39.106620 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-09 10:38:39.107701 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-09 10:38:39.722667 | 
2025-10-09 10:38:39.722804 | PLAY [all]
2025-10-09 10:38:39.742041 | 
2025-10-09 10:38:39.742129 | TASK [include_role : fetch-output]
2025-10-09 10:38:39.791066 | controller | ok
2025-10-09 10:38:39.808608 | 
2025-10-09 10:38:39.808765 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-09 10:38:39.874402 | controller | skipping: Conditional result was False
2025-10-09 10:38:39.882061 | 
2025-10-09 10:38:39.882171 | TASK [fetch-output : Set log path for single node]
2025-10-09 10:38:39.918706 | controller | ok
2025-10-09 10:38:39.930006 | 
2025-10-09 10:38:39.930147 | LOOP [fetch-output : Ensure local output dirs]
2025-10-09 10:38:40.361796 | controller -> localhost | ok: "/var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/logs"
2025-10-09 10:38:40.647909 | controller -> localhost | changed: "/var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/artifacts"
2025-10-09 10:38:40.881097 | controller -> localhost | changed: "/var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/docs"
2025-10-09 10:38:40.893937 | 
2025-10-09 10:38:40.894017 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-09 10:38:41.582896 | controller | changed: .d..t...... ./
2025-10-09 10:38:41.583240 | controller | changed: All items complete
2025-10-09 10:38:41.583299 | 
2025-10-09 10:38:42.108751 | controller | changed: .d..t...... ./
2025-10-09 10:38:42.618015 | controller | changed: .d..t...... ./
2025-10-09 10:38:42.648588 | 
2025-10-09 10:38:42.648826 | TASK [include_role : fetch-output-openshift]
2025-10-09 10:38:42.675893 | controller | skipping: Conditional result was False
2025-10-09 10:38:42.689251 | 
2025-10-09 10:38:42.689402 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-09 10:38:43.201059 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.026329
2025-10-09 10:38:43.478409 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014205
2025-10-09 10:38:43.507470 | 
2025-10-09 10:38:43.507622 | PLAY [all]
2025-10-09 10:38:43.525079 | 
2025-10-09 10:38:43.525214 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-09 10:38:43.967271 | controller | changed
2025-10-09 10:38:43.999924 | 
2025-10-09 10:38:44.000042 | PLAY RECAP
2025-10-09 10:38:44.000098 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-09 10:38:44.000126 | 
2025-10-09 10:38:44.148184 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-09 10:38:44.149078 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-09 10:38:44.776999 | 
2025-10-09 10:38:44.777116 | PLAY [localhost]
2025-10-09 10:38:44.797386 | 
2025-10-09 10:38:44.797539 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-09 10:38:45.177432 | localhost | changed
2025-10-09 10:38:45.185552 | 
2025-10-09 10:38:45.185708 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-09 10:38:45.223169 | localhost | ok
2025-10-09 10:38:45.231231 | 
2025-10-09 10:38:45.231300 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-09 10:38:45.595322 | localhost | changed
2025-10-09 10:38:45.600295 | 
2025-10-09 10:38:45.600365 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-09 10:38:46.423093 | localhost | changed
2025-10-09 10:38:46.434747 | 
2025-10-09 10:38:46.434943 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-09 10:38:46.888863 | localhost | Identity added: /var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/tmp/ansible.yp7vmtor (/var/lib/zuul/builds/6c0ebd95a047455d8205adcf1c1bedcd/work/tmp/ansible.yp7vmtor)
2025-10-09 10:38:46.889111 | localhost | ok: Runtime: 0:00:00.013453
2025-10-09 10:38:46.895710 | 
2025-10-09 10:38:46.895827 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-09 10:38:47.184312 | localhost | ok: Runtime: 0:00:00.008630
2025-10-09 10:38:47.194538 | 
2025-10-09 10:38:47.194687 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-09 10:38:47.274220 | localhost | changed
2025-10-09 10:38:47.283545 | 
2025-10-09 10:38:47.283712 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-09 10:38:47.742221 | localhost | changed
2025-10-09 10:38:47.775572 | 
2025-10-09 10:38:47.775676 | PLAY [localhost]
2025-10-09 10:38:47.790048 | 
2025-10-09 10:38:47.790135 | TASK [Generate bulk log download script]
2025-10-09 10:38:47.819411 | localhost | ok
2025-10-09 10:38:47.831996 | 
2025-10-09 10:38:47.832064 | TASK [local-log-download : Check API endpoint is defined]
2025-10-09 10:38:47.882505 | localhost | ok: All assertions passed
2025-10-09 10:38:47.887203 | 
2025-10-09 10:38:47.887266 | TASK [local-log-download : Create download script]
2025-10-09 10:38:48.351884 | localhost -> localhost | changed
2025-10-09 10:38:48.360802 | 
2025-10-09 10:38:48.360871 | TASK [Register quick-download link]
2025-10-09 10:38:48.388820 | localhost | ok
2025-10-09 10:38:48.431919 | 
2025-10-09 10:38:48.432020 | PLAY [logserver.rdoproject.org]
2025-10-09 10:38:48.441868 | 
2025-10-09 10:38:48.441935 | TASK [Set zuul-log-path fact]
2025-10-09 10:38:48.458372 | logserver.rdoproject.org | ok
2025-10-09 10:38:48.467285 | 
2025-10-09 10:38:48.467349 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-09 10:38:48.493642 | logserver.rdoproject.org | ok
2025-10-09 10:38:48.498868 | 
2025-10-09 10:38:48.498930 | TASK [upload-logs : Create log directories]
2025-10-09 10:38:49.607561 | logserver.rdoproject.org | changed
2025-10-09 10:38:49.616019 | 
2025-10-09 10:38:49.616182 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-09 10:38:50.004444 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009513
2025-10-09 10:38:50.014290 | 
2025-10-09 10:38:50.014458 | TASK [upload-logs : Upload logs to log server]
2025-10-09 10:38:50.805043 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-09 10:38:50.807924 | 
2025-10-09 10:38:50.807989 | LOOP [upload-logs : Compress console log and json output]
2025-10-09 10:38:50.875169 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-09 10:38:50.887212 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-09 10:38:50.901433 | 
2025-10-09 10:38:50.901688 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-09 10:38:50.968175 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-09 10:38:50.968606 | 
2025-10-09 10:38:50.974564 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-09 10:38:50.987662 | 
2025-10-09 10:38:50.987874 | LOOP [upload-logs : Upload console log and json output]