2025-10-13 15:48:32.698137 | Job console starting...
2025-10-13 15:48:32.707683 | Updating repositories
2025-10-13 15:48:32.744497 | Preparing job workspace
2025-10-13 15:48:38.451224 | Running Ansible setup...
2025-10-13 15:48:42.419931 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 15:48:43.028290 | 
2025-10-13 15:48:43.028413 | PLAY [localhost]
2025-10-13 15:48:43.037439 | 
2025-10-13 15:48:43.037508 | TASK [Gathering Facts]
2025-10-13 15:48:44.003214 | localhost | ok
2025-10-13 15:48:44.020058 | 
2025-10-13 15:48:44.020192 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 15:48:44.523065 | localhost -> localhost | changed
2025-10-13 15:48:44.528756 | 
2025-10-13 15:48:44.528879 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 15:48:45.466996 | localhost -> localhost | changed
2025-10-13 15:48:45.477349 | 
2025-10-13 15:48:45.477481 | TASK [Setup log path fact]
2025-10-13 15:48:45.496565 | localhost | ok
2025-10-13 15:48:45.510157 | 
2025-10-13 15:48:45.510404 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 15:48:45.539709 | localhost | ok
2025-10-13 15:48:45.548748 | 
2025-10-13 15:48:45.548895 | TASK [emit-job-header : Print job information]
2025-10-13 15:48:45.586272 | # Job Information
2025-10-13 15:48:45.586968 | Ansible Version: 2.15.12
2025-10-13 15:48:45.587000 | Job: cifmw-molecule-cleanup_openstack
2025-10-13 15:48:45.587179 | Pipeline: github-check
2025-10-13 15:48:45.587201 | Executor: ze01.softwarefactory-project.io
2025-10-13 15:48:45.587219 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402
2025-10-13 15:48:45.587257 | Log URL (when completed): https://logserver.rdoproject.org/ae1/rdoproject.org/ae1c88a5982f458a89edfc9dfb57d0dd/
2025-10-13 15:48:45.587277 | Event ID: c72aa640-a84b-11f0-9b71-9348e6553136
2025-10-13 15:48:45.592568 | 
2025-10-13 15:48:45.592680 | LOOP [emit-job-header : Print node information]
2025-10-13 15:48:45.701184 | localhost | ok:
2025-10-13 15:48:45.701411 | localhost | # Node Information
2025-10-13 15:48:45.701438 | localhost | Inventory Hostname: controller
2025-10-13 15:48:45.701460 | localhost | Hostname: np0005485545
2025-10-13 15:48:45.701480 | localhost | Username: zuul
2025-10-13 15:48:45.701499 | localhost | Distro: CentOS 9
2025-10-13 15:48:45.701517 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 15:48:45.701534 | localhost | Region: RegionOne
2025-10-13 15:48:45.701550 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 15:48:45.701566 | localhost | Product Name: OpenStack Nova
2025-10-13 15:48:45.701583 | localhost | Interface IP: 38.102.83.190
2025-10-13 15:48:45.724364 | 
2025-10-13 15:48:45.724471 | PLAY [all]
2025-10-13 15:48:45.732860 | 
2025-10-13 15:48:45.733061 | TASK [Gather network facts]
2025-10-13 15:48:46.185178 | controller | ok
2025-10-13 15:48:46.208515 | 
2025-10-13 15:48:46.208637 | TASK [include_role : start-zuul-console]
2025-10-13 15:48:46.237542 | controller | ok
2025-10-13 15:48:46.250051 | 
2025-10-13 15:48:46.250178 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 15:48:46.675706 | controller | ok
2025-10-13 15:48:46.685452 | 
2025-10-13 15:48:46.685522 | TASK [include_role : add-build-sshkey]
2025-10-13 15:48:46.714576 | controller | ok
2025-10-13 15:48:46.729576 | 
2025-10-13 15:48:46.729662 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 15:48:47.002499 | controller -> localhost | ok
2025-10-13 15:48:47.009210 | 
2025-10-13 15:48:47.009276 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 15:48:47.042850 | controller | ok
2025-10-13 15:48:47.066124 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 15:48:47.072055 | 
2025-10-13 15:48:47.072116 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 15:48:48.294966 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 15:48:48.295173 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/ae1c88a5982f458a89edfc9dfb57d0dd_id_rsa.
2025-10-13 15:48:48.295204 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/ae1c88a5982f458a89edfc9dfb57d0dd_id_rsa.pub.
2025-10-13 15:48:48.295226 | controller -> localhost | The key fingerprint is:
2025-10-13 15:48:48.295245 | controller -> localhost | SHA256:lhXHYmHBIJLJNoX/DOcK3NWAWroUhWk5hsE6cRF17ks zuul-build-sshkey
2025-10-13 15:48:48.295264 | controller -> localhost | The key's randomart image is:
2025-10-13 15:48:48.295282 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 15:48:48.295299 | controller -> localhost | | .+BoX=..o=+.    |
2025-10-13 15:48:48.295316 | controller -> localhost | |. + /+o...+o.    |
2025-10-13 15:48:48.295334 | controller -> localhost | | + + O.  +..     |
2025-10-13 15:48:48.295352 | controller -> localhost | |o   +.o oo.      |
2025-10-13 15:48:48.295368 | controller -> localhost | | . o oEBS        |
2025-10-13 15:48:48.295385 | controller -> localhost | |    +..o+        |
2025-10-13 15:48:48.295402 | controller -> localhost | |     ...         |
2025-10-13 15:48:48.295421 | controller -> localhost | |      .          |
2025-10-13 15:48:48.295437 | controller -> localhost | |                 |
2025-10-13 15:48:48.295454 | controller -> localhost | +----[SHA256]-----+
2025-10-13 15:48:48.295499 | controller -> localhost | ok: Runtime: 0:00:00.337163
2025-10-13 15:48:48.301431 | 
2025-10-13 15:48:48.301499 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 15:48:48.332451 | controller | ok
2025-10-13 15:48:48.345963 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 15:48:48.355807 | 
2025-10-13 15:48:48.355935 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 15:48:48.390534 | controller | skipping: Conditional result was False
2025-10-13 15:48:48.397722 | 
2025-10-13 15:48:48.397845 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 15:48:48.918870 | controller | changed
2025-10-13 15:48:48.928365 | 
2025-10-13 15:48:48.928485 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 15:48:49.230666 | controller | ok
2025-10-13 15:48:49.239944 | 
2025-10-13 15:48:49.240092 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 15:48:50.093873 | controller | changed
2025-10-13 15:48:50.100948 | 
2025-10-13 15:48:50.101059 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 15:48:50.982886 | controller | changed
2025-10-13 15:48:50.988573 | 
2025-10-13 15:48:50.988672 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 15:48:51.003844 | controller | skipping: Conditional result was False
2025-10-13 15:48:51.011724 | 
2025-10-13 15:48:51.012057 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 15:48:51.444270 | controller -> localhost | changed
2025-10-13 15:48:51.454769 | 
2025-10-13 15:48:51.454883 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 15:48:51.754670 | controller -> localhost | Identity added: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/ae1c88a5982f458a89edfc9dfb57d0dd_id_rsa (zuul-build-sshkey)
2025-10-13 15:48:51.754879 | controller -> localhost | ok: Runtime: 0:00:00.011537
2025-10-13 15:48:51.761584 | 
2025-10-13 15:48:51.761696 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 15:48:52.171648 | controller | ok
2025-10-13 15:48:52.177187 | 
2025-10-13 15:48:52.177293 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 15:48:52.212616 | controller | skipping: Conditional result was False
2025-10-13 15:48:52.223376 | 
2025-10-13 15:48:52.223491 | TASK [include_role : validate-host]
2025-10-13 15:48:52.259426 | controller | ok
2025-10-13 15:48:52.287309 | 
2025-10-13 15:48:52.287445 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 15:48:52.317099 | controller | ok
2025-10-13 15:48:52.322385 | 
2025-10-13 15:48:52.322496 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 15:48:52.613948 | controller -> localhost | ok
2025-10-13 15:48:52.659996 | 
2025-10-13 15:48:52.660137 | TASK [validate-host : Collect information about the host]
2025-10-13 15:48:53.437388 | controller | ok
2025-10-13 15:48:53.457359 | 
2025-10-13 15:48:53.457509 | TASK [validate-host : Sanitize hostname]
2025-10-13 15:48:53.533256 | controller | ok
2025-10-13 15:48:53.542651 | 
2025-10-13 15:48:53.542797 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 15:48:54.002404 | controller -> localhost | changed
2025-10-13 15:48:54.007865 | 
2025-10-13 15:48:54.007930 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 15:48:54.407810 | controller | ok
2025-10-13 15:48:54.413280 | 
2025-10-13 15:48:54.413367 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 15:48:54.899702 | controller -> localhost | changed
2025-10-13 15:48:54.909524 | 
2025-10-13 15:48:54.909606 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 15:48:54.923988 | controller | skipping: Conditional result was False
2025-10-13 15:48:54.930667 | 
2025-10-13 15:48:54.930770 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 15:48:54.947729 | controller | skipping: Conditional result was False
2025-10-13 15:48:54.954423 | 
2025-10-13 15:48:54.954522 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 15:48:55.204593 | controller | ok: "logs"
2025-10-13 15:48:55.204824 | controller | ok: All items complete
2025-10-13 15:48:55.204857 | 
2025-10-13 15:48:55.417504 | controller | ok: "artifacts"
2025-10-13 15:48:55.645223 | controller | ok: "docs"
2025-10-13 15:48:55.664670 | 
2025-10-13 15:48:55.664861 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 15:48:55.948370 | controller | changed: "logs"
2025-10-13 15:48:56.215830 | controller | changed: "artifacts"
2025-10-13 15:48:56.492153 | controller | changed: "docs"
2025-10-13 15:48:56.522085 | 
2025-10-13 15:48:56.522191 | PLAY RECAP
2025-10-13 15:48:56.522232 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 15:48:56.522257 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 15:48:56.522274 | 
2025-10-13 15:48:56.647262 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 15:48:56.648069 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 15:48:57.306550 | 
2025-10-13 15:48:57.306676 | PLAY [localhost]
2025-10-13 15:48:57.326376 | 
2025-10-13 15:48:57.326490 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 15:48:57.768329 | localhost | ok
2025-10-13 15:48:57.777127 | 
2025-10-13 15:48:57.777220 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 15:48:58.502706 | localhost | changed
2025-10-13 15:48:58.529647 | 
2025-10-13 15:48:58.529804 | PLAY [all]
2025-10-13 15:48:58.563089 | 
2025-10-13 15:48:58.563200 | TASK [include_role : prepare-workspace]
2025-10-13 15:48:58.585302 | controller | ok
2025-10-13 15:48:58.603414 | 
2025-10-13 15:48:58.603538 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 15:48:59.011153 | controller | ok
2025-10-13 15:48:59.021122 | 
2025-10-13 15:48:59.021404 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 15:49:00.921817 | controller | Output suppressed because no_log was given
2025-10-13 15:49:00.932382 | 
2025-10-13 15:49:00.932468 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 15:49:01.235479 | controller | changed: "logs"
2025-10-13 15:49:01.491658 | controller | changed: "artifacts"
2025-10-13 15:49:01.759885 | controller | changed: "docs"
2025-10-13 15:49:01.770083 | 
2025-10-13 15:49:01.770227 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 15:49:02.049782 | controller | changed: "logs"
2025-10-13 15:49:02.050087 | controller | changed: All items complete
2025-10-13 15:49:02.050125 | 
2025-10-13 15:49:02.300764 | controller | changed: "artifacts"
2025-10-13 15:49:02.538463 | controller | changed: "docs"
2025-10-13 15:49:02.558741 | 
2025-10-13 15:49:02.558909 | TASK [Check if worker can sudo]
2025-10-13 15:49:03.094535 | controller | ok: Runtime: 0:00:00.044140
2025-10-13 15:49:03.103357 | 
2025-10-13 15:49:03.103468 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 15:49:03.202792 | controller | skipping: Conditional result was False
2025-10-13 15:49:03.209347 | 
2025-10-13 15:49:03.209476 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 15:49:03.270449 | controller | ok
2025-10-13 15:49:03.280352 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 15:49:03.319968 | 
2025-10-13 15:49:03.320115 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 15:49:03.617899 | controller | ok
2025-10-13 15:49:03.627076 | 
2025-10-13 15:49:03.627206 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 15:49:03.733132 | controller | ok: "/var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 15:49:03.746612 | 
2025-10-13 15:49:03.747128 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 15:49:04.674862 | controller | changed
2025-10-13 15:49:04.690264 | 
2025-10-13 15:49:04.690392 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 15:49:04.792110 | controller | ok: "/var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 15:49:04.792405 | controller | ok: All items complete
2025-10-13 15:49:04.792445 | 
2025-10-13 15:49:04.878805 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 15:49:04.886847 | 
2025-10-13 15:49:04.886974 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 15:49:05.863735 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 15:49:06.756672 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 15:49:06.776275 | 
2025-10-13 15:49:06.776416 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 15:49:07.267964 | controller | changed: section and option added
2025-10-13 15:49:07.311449 | 
2025-10-13 15:49:07.311604 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 15:49:08.178885 | controller | 29 files removed
2025-10-13 15:49:08.179159 | controller | ok: Item: dnf clean all Runtime: 0:00:00.535151
2025-10-13 15:49:08.179218 | controller | changed: All items complete
2025-10-13 15:49:08.179247 | 
2025-10-13 15:49:19.369886 | 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-13 15:49:19.370057 | controller | DNF version: 4.14.0
2025-10-13 15:49:19.370122 | controller | cachedir: /var/cache/dnf
2025-10-13 15:49:19.370170 | controller | Making cache files for all metadata files.
2025-10-13 15:49:19.370222 | controller | baseos: has expired and will be refreshed.
2025-10-13 15:49:19.370269 | controller | appstream: has expired and will be refreshed.
2025-10-13 15:49:19.370318 | controller | crb: has expired and will be refreshed.
2025-10-13 15:49:19.370378 | controller | extras-common: has expired and will be refreshed.
2025-10-13 15:49:19.370419 | controller | repo: downloading from remote: baseos
2025-10-13 15:49:19.370458 | controller | CentOS Stream 9 - BaseOS                         65 MB/s | 8.8 MB     00:00
2025-10-13 15:49:19.370496 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 15:49:19.370533 | controller | repo: downloading from remote: appstream
2025-10-13 15:49:19.370570 | controller | CentOS Stream 9 - AppStream                      96 MB/s |  25 MB     00:00
2025-10-13 15:49:19.370606 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 15:49:19.370642 | controller | repo: downloading from remote: crb
2025-10-13 15:49:19.370678 | controller | CentOS Stream 9 - CRB                            26 MB/s | 7.2 MB     00:00
2025-10-13 15:49:19.370715 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 15:49:19.370751 | controller | repo: downloading from remote: extras-common
2025-10-13 15:49:19.370794 | controller | CentOS Stream 9 - Extras packages               1.5 MB/s |  20 kB     00:00
2025-10-13 15:49:19.370845 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 15:49:19.370893 | controller | Last metadata expiration check: 0:00:01 ago on Mon 13 Oct 2025 11:49:17 AM EDT.
2025-10-13 15:49:19.370943 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 15:49:19.370985 | controller | Completion plugin: Generating completion cache...
2025-10-13 15:49:19.371064 | controller | Metadata cache created.
2025-10-13 15:49:19.371129 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.924323
2025-10-13 15:49:19.401822 | 
2025-10-13 15:49:19.401936 | PLAY RECAP
2025-10-13 15:49:19.401990 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 15:49:19.402102 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 15:49:19.402140 | 
2025-10-13 15:49:19.531733 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 15:49:19.532554 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 15:49:20.117153 | 
2025-10-13 15:49:20.117271 | PLAY [all]
2025-10-13 15:49:20.139064 | 
2025-10-13 15:49:20.139169 | TASK [Install binary dependencies]
2025-10-13 15:49:20.210422 | controller | ok
2025-10-13 15:49:20.229281 | 
2025-10-13 15:49:20.229388 | TASK [bindep : Include find tasks]
2025-10-13 15:49:20.258236 | controller | ok
2025-10-13 15:49:20.265610 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 15:49:20.271444 | 
2025-10-13 15:49:20.271505 | TASK [bindep : Look for bindep.txt]
2025-10-13 15:49:20.693307 | controller | ok
2025-10-13 15:49:20.708175 | 
2025-10-13 15:49:20.708348 | TASK [bindep : Define bindep_file fact]
2025-10-13 15:49:20.744939 | controller | ok
2025-10-13 15:49:20.752795 | 
2025-10-13 15:49:20.753107 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 15:49:20.778881 | controller | skipping: Conditional result was False
2025-10-13 15:49:20.787369 | 
2025-10-13 15:49:20.787480 | TASK [bindep : Define bindep_file fact]
2025-10-13 15:49:20.813070 | controller | skipping: Conditional result was False
2025-10-13 15:49:20.821739 | 
2025-10-13 15:49:20.821844 | TASK [bindep : Look for bindep fallback file]
2025-10-13 15:49:20.847433 | controller | skipping: Conditional result was False
2025-10-13 15:49:20.855855 | 
2025-10-13 15:49:20.855960 | TASK [bindep : Define bindep_file fact]
2025-10-13 15:49:20.881293 | controller | skipping: Conditional result was False
2025-10-13 15:49:20.891638 | 
2025-10-13 15:49:20.891760 | TASK [bindep : Include bindep tasks]
2025-10-13 15:49:20.924830 | controller | ok
2025-10-13 15:49:20.934699 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 15:49:20.946891 | 
2025-10-13 15:49:20.946994 | TASK [bindep : Look for bindep command]
2025-10-13 15:49:20.972311 | controller | skipping: Conditional result was False
2025-10-13 15:49:20.981528 | 
2025-10-13 15:49:20.981630 | TASK [bindep : Check for system bindep]
2025-10-13 15:49:21.525840 | controller | ok: Runtime: 0:00:00.005364
2025-10-13 15:49:21.534247 | 
2025-10-13 15:49:21.534358 | TASK [bindep : Define bindep_command fact]
2025-10-13 15:49:21.562572 | controller | skipping: Conditional result was False
2025-10-13 15:49:21.568685 | 
2025-10-13 15:49:21.568757 | TASK [bindep : Include install tasks]
2025-10-13 15:49:21.598783 | controller | ok
2025-10-13 15:49:21.612224 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 15:49:21.621971 | 
2025-10-13 15:49:21.622106 | TASK [bindep : Create temp dir for bindep]
2025-10-13 15:49:22.041184 | controller | changed
2025-10-13 15:49:22.046610 | 
2025-10-13 15:49:22.046682 | TASK [Ensure we have pip dependencies]
2025-10-13 15:49:22.065549 | controller | ok
2025-10-13 15:49:22.089666 | 
2025-10-13 15:49:22.089937 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 11:49:22.372684 | controller | /usr/bin/pip3
2025-10-13 11:49:22.421477 | controller | /usr/bin/python3: No module named wheel
2025-10-13 15:49:22.627529 | controller | ok: Runtime: 0:00:00.063691
2025-10-13 15:49:22.635973 | 
2025-10-13 15:49:22.636110 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 15:49:22.669415 | controller | ok: "/var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 15:49:22.680282 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 15:49:22.693182 | 
2025-10-13 15:49:22.693297 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 15:49:29.636460 | controller | changed
2025-10-13 15:49:29.654548 | 
2025-10-13 15:49:29.654689 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 15:49:29.710976 | controller | skipping: Conditional result was False
2025-10-13 15:49:29.722063 | 
2025-10-13 15:49:29.722215 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 15:49:29.780378 | controller | skipping: Conditional result was False
2025-10-13 15:49:29.795429 | 
2025-10-13 15:49:29.795590 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 15:49:29.837978 | controller | skipping: Conditional result was False
2025-10-13 15:49:29.860752 | 
2025-10-13 15:49:29.860965 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 15:49:29.909931 | controller | skipping: Conditional result was False
2025-10-13 15:49:29.922399 | 
2025-10-13 15:49:29.922510 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 15:49:30.454061 | controller | skipping: Conditional result was False
2025-10-13 15:49:30.467594 | 
2025-10-13 15:49:30.467817 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 15:49:30.507887 | controller | skipping: Conditional result was False
2025-10-13 15:49:30.521257 | 
2025-10-13 15:49:30.521439 | TASK [ensure-pip : Install pip from source]
2025-10-13 15:49:30.547991 | controller | skipping: Conditional result was False
2025-10-13 15:49:30.557244 | 
2025-10-13 15:49:30.557365 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 11:49:30.855708 | controller | /usr/bin/python3
2025-10-13 15:49:31.099501 | controller | ok: Runtime: 0:00:00.005161
2025-10-13 15:49:31.105309 | 
2025-10-13 15:49:31.105376 | TASK [ensure-pip : Set host default]
2025-10-13 15:49:31.164568 | controller | ok
2025-10-13 15:49:31.179535 | 
2025-10-13 15:49:31.179608 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 15:49:31.241407 | controller | ok
2025-10-13 15:49:31.250904 | 
2025-10-13 15:49:31.250974 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 15:49:36.016749 | controller | changed
2025-10-13 15:49:36.029651 | 
2025-10-13 15:49:36.029826 | TASK [bindep : Define bindep_command]
2025-10-13 15:49:36.060279 | controller | ok
2025-10-13 15:49:36.071884 | 
2025-10-13 15:49:36.072049 | LOOP [bindep : Include package tasks]
2025-10-13 15:49:36.134309 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 15:49:36.134587 | controller | ok: All items complete
2025-10-13 15:49:36.134620 | 
2025-10-13 15:49:36.160867 | controller | included: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 15:49:36.184892 | 
2025-10-13 15:49:36.185108 | TASK [bindep : Define bindep_run fact]
2025-10-13 15:49:36.218998 | controller | ok
2025-10-13 15:49:36.226830 | 
2025-10-13 15:49:36.226950 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 11:49:37.634164 | controller | podman
2025-10-13 11:49:37.666835 | controller | python3-jmespath
2025-10-13 11:49:37.667001 | controller | python3-libvirt
2025-10-13 11:49:37.667011 | controller | python3-lxml
2025-10-13 11:49:37.667042 | controller | python3-netaddr
2025-10-13 15:49:37.774228 | controller | ok: Runtime: 0:00:01.146364
2025-10-13 15:49:37.782554 | 
2025-10-13 15:49:37.782652 | TASK [bindep : Install distro packages from bindep]
2025-10-13 15:50:49.169135 | controller | changed
2025-10-13 15:50:49.174897 | 
2025-10-13 15:50:49.174978 | TASK [bindep : Check that packages are installed]
2025-10-13 15:50:51.221494 | controller | ok: Runtime: 0:00:01.722361
2025-10-13 15:50:51.242984 | 
2025-10-13 15:50:51.243150 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 15:50:51.269977 | controller | skipping: Conditional result was False
2025-10-13 15:50:51.286639 | 
2025-10-13 15:50:51.286779 | TASK [Run test-setup role]
2025-10-13 15:50:51.308858 | controller | ok
2025-10-13 15:50:51.326244 | 
2025-10-13 15:50:51.326378 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 15:50:51.580903 | controller | ok
2025-10-13 15:50:51.586406 | 
2025-10-13 15:50:51.586494 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 15:50:52.119620 | controller | skipping: Conditional result was False
2025-10-13 15:50:52.165237 | 
2025-10-13 15:50:52.165436 | TASK [bindep : Remove bindep temp dir]
2025-10-13 15:50:52.603958 | controller | ok
2025-10-13 15:50:52.627877 | 
2025-10-13 15:50:52.628078 | PLAY RECAP
2025-10-13 15:50:52.628178 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 15:50:52.628224 | 
2025-10-13 15:50:52.783581 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 15:50:52.784517 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 15:50:53.351608 | 
2025-10-13 15:50:53.351731 | PLAY [all]
2025-10-13 15:50:53.370926 | 
2025-10-13 15:50:53.371035 | TASK [Abort when test_command variable is undefined]
2025-10-13 15:50:53.405983 | controller | skipping: Conditional result was False
2025-10-13 15:50:53.412281 | 
2025-10-13 15:50:53.412356 | TASK [Convert test_command to list]
2025-10-13 15:50:53.465955 | controller | skipping: Conditional result was False
2025-10-13 15:50:53.472102 | 
2025-10-13 15:50:53.472172 | TASK [Use test_command list]
2025-10-13 15:50:53.522842 | controller | ok
2025-10-13 15:50:53.528692 | 
2025-10-13 15:50:53.528790 | LOOP [Run test_command]
2025-10-13 15:50:53.977585 | controller | no check to run
2025-10-13 15:50:53.977932 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008429
2025-10-13 15:50:54.016109 | 
2025-10-13 15:50:54.016304 | PLAY RECAP
2025-10-13 15:50:54.016357 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 15:50:54.016396 | 
2025-10-13 15:50:54.143768 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 15:50:54.144818 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 15:50:54.773416 | 
2025-10-13 15:50:54.773571 | PLAY [all]
2025-10-13 15:50:54.795726 | 
2025-10-13 15:50:54.795883 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 15:50:55.160402 | controller | changed: non-zero return code
2025-10-13 15:50:55.175504 | 
2025-10-13 15:50:55.175683 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 15:50:55.192519 | controller | skipping: Conditional result was False
2025-10-13 15:50:55.201394 | 
2025-10-13 15:50:55.201500 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 15:50:55.237108 | 
2025-10-13 15:50:55.237298 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 15:50:55.267882 | 
2025-10-13 15:50:55.268074 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 15:50:55.281786 | controller | skipping: Conditional result was False
2025-10-13 15:50:55.288605 | 
2025-10-13 15:50:55.288687 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 15:50:55.311701 | 
2025-10-13 15:50:55.311879 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 15:50:55.327404 | controller | skipping: Conditional result was False
2025-10-13 15:50:55.334631 | 
2025-10-13 15:50:55.334724 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 15:50:55.350524 | controller | skipping: Conditional result was False
2025-10-13 15:50:55.357335 | 
2025-10-13 15:50:55.357416 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 15:50:55.372601 | controller | skipping: Conditional result was False
2025-10-13 15:50:55.400136 | 
2025-10-13 15:50:55.400233 | PLAY RECAP
2025-10-13 15:50:55.400273 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 15:50:55.400293 | 
2025-10-13 15:50:55.497122 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 15:50:55.498087 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 15:50:56.113983 | 
2025-10-13 15:50:56.114178 | PLAY [all]
2025-10-13 15:50:56.134394 | 
2025-10-13 15:50:56.134544 | TASK [include_role : fetch-output]
2025-10-13 15:50:56.164741 | controller | ok
2025-10-13 15:50:56.183320 | 
2025-10-13 15:50:56.183476 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 15:50:56.238919 | controller | skipping: Conditional result was False
2025-10-13 15:50:56.245362 | 
2025-10-13 15:50:56.245482 | TASK [fetch-output : Set log path for single node]
2025-10-13 15:50:56.275222 | controller | ok
2025-10-13 15:50:56.280391 | 
2025-10-13 15:50:56.280482 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 15:50:56.671667 | controller -> localhost | ok: "/var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/logs"
2025-10-13 15:50:56.895250 | controller -> localhost | changed: "/var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/artifacts"
2025-10-13 15:50:57.109902 | controller -> localhost | changed: "/var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/docs"
2025-10-13 15:50:57.128006 | 
2025-10-13 15:50:57.128248 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 15:50:57.783032 | controller | changed: .d..t...... ./
2025-10-13 15:50:57.784524 | controller | changed: All items complete
2025-10-13 15:50:57.784584 | 
2025-10-13 15:50:58.329037 | controller | changed: .d..t...... ./
2025-10-13 15:50:58.803474 | controller | changed: .d..t...... ./
2025-10-13 15:50:58.825397 | 
2025-10-13 15:50:58.825612 | TASK [include_role : fetch-output-openshift]
2025-10-13 15:50:58.842129 | controller | skipping: Conditional result was False
2025-10-13 15:50:58.852121 | 
2025-10-13 15:50:58.852276 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 15:50:59.345513 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012532
2025-10-13 15:50:59.635177 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014206
2025-10-13 15:50:59.692970 | 
2025-10-13 15:50:59.693164 | PLAY [all]
2025-10-13 15:50:59.715058 | 
2025-10-13 15:50:59.715181 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 15:51:00.217586 | controller | changed
2025-10-13 15:51:00.254975 | 
2025-10-13 15:51:00.255107 | PLAY RECAP
2025-10-13 15:51:00.255166 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 15:51:00.255196 | 
2025-10-13 15:51:00.365358 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 15:51:00.367248 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 15:51:01.014697 | 
2025-10-13 15:51:01.014840 | PLAY [localhost]
2025-10-13 15:51:01.034718 | 
2025-10-13 15:51:01.034871 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 15:51:01.419785 | localhost | changed
2025-10-13 15:51:01.424843 | 
2025-10-13 15:51:01.424966 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 15:51:01.453681 | localhost | ok
2025-10-13 15:51:01.462248 | 
2025-10-13 15:51:01.462364 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 15:51:01.862952 | localhost | changed
2025-10-13 15:51:01.874116 | 
2025-10-13 15:51:01.874276 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 15:51:02.561568 | localhost | changed
2025-10-13 15:51:02.573872 | 
2025-10-13 15:51:02.574043 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 15:51:02.988602 | localhost | Identity added: /var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/tmp/ansible.a1ulji_r (/var/lib/zuul/builds/ae1c88a5982f458a89edfc9dfb57d0dd/work/tmp/ansible.a1ulji_r)
2025-10-13 15:51:02.988775 | localhost | ok: Runtime: 0:00:00.007569
2025-10-13 15:51:02.992988 | 
2025-10-13 15:51:02.993061 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 15:51:03.276992 | localhost | ok: Runtime: 0:00:00.022683
2025-10-13 15:51:03.282577 | 
2025-10-13 15:51:03.282649 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 15:51:03.343686 | localhost | changed
2025-10-13 15:51:03.350500 | 
2025-10-13 15:51:03.350617 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 15:51:03.727723 | localhost | changed
2025-10-13 15:51:03.749718 | 
2025-10-13 15:51:03.749836 | PLAY [localhost]
2025-10-13 15:51:03.762777 | 
2025-10-13 15:51:03.762874 | TASK [Generate bulk log download script]
2025-10-13 15:51:03.781069 | localhost | ok
2025-10-13 15:51:03.792699 | 
2025-10-13 15:51:03.792790 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 15:51:03.820712 | localhost | ok: All assertions passed
2025-10-13 15:51:03.825724 | 
2025-10-13 15:51:03.825825 | TASK [local-log-download : Create download script]
2025-10-13 15:51:04.226466 | localhost -> localhost | changed
2025-10-13 15:51:04.245837 | 
2025-10-13 15:51:04.246037 | TASK [Register quick-download link]
2025-10-13 15:51:04.268511 | localhost | ok
2025-10-13 15:51:04.318045 | 
2025-10-13 15:51:04.318156 | PLAY [logserver.rdoproject.org]
2025-10-13 15:51:04.327649 | 
2025-10-13 15:51:04.327731 | TASK [Set zuul-log-path fact]
2025-10-13 15:51:04.344178 | logserver.rdoproject.org | ok
2025-10-13 15:51:04.353153 | 
2025-10-13 15:51:04.353246 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 15:51:04.389985 | logserver.rdoproject.org | ok
2025-10-13 15:51:04.395511 | 
2025-10-13 15:51:04.395579 | TASK [upload-logs : Create log directories]
2025-10-13 15:51:05.111043 | logserver.rdoproject.org | changed
2025-10-13 15:51:05.119192 | 
2025-10-13 15:51:05.119419 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 15:51:05.457207 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008052
2025-10-13 15:51:05.462867 | 
2025-10-13 15:51:05.462970 | TASK [upload-logs : Upload logs to log server]
2025-10-13 15:51:06.158321 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 15:51:06.165405 | 
2025-10-13 15:51:06.165549 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 15:51:06.214071 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:51:06.224280 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:51:06.237761 | 
2025-10-13 15:51:06.237933 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 15:51:06.282888 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:51:06.283182 | 
2025-10-13 15:51:06.287466 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:51:06.299252 | 
2025-10-13 15:51:06.299435 | LOOP [upload-logs : Upload console log and json output]