2025-10-08 05:37:34.308837 | Job console starting...
2025-10-08 05:37:34.328208 | Updating repositories
2025-10-08 05:37:34.370696 | Preparing job workspace
2025-10-08 05:37:38.173411 | Running Ansible setup...
2025-10-08 05:37:42.280983 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 05:37:42.863706 | 
2025-10-08 05:37:42.863840 | PLAY [localhost]
2025-10-08 05:37:42.872368 | 
2025-10-08 05:37:42.872437 | TASK [Gathering Facts]
2025-10-08 05:37:43.881644 | localhost | ok
2025-10-08 05:37:43.917683 | 
2025-10-08 05:37:43.917825 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-08 05:37:44.319403 | localhost -> localhost | changed
2025-10-08 05:37:44.325238 | 
2025-10-08 05:37:44.325312 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-08 05:37:45.193552 | localhost -> localhost | changed
2025-10-08 05:37:45.202456 | 
2025-10-08 05:37:45.202540 | TASK [Setup log path fact]
2025-10-08 05:37:45.219678 | localhost | ok
2025-10-08 05:37:45.230946 | 
2025-10-08 05:37:45.231024 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 05:37:45.268204 | localhost | ok
2025-10-08 05:37:45.281420 | 
2025-10-08 05:37:45.281529 | TASK [emit-job-header : Print job information]
2025-10-08 05:37:45.320040 | # Job Information
2025-10-08 05:37:45.320188 | Ansible Version: 2.15.12
2025-10-08 05:37:45.320231 | Job: cifmw-molecule-federation
2025-10-08 05:37:45.320252 | Pipeline: github-check
2025-10-08 05:37:45.320278 | Executor: ze03.softwarefactory-project.io
2025-10-08 05:37:45.320295 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-08 05:37:45.320313 | Log URL (when completed): https://logserver.rdoproject.org/f7b/rdoproject.org/f7bc249a35014128aed776ca238f912f/
2025-10-08 05:37:45.320331 | Event ID: 920c7930-a408-11f0-96e0-244f77bacc6d
2025-10-08 05:37:45.324103 | 
2025-10-08 05:37:45.324167 | LOOP [emit-job-header : Print node information]
2025-10-08 05:37:45.434012 | localhost | ok:
2025-10-08 05:37:45.434176 | localhost | # Node Information
2025-10-08 05:37:45.434203 | localhost | Inventory Hostname: controller
2025-10-08 05:37:45.434226 | localhost | Hostname: np0005475255
2025-10-08 05:37:45.434245 | localhost | Username: zuul
2025-10-08 05:37:45.434266 | localhost | Distro: CentOS 9
2025-10-08 05:37:45.434284 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-08 05:37:45.434302 | localhost | Region: RegionOne
2025-10-08 05:37:45.434319 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-08 05:37:45.434336 | localhost | Product Name: OpenStack Nova
2025-10-08 05:37:45.434352 | localhost | Interface IP: 38.102.83.143
2025-10-08 05:37:45.461777 | 
2025-10-08 05:37:45.461957 | PLAY [all]
2025-10-08 05:37:45.468661 | 
2025-10-08 05:37:45.468845 | TASK [Gather network facts]
2025-10-08 05:37:45.946035 | controller | ok
2025-10-08 05:37:45.973689 | 
2025-10-08 05:37:45.973819 | TASK [include_role : start-zuul-console]
2025-10-08 05:37:45.995525 | controller | ok
2025-10-08 05:37:46.016355 | 
2025-10-08 05:37:46.016454 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-08 05:37:46.545340 | controller | ok
2025-10-08 05:37:46.563053 | 
2025-10-08 05:37:46.563144 | TASK [include_role : add-build-sshkey]
2025-10-08 05:37:46.582877 | controller | ok
2025-10-08 05:37:46.603688 | 
2025-10-08 05:37:46.603816 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-08 05:37:47.035845 | controller -> localhost | ok
2025-10-08 05:37:47.041270 | 
2025-10-08 05:37:47.041358 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-08 05:37:47.092829 | controller | ok
2025-10-08 05:37:47.135950 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-08 05:37:47.150293 | 
2025-10-08 05:37:47.150389 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-08 05:37:47.920162 | controller -> localhost | Generating public/private rsa key pair.
2025-10-08 05:37:47.920373 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/f7bc249a35014128aed776ca238f912f_id_rsa.
2025-10-08 05:37:47.920418 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/f7bc249a35014128aed776ca238f912f_id_rsa.pub.
2025-10-08 05:37:47.920442 | controller -> localhost | The key fingerprint is:
2025-10-08 05:37:47.920462 | controller -> localhost | SHA256:BRlnsCz4C5hxsGCgFqXeb4uCFvyHzUgDxgtwKCTxFVw zuul-build-sshkey
2025-10-08 05:37:47.920483 | controller -> localhost | The key's randomart image is:
2025-10-08 05:37:47.920502 | controller -> localhost | +---[RSA 3072]----+
2025-10-08 05:37:47.920520 | controller -> localhost | |B*ooooE ++o      |
2025-10-08 05:37:47.920538 | controller -> localhost | |Bo++.. ..=       |
2025-10-08 05:37:47.920556 | controller -> localhost | |=++ o . o .      |
2025-10-08 05:37:47.920574 | controller -> localhost | |++.= . . .       |
2025-10-08 05:37:47.920591 | controller -> localhost | |+.=.. . S        |
2025-10-08 05:37:47.920609 | controller -> localhost | | + o.. .         |
2025-10-08 05:37:47.920626 | controller -> localhost | |. + *o.          |
2025-10-08 05:37:47.920644 | controller -> localhost | |.o +o+.          |
2025-10-08 05:37:47.920661 | controller -> localhost | |. ....           |
2025-10-08 05:37:47.920678 | controller -> localhost | +----[SHA256]-----+
2025-10-08 05:37:47.920718 | controller -> localhost | ok: Runtime: 0:00:00.236135
2025-10-08 05:37:47.928695 | 
2025-10-08 05:37:47.928781 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-08 05:37:48.002303 | controller | ok
2025-10-08 05:37:48.031799 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-08 05:37:48.056848 | 
2025-10-08 05:37:48.056959 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-08 05:37:48.097547 | controller | skipping: Conditional result was False
2025-10-08 05:37:48.103206 | 
2025-10-08 05:37:48.103269 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-08 05:37:48.752423 | controller | changed
2025-10-08 05:37:48.757429 | 
2025-10-08 05:37:48.757489 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-08 05:37:49.051475 | controller | ok
2025-10-08 05:37:49.059739 | 
2025-10-08 05:37:49.059816 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-08 05:37:50.012262 | controller | changed
2025-10-08 05:37:50.017593 | 
2025-10-08 05:37:50.017657 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-08 05:37:50.861681 | controller | changed
2025-10-08 05:37:50.889084 | 
2025-10-08 05:37:50.889273 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-08 05:37:50.945988 | controller | skipping: Conditional result was False
2025-10-08 05:37:50.951818 | 
2025-10-08 05:37:50.951884 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-08 05:37:51.458810 | controller -> localhost | changed
2025-10-08 05:37:51.477429 | 
2025-10-08 05:37:51.477539 | TASK [add-build-sshkey : Add back temp key]
2025-10-08 05:37:51.823970 | controller -> localhost | Identity added: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/f7bc249a35014128aed776ca238f912f_id_rsa (zuul-build-sshkey)
2025-10-08 05:37:51.824248 | controller -> localhost | ok: Runtime: 0:00:00.012471
2025-10-08 05:37:51.834282 | 
2025-10-08 05:37:51.834392 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-08 05:37:52.257294 | controller | ok
2025-10-08 05:37:52.264720 | 
2025-10-08 05:37:52.264844 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-08 05:37:52.292757 | controller | skipping: Conditional result was False
2025-10-08 05:37:52.308350 | 
2025-10-08 05:37:52.308506 | TASK [include_role : validate-host]
2025-10-08 05:37:52.342179 | controller | ok
2025-10-08 05:37:52.379002 | 
2025-10-08 05:37:52.379136 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-08 05:37:52.409210 | controller | ok
2025-10-08 05:37:52.416428 | 
2025-10-08 05:37:52.416504 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-08 05:37:52.910487 | controller -> localhost | ok
2025-10-08 05:37:52.916392 | 
2025-10-08 05:37:52.916583 | TASK [validate-host : Collect information about the host]
2025-10-08 05:37:53.663063 | controller | ok
2025-10-08 05:37:53.672109 | 
2025-10-08 05:37:53.672180 | TASK [validate-host : Sanitize hostname]
2025-10-08 05:37:53.761279 | controller | ok
2025-10-08 05:37:53.768783 | 
2025-10-08 05:37:53.768855 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-08 05:37:54.410596 | controller -> localhost | changed
2025-10-08 05:37:54.418936 | 
2025-10-08 05:37:54.419003 | TASK [validate-host : Collect information about zuul worker]
2025-10-08 05:37:54.989843 | controller | ok
2025-10-08 05:37:54.997417 | 
2025-10-08 05:37:54.997536 | TASK [validate-host : Write out all zuul information for each host]
2025-10-08 05:37:55.414395 | controller -> localhost | changed
2025-10-08 05:37:55.423953 | 
2025-10-08 05:37:55.424024 | TASK [include_role : prepare-workspace-openshift]
2025-10-08 05:37:55.463930 | controller | skipping: Conditional result was False
2025-10-08 05:37:55.472011 | 
2025-10-08 05:37:55.472100 | TASK [include_role : remove-zuul-sshkey]
2025-10-08 05:37:55.496486 | controller | skipping: Conditional result was False
2025-10-08 05:37:55.506301 | 
2025-10-08 05:37:55.506405 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-08 05:37:55.799326 | controller | ok: "logs"
2025-10-08 05:37:55.799566 | controller | ok: All items complete
2025-10-08 05:37:55.799593 | 
2025-10-08 05:37:56.080377 | controller | ok: "artifacts"
2025-10-08 05:37:56.296151 | controller | ok: "docs"
2025-10-08 05:37:56.310652 | 
2025-10-08 05:37:56.310800 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-08 05:37:56.591675 | controller | changed: "logs"
2025-10-08 05:37:56.818290 | controller | changed: "artifacts"
2025-10-08 05:37:57.039190 | controller | changed: "docs"
2025-10-08 05:37:57.065881 | 
2025-10-08 05:37:57.065991 | PLAY RECAP
2025-10-08 05:37:57.066031 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 05:37:57.066057 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 05:37:57.066076 | 
2025-10-08 05:37:57.184721 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 05:37:57.185542 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-08 05:37:57.794808 | 
2025-10-08 05:37:57.794982 | PLAY [localhost]
2025-10-08 05:37:57.811944 | 
2025-10-08 05:37:57.812091 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-08 05:37:58.197858 | localhost | ok
2025-10-08 05:37:58.209950 | 
2025-10-08 05:37:58.210125 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-08 05:37:58.818704 | localhost | changed
2025-10-08 05:37:58.851128 | 
2025-10-08 05:37:58.851239 | PLAY [all]
2025-10-08 05:37:58.868264 | 
2025-10-08 05:37:58.868368 | TASK [include_role : prepare-workspace]
2025-10-08 05:37:58.897320 | controller | ok
2025-10-08 05:37:58.923871 | 
2025-10-08 05:37:58.924003 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-08 05:37:59.456414 | controller | ok
2025-10-08 05:37:59.468135 | 
2025-10-08 05:37:59.468203 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-08 05:38:01.536282 | controller | Output suppressed because no_log was given
2025-10-08 05:38:01.557763 | 
2025-10-08 05:38:01.557960 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-08 05:38:01.856562 | controller | changed: "logs"
2025-10-08 05:38:02.063550 | controller | changed: "artifacts"
2025-10-08 05:38:02.267047 | controller | changed: "docs"
2025-10-08 05:38:02.283160 | 
2025-10-08 05:38:02.283298 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-08 05:38:02.596662 | controller | changed: "logs"
2025-10-08 05:38:02.597095 | controller | changed: All items complete
2025-10-08 05:38:02.597126 | 
2025-10-08 05:38:02.804950 | controller | changed: "artifacts"
2025-10-08 05:38:03.024413 | controller | changed: "docs"
2025-10-08 05:38:03.041853 | 
2025-10-08 05:38:03.042022 | TASK [Check if worker can sudo]
2025-10-08 05:38:03.575487 | controller | ok: Runtime: 0:00:00.069148
2025-10-08 05:38:03.581485 | 
2025-10-08 05:38:03.581551 | TASK [configure-mirrors : Gather needed facts]
2025-10-08 05:38:03.666534 | controller | skipping: Conditional result was False
2025-10-08 05:38:03.672983 | 
2025-10-08 05:38:03.673057 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-08 05:38:03.744856 | controller | ok
2025-10-08 05:38:03.752938 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-08 05:38:03.794640 | 
2025-10-08 05:38:03.794806 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-08 05:38:04.052961 | controller | ok
2025-10-08 05:38:04.060653 | 
2025-10-08 05:38:04.060748 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-08 05:38:04.158123 | controller | ok: "/var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-08 05:38:04.182522 | 
2025-10-08 05:38:04.182656 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-08 05:38:04.996566 | controller | changed
2025-10-08 05:38:05.005540 | 
2025-10-08 05:38:05.005615 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-08 05:38:05.071378 | controller | ok: "/var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-08 05:38:05.071599 | controller | ok: All items complete
2025-10-08 05:38:05.071625 | 
2025-10-08 05:38:05.118069 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-08 05:38:05.124993 | 
2025-10-08 05:38:05.125060 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-08 05:38:06.063231 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-08 05:38:06.996492 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-08 05:38:07.008958 | 
2025-10-08 05:38:07.009136 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-08 05:38:07.527947 | controller | changed: section and option added
2025-10-08 05:38:07.567793 | 
2025-10-08 05:38:07.567973 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-08 05:38:08.440854 | controller | 29 files removed
2025-10-08 05:38:08.441118 | controller | ok: Item: dnf clean all Runtime: 0:00:00.532512
2025-10-08 05:38:08.441159 | controller | changed: All items complete
2025-10-08 05:38:08.441180 | 
2025-10-08 05:38:18.934319 | 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-08 05:38:18.934569 | controller | DNF version: 4.14.0
2025-10-08 05:38:18.934633 | controller | cachedir: /var/cache/dnf
2025-10-08 05:38:18.934685 | controller | Making cache files for all metadata files.
2025-10-08 05:38:18.934768 | controller | baseos: has expired and will be refreshed.
2025-10-08 05:38:18.934818 | controller | appstream: has expired and will be refreshed.
2025-10-08 05:38:18.934862 | controller | crb: has expired and will be refreshed.
2025-10-08 05:38:18.935049 | controller | extras-common: has expired and will be refreshed.
2025-10-08 05:38:18.935102 | controller | repo: downloading from remote: baseos
2025-10-08 05:38:18.935177 | controller | CentOS Stream 9 - BaseOS                         72 MB/s | 8.8 MB     00:00
2025-10-08 05:38:18.935214 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-08 05:38:18.935250 | controller | repo: downloading from remote: appstream
2025-10-08 05:38:18.935285 | controller | CentOS Stream 9 - AppStream                     108 MB/s |  25 MB     00:00
2025-10-08 05:38:18.935319 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-08 05:38:18.935353 | controller | repo: downloading from remote: crb
2025-10-08 05:38:18.935387 | controller | CentOS Stream 9 - CRB                            66 MB/s | 7.1 MB     00:00
2025-10-08 05:38:18.935423 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-08 05:38:18.935458 | controller | repo: downloading from remote: extras-common
2025-10-08 05:38:18.935493 | controller | CentOS Stream 9 - Extras packages               1.4 MB/s |  20 kB     00:00
2025-10-08 05:38:18.935528 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-08 05:38:18.935561 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-08 05:38:18.935595 | controller | Completion plugin: Generating completion cache...
2025-10-08 05:38:18.935630 | controller | Metadata cache created.
2025-10-08 05:38:18.935690 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.245662
2025-10-08 05:38:18.963427 | 
2025-10-08 05:38:18.963867 | PLAY RECAP
2025-10-08 05:38:18.963940 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 05:38:18.963977 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 05:38:18.964002 | 
2025-10-08 05:38:19.165493 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-08 05:38:19.166448 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-08 05:38:19.805213 | 
2025-10-08 05:38:19.805353 | PLAY [all]
2025-10-08 05:38:19.835450 | 
2025-10-08 05:38:19.835563 | TASK [Install binary dependencies]
2025-10-08 05:38:19.886496 | controller | ok
2025-10-08 05:38:19.906559 | 
2025-10-08 05:38:19.906642 | TASK [bindep : Include find tasks]
2025-10-08 05:38:19.946090 | controller | ok
2025-10-08 05:38:19.954017 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-08 05:38:19.959911 | 
2025-10-08 05:38:19.959995 | TASK [bindep : Look for bindep.txt]
2025-10-08 05:38:20.373100 | controller | ok
2025-10-08 05:38:20.382275 | 
2025-10-08 05:38:20.382373 | TASK [bindep : Define bindep_file fact]
2025-10-08 05:38:20.415112 | controller | ok
2025-10-08 05:38:20.422351 | 
2025-10-08 05:38:20.422437 | TASK [bindep : Look for other-requirements.txt]
2025-10-08 05:38:20.448238 | controller | skipping: Conditional result was False
2025-10-08 05:38:20.456639 | 
2025-10-08 05:38:20.456769 | TASK [bindep : Define bindep_file fact]
2025-10-08 05:38:20.483407 | controller | skipping: Conditional result was False
2025-10-08 05:38:20.492134 | 
2025-10-08 05:38:20.492250 | TASK [bindep : Look for bindep fallback file]
2025-10-08 05:38:20.535354 | controller | skipping: Conditional result was False
2025-10-08 05:38:20.549421 | 
2025-10-08 05:38:20.549527 | TASK [bindep : Define bindep_file fact]
2025-10-08 05:38:20.574826 | controller | skipping: Conditional result was False
2025-10-08 05:38:20.581068 | 
2025-10-08 05:38:20.581136 | TASK [bindep : Include bindep tasks]
2025-10-08 05:38:20.612623 | controller | ok
2025-10-08 05:38:20.619432 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-08 05:38:20.631268 | 
2025-10-08 05:38:20.631501 | TASK [bindep : Look for bindep command]
2025-10-08 05:38:20.661341 | controller | skipping: Conditional result was False
2025-10-08 05:38:20.668858 | 
2025-10-08 05:38:20.668929 | TASK [bindep : Check for system bindep]
2025-10-08 05:38:21.200958 | controller | ok: Runtime: 0:00:00.005521
2025-10-08 05:38:21.206702 | 
2025-10-08 05:38:21.206785 | TASK [bindep : Define bindep_command fact]
2025-10-08 05:38:21.244237 | controller | skipping: Conditional result was False
2025-10-08 05:38:21.253618 | 
2025-10-08 05:38:21.253752 | TASK [bindep : Include install tasks]
2025-10-08 05:38:21.296359 | controller | ok
2025-10-08 05:38:21.304759 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-08 05:38:21.313608 | 
2025-10-08 05:38:21.313671 | TASK [bindep : Create temp dir for bindep]
2025-10-08 05:38:21.740211 | controller | changed
2025-10-08 05:38:21.745819 | 
2025-10-08 05:38:21.745945 | TASK [Ensure we have pip dependencies]
2025-10-08 05:38:21.777072 | controller | ok
2025-10-08 05:38:21.802307 | 
2025-10-08 05:38:21.802399 | TASK [ensure-pip : Check if pip is installed]
2025-10-08 01:38:22.076119 | controller | /usr/bin/pip3
2025-10-08 01:38:22.122197 | controller | /usr/bin/python3: No module named wheel
2025-10-08 05:38:22.335111 | controller | ok: Runtime: 0:00:00.063367
2025-10-08 05:38:22.348470 | 
2025-10-08 05:38:22.348608 | LOOP [ensure-pip : Install pip from packages]
2025-10-08 05:38:22.406060 | controller | ok: "/var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-08 05:38:22.426449 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-08 05:38:22.451181 | 
2025-10-08 05:38:22.451339 | TASK [ensure-pip : Install Python 3 pip]
2025-10-08 05:38:24.682214 | controller | changed
2025-10-08 05:38:24.695837 | 
2025-10-08 05:38:24.696008 | TASK [ensure-pip : Check for EPEL repository]
2025-10-08 05:38:24.765906 | controller | skipping: Conditional result was False
2025-10-08 05:38:24.782978 | 
2025-10-08 05:38:24.783141 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-08 05:38:24.843088 | controller | skipping: Conditional result was False
2025-10-08 05:38:24.859514 | 
2025-10-08 05:38:24.859695 | TASK [ensure-pip : Install Python 2 pip]
2025-10-08 05:38:24.909114 | controller | skipping: Conditional result was False
2025-10-08 05:38:24.931442 | 
2025-10-08 05:38:24.931665 | TASK [ensure-pip : Ensure setuptools]
2025-10-08 05:38:24.969488 | controller | skipping: Conditional result was False
2025-10-08 05:38:24.982007 | 
2025-10-08 05:38:24.982148 | TASK [ensure-pip : Check for ensurepip module]
2025-10-08 05:38:25.530938 | controller | skipping: Conditional result was False
2025-10-08 05:38:25.554650 | 
2025-10-08 05:38:25.554833 | TASK [ensure-pip : Ensure python3-venv]
2025-10-08 05:38:25.583810 | controller | skipping: Conditional result was False
2025-10-08 05:38:25.601494 | 
2025-10-08 05:38:25.601655 | TASK [ensure-pip : Install pip from source]
2025-10-08 05:38:25.631526 | controller | skipping: Conditional result was False
2025-10-08 05:38:25.645061 | 
2025-10-08 05:38:25.645196 | TASK [ensure-pip : Probe for venv python full path]
2025-10-08 01:38:25.914547 | controller | /usr/bin/python3
2025-10-08 05:38:26.190239 | controller | ok: Runtime: 0:00:00.005038
2025-10-08 05:38:26.207820 | 
2025-10-08 05:38:26.208077 | TASK [ensure-pip : Set host default]
2025-10-08 05:38:26.297217 | controller | ok
2025-10-08 05:38:26.303556 | 
2025-10-08 05:38:26.303708 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-08 05:38:26.363198 | controller | ok
2025-10-08 05:38:26.391488 | 
2025-10-08 05:38:26.391636 | TASK [bindep : Install bindep into temporary venv]
2025-10-08 05:38:30.582918 | controller | changed
2025-10-08 05:38:30.597093 | 
2025-10-08 05:38:30.597243 | TASK [bindep : Define bindep_command]
2025-10-08 05:38:30.634396 | controller | ok
2025-10-08 05:38:30.640414 | 
2025-10-08 05:38:30.640509 | LOOP [bindep : Include package tasks]
2025-10-08 05:38:30.708190 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-08 05:38:30.708386 | controller | ok: All items complete
2025-10-08 05:38:30.708412 | 
2025-10-08 05:38:30.717185 | controller | included: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-08 05:38:30.740961 | 
2025-10-08 05:38:30.741102 | TASK [bindep : Define bindep_run fact]
2025-10-08 05:38:30.776886 | controller | ok
2025-10-08 05:38:30.782238 | 
2025-10-08 05:38:30.782319 | TASK [bindep : Get list of packages to install from bindep]
2025-10-08 01:38:32.299558 | controller | podman
2025-10-08 01:38:32.333623 | controller | python3-jmespath
2025-10-08 01:38:32.333687 | controller | python3-libvirt
2025-10-08 01:38:32.333776 | controller | python3-lxml
2025-10-08 01:38:32.333786 | controller | python3-netaddr
2025-10-08 05:38:32.818257 | controller | ok: Runtime: 0:00:01.289750
2025-10-08 05:38:32.824016 | 
2025-10-08 05:38:32.824085 | TASK [bindep : Install distro packages from bindep]
2025-10-08 05:39:33.765439 | controller | changed
2025-10-08 05:39:33.773542 | 
2025-10-08 05:39:33.773678 | TASK [bindep : Check that packages are installed]
2025-10-08 05:39:35.343653 | controller | ok: Runtime: 0:00:01.134465
2025-10-08 05:39:35.356659 | 
2025-10-08 05:39:35.356879 | TASK [bindep : Fail if we cannot install all packages]
2025-10-08 05:39:35.383672 | controller | skipping: Conditional result was False
2025-10-08 05:39:35.407799 | 
2025-10-08 05:39:35.408051 | TASK [Run test-setup role]
2025-10-08 05:39:35.436546 | controller | ok
2025-10-08 05:39:35.467951 | 
2025-10-08 05:39:35.468126 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-08 05:39:35.709525 | controller | ok
2025-10-08 05:39:35.721213 | 
2025-10-08 05:39:35.721389 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-08 05:39:36.271439 | controller | skipping: Conditional result was False
2025-10-08 05:39:36.318972 | 
2025-10-08 05:39:36.319164 | TASK [bindep : Remove bindep temp dir]
2025-10-08 05:39:36.781875 | controller | ok
2025-10-08 05:39:36.797992 | 
2025-10-08 05:39:36.798121 | PLAY RECAP
2025-10-08 05:39:36.798171 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-08 05:39:36.798197 | 
2025-10-08 05:39:36.957639 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-08 05:39:36.958925 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-08 05:39:37.521404 | 
2025-10-08 05:39:37.521522 | PLAY [all]
2025-10-08 05:39:37.540973 | 
2025-10-08 05:39:37.541078 | TASK [Abort when test_command variable is undefined]
2025-10-08 05:39:37.575833 | controller | skipping: Conditional result was False
2025-10-08 05:39:37.581664 | 
2025-10-08 05:39:37.581762 | TASK [Convert test_command to list]
2025-10-08 05:39:37.637583 | controller | skipping: Conditional result was False
2025-10-08 05:39:37.644453 | 
2025-10-08 05:39:37.644527 | TASK [Use test_command list]
2025-10-08 05:39:37.713998 | controller | ok
2025-10-08 05:39:37.719345 | 
2025-10-08 05:39:37.719411 | LOOP [Run test_command]
2025-10-08 05:39:38.143892 | controller | no check to run
2025-10-08 05:39:38.144302 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006638
2025-10-08 05:39:38.170937 | 
2025-10-08 05:39:38.171052 | PLAY RECAP
2025-10-08 05:39:38.171093 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-08 05:39:38.171113 | 
2025-10-08 05:39:38.277935 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-08 05:39:38.278828 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-08 05:39:38.947569 | 
2025-10-08 05:39:38.947756 | PLAY [all]
2025-10-08 05:39:38.972684 | 
2025-10-08 05:39:38.972877 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-08 05:39:39.439954 | controller | changed: non-zero return code
2025-10-08 05:39:39.451875 | 
2025-10-08 05:39:39.452035 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-08 05:39:39.479106 | controller | skipping: Conditional result was False
2025-10-08 05:39:39.491539 | 
2025-10-08 05:39:39.491692 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-08 05:39:39.531242 | 
2025-10-08 05:39:39.531494 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-08 05:39:39.569563 | 
2025-10-08 05:39:39.569840 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-08 05:39:39.587050 | controller | skipping: Conditional result was False
2025-10-08 05:39:39.600271 | 
2025-10-08 05:39:39.600416 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-08 05:39:39.660940 | 
2025-10-08 05:39:39.661197 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-08 05:39:39.677873 | controller | skipping: Conditional result was False
2025-10-08 05:39:39.691651 | 
2025-10-08 05:39:39.691844 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-08 05:39:39.714412 | controller | skipping: Conditional result was False
2025-10-08 05:39:39.726815 | 
2025-10-08 05:39:39.726988 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-08 05:39:39.743608 | controller | skipping: Conditional result was False
2025-10-08 05:39:39.783307 | 
2025-10-08 05:39:39.783453 | PLAY RECAP
2025-10-08 05:39:39.783515 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-08 05:39:39.783544 | 
2025-10-08 05:39:39.919030 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-08 05:39:39.920154 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 05:39:40.482465 | 
2025-10-08 05:39:40.482595 | PLAY [all]
2025-10-08 05:39:40.501385 | 
2025-10-08 05:39:40.501466 | TASK [include_role : fetch-output]
2025-10-08 05:39:40.550319 | controller | ok
2025-10-08 05:39:40.567058 | 
2025-10-08 05:39:40.567136 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 05:39:40.642151 | controller | skipping: Conditional result was False
2025-10-08 05:39:40.654223 | 
2025-10-08 05:39:40.654369 | TASK [fetch-output : Set log path for single node]
2025-10-08 05:39:40.701572 | controller | ok
2025-10-08 05:39:40.712517 | 
2025-10-08 05:39:40.712658 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 05:39:41.155846 | controller -> localhost | ok: "/var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/logs"
2025-10-08 05:39:41.359575 | controller -> localhost | changed: "/var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/artifacts"
2025-10-08 05:39:41.578053 | controller -> localhost | changed: "/var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/docs"
2025-10-08 05:39:41.602095 | 
2025-10-08 05:39:41.602316 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 05:39:42.325234 | controller | changed: .d..t...... ./
2025-10-08 05:39:42.325603 | controller | changed: All items complete
2025-10-08 05:39:42.325673 | 
2025-10-08 05:39:42.892196 | controller | changed: .d..t...... ./
2025-10-08 05:39:43.445240 | controller | changed: .d..t...... ./
2025-10-08 05:39:43.468428 | 
2025-10-08 05:39:43.468596 | TASK [include_role : fetch-output-openshift]
2025-10-08 05:39:43.494617 | controller | skipping: Conditional result was False
2025-10-08 05:39:43.503959 | 
2025-10-08 05:39:43.504133 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-08 05:39:43.990843 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014712
2025-10-08 05:39:44.278969 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015778
2025-10-08 05:39:44.338936 | 
2025-10-08 05:39:44.339091 | PLAY [all]
2025-10-08 05:39:44.362087 | 
2025-10-08 05:39:44.362266 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-08 05:39:44.820605 | controller | changed
2025-10-08 05:39:44.866718 | 
2025-10-08 05:39:44.866895 | PLAY RECAP
2025-10-08 05:39:44.866956 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-08 05:39:44.866986 | 
2025-10-08 05:39:44.990578 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 05:39:44.992506 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-08 05:39:45.614281 | 
2025-10-08 05:39:45.614429 | PLAY [localhost]
2025-10-08 05:39:45.634224 | 
2025-10-08 05:39:45.634315 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-08 05:39:46.115705 | localhost | changed
2025-10-08 05:39:46.126936 | 
2025-10-08 05:39:46.127102 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-08 05:39:46.174776 | localhost | ok
2025-10-08 05:39:46.193540 | 
2025-10-08 05:39:46.193750 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-08 05:39:46.617856 | localhost | changed
2025-10-08 05:39:46.630143 | 
2025-10-08 05:39:46.630334 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-08 05:39:47.399518 | localhost | changed
2025-10-08 05:39:47.411587 | 
2025-10-08 05:39:47.411776 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-08 05:39:47.892794 | localhost | Identity added: /var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/tmp/ansible.8e64a9bt (/var/lib/zuul/builds/f7bc249a35014128aed776ca238f912f/work/tmp/ansible.8e64a9bt)
2025-10-08 05:39:47.893030 | localhost | ok: Runtime: 0:00:00.013924
2025-10-08 05:39:47.897570 | 
2025-10-08 05:39:47.897649 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-08 05:39:48.193043 | localhost | ok: Runtime: 0:00:00.008449
2025-10-08 05:39:48.198571 | 
2025-10-08 05:39:48.198641 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-08 05:39:48.247375 | localhost | changed
2025-10-08 05:39:48.251822 | 
2025-10-08 05:39:48.251895 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-08 05:39:48.646300 | localhost | changed
2025-10-08 05:39:48.667363 | 
2025-10-08 05:39:48.667425 | PLAY [localhost]
2025-10-08 05:39:48.679652 | 
2025-10-08 05:39:48.679710 | TASK [Generate bulk log download script]
2025-10-08 05:39:48.698465 | localhost | ok
2025-10-08 05:39:48.711145 | 
2025-10-08 05:39:48.711227 | TASK [local-log-download : Check API endpoint is defined]
2025-10-08 05:39:48.740529 | localhost | ok: All assertions passed
2025-10-08 05:39:48.745436 | 
2025-10-08 05:39:48.745498 | TASK [local-log-download : Create download script]
2025-10-08 05:39:49.196682 | localhost -> localhost | changed
2025-10-08 05:39:49.206211 | 
2025-10-08 05:39:49.206279 | TASK [Register quick-download link]
2025-10-08 05:39:49.234914 | localhost | ok
2025-10-08 05:39:49.277528 | 
2025-10-08 05:39:49.277637 | PLAY [logserver.rdoproject.org]
2025-10-08 05:39:49.287745 | 
2025-10-08 05:39:49.287810 | TASK [Set zuul-log-path fact]
2025-10-08 05:39:49.304155 | logserver.rdoproject.org | ok
2025-10-08 05:39:49.314676 | 
2025-10-08 05:39:49.314766 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 05:39:49.341336 | logserver.rdoproject.org | ok
2025-10-08 05:39:49.346849 | 
2025-10-08 05:39:49.346913 | TASK [upload-logs : Create log directories]
2025-10-08 05:39:50.159317 | logserver.rdoproject.org | changed
2025-10-08 05:39:50.166161 | 
2025-10-08 05:39:50.166314 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-08 05:39:50.468256 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004719
2025-10-08 05:39:50.473227 | 
2025-10-08 05:39:50.473290 | TASK [upload-logs : Upload logs to log server]
2025-10-08 05:39:51.199537 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-08 05:39:51.206443 | 
2025-10-08 05:39:51.206574 | LOOP [upload-logs : Compress console log and json output]
2025-10-08 05:39:51.288865 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 05:39:51.300929 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 05:39:51.314346 | 
2025-10-08 05:39:51.314487 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-08 05:39:51.381854 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 05:39:51.382255 | 
2025-10-08 05:39:51.386968 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 05:39:51.400693 | 
2025-10-08 05:39:51.400898 | LOOP [upload-logs : Upload console log and json output]