2025-10-13 13:27:34.431677 | Job console starting...
2025-10-13 13:27:34.441560 | Updating repositories
2025-10-13 13:27:34.479206 | Preparing job workspace
2025-10-13 13:27:38.432393 | Running Ansible setup...
2025-10-13 13:27:43.225486 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 13:27:44.176851 | 
2025-10-13 13:27:44.176985 | PLAY [localhost]
2025-10-13 13:27:44.185996 | 
2025-10-13 13:27:44.186085 | TASK [Gathering Facts]
2025-10-13 13:27:45.597635 | localhost | ok
2025-10-13 13:27:45.628241 | 
2025-10-13 13:27:45.628418 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 13:27:46.305487 | localhost -> localhost | changed
2025-10-13 13:27:46.311223 | 
2025-10-13 13:27:46.311326 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 13:27:47.445352 | localhost -> localhost | changed
2025-10-13 13:27:47.453755 | 
2025-10-13 13:27:47.453822 | TASK [Setup log path fact]
2025-10-13 13:27:47.474805 | localhost | ok
2025-10-13 13:27:47.486230 | 
2025-10-13 13:27:47.486330 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 13:27:47.514765 | localhost | ok
2025-10-13 13:27:47.525535 | 
2025-10-13 13:27:47.525622 | TASK [emit-job-header : Print job information]
2025-10-13 13:27:47.555555 | # Job Information
2025-10-13 13:27:47.555687 | Ansible Version: 2.15.12
2025-10-13 13:27:47.555713 | Job: cifmw-molecule-polarion
2025-10-13 13:27:47.555733 | Pipeline: github-check
2025-10-13 13:27:47.555751 | Executor: ze01.softwarefactory-project.io
2025-10-13 13:27:47.555768 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402
2025-10-13 13:27:47.555787 | Log URL (when completed): https://logserver.rdoproject.org/e10/rdoproject.org/e100a7b381c645d0929217c051d1ad72/
2025-10-13 13:27:47.555805 | Event ID: 1d8d4d80-a838-11f0-8dac-98223402f22d
2025-10-13 13:27:47.559425 | 
2025-10-13 13:27:47.559488 | LOOP [emit-job-header : Print node information]
2025-10-13 13:27:47.655933 | localhost | ok:
2025-10-13 13:27:47.656112 | localhost | # Node Information
2025-10-13 13:27:47.656140 | localhost | Inventory Hostname: controller
2025-10-13 13:27:47.656162 | localhost | Hostname: np0005484805
2025-10-13 13:27:47.656181 | localhost | Username: zuul
2025-10-13 13:27:47.656201 | localhost | Distro: CentOS 9
2025-10-13 13:27:47.656218 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 13:27:47.656235 | localhost | Region: RegionOne
2025-10-13 13:27:47.656252 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 13:27:47.656268 | localhost | Product Name: OpenStack Nova
2025-10-13 13:27:47.656283 | localhost | Interface IP: 38.129.56.226
2025-10-13 13:27:47.684223 | 
2025-10-13 13:27:47.684289 | PLAY [all]
2025-10-13 13:27:47.695328 | 
2025-10-13 13:27:47.695404 | TASK [Gather network facts]
2025-10-13 13:27:48.155489 | controller | ok
2025-10-13 13:27:48.193156 | 
2025-10-13 13:27:48.193300 | TASK [include_role : start-zuul-console]
2025-10-13 13:27:48.233462 | controller | ok
2025-10-13 13:27:48.258427 | 
2025-10-13 13:27:48.258562 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 13:27:48.724060 | controller | ok
2025-10-13 13:27:48.734726 | 
2025-10-13 13:27:48.734847 | TASK [include_role : add-build-sshkey]
2025-10-13 13:27:48.755802 | controller | ok
2025-10-13 13:27:48.775641 | 
2025-10-13 13:27:48.775762 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 13:27:49.339822 | controller -> localhost | ok
2025-10-13 13:27:49.345813 | 
2025-10-13 13:27:49.345875 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 13:27:49.374668 | controller | ok
2025-10-13 13:27:49.397982 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 13:27:49.425134 | 
2025-10-13 13:27:49.425268 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 13:27:50.920391 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 13:27:50.920593 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/e100a7b381c645d0929217c051d1ad72_id_rsa.
2025-10-13 13:27:50.920623 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/e100a7b381c645d0929217c051d1ad72_id_rsa.pub.
2025-10-13 13:27:50.920645 | controller -> localhost | The key fingerprint is:
2025-10-13 13:27:50.920665 | controller -> localhost | SHA256:KPe/RPPhz/b1o4pFOkLUvkoJjQimRurdUFxBd8MjA3o zuul-build-sshkey
2025-10-13 13:27:50.920683 | controller -> localhost | The key's randomart image is:
2025-10-13 13:27:50.920701 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 13:27:50.920719 | controller -> localhost | |      .=o..o     |
2025-10-13 13:27:50.920737 | controller -> localhost | |    . o oo.o.    |
2025-10-13 13:27:50.920755 | controller -> localhost | | +   + E .o .    |
2025-10-13 13:27:50.920773 | controller -> localhost | |= . o =..        |
2025-10-13 13:27:50.920790 | controller -> localhost | |o. o.oooS.o..    |
2025-10-13 13:27:50.920808 | controller -> localhost | |o . ooo...++ .   |
2025-10-13 13:27:50.920825 | controller -> localhost | | . . . +.+..o   .|
2025-10-13 13:27:50.920843 | controller -> localhost | |      . oo+  o..o|
2025-10-13 13:27:50.920861 | controller -> localhost | |       . .oo.o+.+|
2025-10-13 13:27:50.920879 | controller -> localhost | +----[SHA256]-----+
2025-10-13 13:27:50.920923 | controller -> localhost | ok: Runtime: 0:00:01.005672
2025-10-13 13:27:50.927036 | 
2025-10-13 13:27:50.927104 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 13:27:50.981624 | controller | ok
2025-10-13 13:27:51.002547 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 13:27:51.021623 | 
2025-10-13 13:27:51.021718 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 13:27:51.081924 | controller | skipping: Conditional result was False
2025-10-13 13:27:51.087983 | 
2025-10-13 13:27:51.088091 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 13:27:51.737007 | controller | changed
2025-10-13 13:27:51.743808 | 
2025-10-13 13:27:51.743910 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 13:27:51.992503 | controller | ok
2025-10-13 13:27:51.998070 | 
2025-10-13 13:27:51.998145 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 13:27:52.944995 | controller | changed
2025-10-13 13:27:52.951093 | 
2025-10-13 13:27:52.951177 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 13:27:53.888348 | controller | changed
2025-10-13 13:27:53.911463 | 
2025-10-13 13:27:53.911559 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 13:27:53.970529 | controller | skipping: Conditional result was False
2025-10-13 13:27:53.994838 | 
2025-10-13 13:27:53.994967 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 13:27:54.567437 | controller -> localhost | changed
2025-10-13 13:27:54.577543 | 
2025-10-13 13:27:54.577606 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 13:27:54.970989 | controller -> localhost | Identity added: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/e100a7b381c645d0929217c051d1ad72_id_rsa (zuul-build-sshkey)
2025-10-13 13:27:54.971185 | controller -> localhost | ok: Runtime: 0:00:00.014034
2025-10-13 13:27:54.976813 | 
2025-10-13 13:27:54.976872 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 13:27:55.473889 | controller | ok
2025-10-13 13:27:55.487092 | 
2025-10-13 13:27:55.487158 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 13:27:55.521098 | controller | skipping: Conditional result was False
2025-10-13 13:27:55.530998 | 
2025-10-13 13:27:55.531084 | TASK [include_role : validate-host]
2025-10-13 13:27:55.552399 | controller | ok
2025-10-13 13:27:55.650658 | 
2025-10-13 13:27:55.650761 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 13:27:55.680371 | controller | ok
2025-10-13 13:27:55.685410 | 
2025-10-13 13:27:55.685477 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 13:27:56.010216 | controller -> localhost | ok
2025-10-13 13:27:56.021846 | 
2025-10-13 13:27:56.021916 | TASK [validate-host : Collect information about the host]
2025-10-13 13:27:56.801933 | controller | ok
2025-10-13 13:27:56.812407 | 
2025-10-13 13:27:56.812531 | TASK [validate-host : Sanitize hostname]
2025-10-13 13:27:56.854127 | controller | ok
2025-10-13 13:27:56.859084 | 
2025-10-13 13:27:56.859149 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 13:27:57.377314 | controller -> localhost | changed
2025-10-13 13:27:57.383435 | 
2025-10-13 13:27:57.383496 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 13:27:57.801614 | controller | ok
2025-10-13 13:27:57.813042 | 
2025-10-13 13:27:57.813146 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 13:27:58.204387 | controller -> localhost | changed
2025-10-13 13:27:58.214884 | 
2025-10-13 13:27:58.214973 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 13:27:58.229528 | controller | skipping: Conditional result was False
2025-10-13 13:27:58.235896 | 
2025-10-13 13:27:58.235978 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 13:27:58.262642 | controller | skipping: Conditional result was False
2025-10-13 13:27:58.269917 | 
2025-10-13 13:27:58.270003 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 13:27:58.549547 | controller | ok: "logs"
2025-10-13 13:27:58.549792 | controller | ok: All items complete
2025-10-13 13:27:58.549819 | 
2025-10-13 13:27:58.794044 | controller | ok: "artifacts"
2025-10-13 13:27:59.015658 | controller | ok: "docs"
2025-10-13 13:27:59.026142 | 
2025-10-13 13:27:59.026209 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 13:27:59.276994 | controller | changed: "logs"
2025-10-13 13:27:59.515513 | controller | changed: "artifacts"
2025-10-13 13:27:59.823409 | controller | changed: "docs"
2025-10-13 13:27:59.871585 | 
2025-10-13 13:27:59.871755 | PLAY RECAP
2025-10-13 13:27:59.871988 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 13:27:59.872058 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 13:27:59.872088 | 
2025-10-13 13:28:00.017288 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 13:28:00.018163 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 13:28:00.644046 | 
2025-10-13 13:28:00.644153 | PLAY [localhost]
2025-10-13 13:28:00.660281 | 
2025-10-13 13:28:00.660354 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 13:28:01.100251 | localhost | ok
2025-10-13 13:28:01.115480 | 
2025-10-13 13:28:01.115772 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 13:28:01.918482 | localhost | changed
2025-10-13 13:28:01.947854 | 
2025-10-13 13:28:01.947951 | PLAY [all]
2025-10-13 13:28:01.970179 | 
2025-10-13 13:28:01.970271 | TASK [include_role : prepare-workspace]
2025-10-13 13:28:02.000604 | controller | ok
2025-10-13 13:28:02.018052 | 
2025-10-13 13:28:02.018198 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 13:28:02.436926 | controller | ok
2025-10-13 13:28:02.446764 | 
2025-10-13 13:28:02.446856 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 13:28:04.081429 | controller | Output suppressed because no_log was given
2025-10-13 13:28:04.091893 | 
2025-10-13 13:28:04.092109 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 13:28:04.370983 | controller | changed: "logs"
2025-10-13 13:28:04.594770 | controller | changed: "artifacts"
2025-10-13 13:28:04.836412 | controller | changed: "docs"
2025-10-13 13:28:04.866526 | 
2025-10-13 13:28:04.866990 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 13:28:05.130110 | controller | changed: "logs"
2025-10-13 13:28:05.130357 | controller | changed: All items complete
2025-10-13 13:28:05.130393 | 
2025-10-13 13:28:05.364083 | controller | changed: "artifacts"
2025-10-13 13:28:05.605734 | controller | changed: "docs"
2025-10-13 13:28:05.629061 | 
2025-10-13 13:28:05.629165 | TASK [Check if worker can sudo]
2025-10-13 13:28:06.162848 | controller | ok: Runtime: 0:00:00.056520
2025-10-13 13:28:06.173455 | 
2025-10-13 13:28:06.173682 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 13:28:06.267007 | controller | skipping: Conditional result was False
2025-10-13 13:28:06.279128 | 
2025-10-13 13:28:06.279352 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 13:28:06.355361 | controller | ok
2025-10-13 13:28:06.365924 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 13:28:06.374070 | 
2025-10-13 13:28:06.374136 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 13:28:06.783322 | controller | ok
2025-10-13 13:28:06.789056 | 
2025-10-13 13:28:06.789116 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 13:28:06.856620 | controller | ok: "/var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 13:28:06.870565 | 
2025-10-13 13:28:06.870669 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 13:28:07.781131 | controller | changed
2025-10-13 13:28:07.804455 | 
2025-10-13 13:28:07.804653 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 13:28:07.880484 | controller | ok: "/var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 13:28:07.880889 | controller | ok: All items complete
2025-10-13 13:28:07.880954 | 
2025-10-13 13:28:07.966553 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 13:28:07.973670 | 
2025-10-13 13:28:07.973738 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 13:28:08.825861 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 13:28:09.624731 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 13:28:09.636696 | 
2025-10-13 13:28:09.636862 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 13:28:10.145733 | controller | changed: section and option added
2025-10-13 13:28:10.175312 | 
2025-10-13 13:28:10.175440 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 13:28:11.121346 | controller | 29 files removed
2025-10-13 13:28:11.121549 | controller | ok: Item: dnf clean all Runtime: 0:00:00.621688
2025-10-13 13:28:11.121605 | controller | changed: All items complete
2025-10-13 13:28:11.121631 | 
2025-10-13 13:28:22.392367 | 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 13:28:22.392529 | controller | DNF version: 4.14.0
2025-10-13 13:28:22.392577 | controller | cachedir: /var/cache/dnf
2025-10-13 13:28:22.392719 | controller | Making cache files for all metadata files.
2025-10-13 13:28:22.392751 | controller | baseos: has expired and will be refreshed.
2025-10-13 13:28:22.392775 | controller | appstream: has expired and will be refreshed.
2025-10-13 13:28:22.392799 | controller | crb: has expired and will be refreshed.
2025-10-13 13:28:22.392848 | controller | extras-common: has expired and will be refreshed.
2025-10-13 13:28:22.392872 | controller | repo: downloading from remote: baseos
2025-10-13 13:28:22.392895 | controller | CentOS Stream 9 - BaseOS                         69 MB/s | 8.8 MB     00:00
2025-10-13 13:28:22.392917 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 13:28:22.392938 | controller | repo: downloading from remote: appstream
2025-10-13 13:28:22.392960 | controller | CentOS Stream 9 - AppStream                      63 MB/s |  25 MB     00:00
2025-10-13 13:28:22.392982 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 13:28:22.393003 | controller | repo: downloading from remote: crb
2025-10-13 13:28:22.393048 | controller | CentOS Stream 9 - CRB                            41 MB/s | 7.2 MB     00:00
2025-10-13 13:28:22.393074 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 13:28:22.393098 | controller | repo: downloading from remote: extras-common
2025-10-13 13:28:22.393121 | controller | CentOS Stream 9 - Extras packages               776 kB/s |  20 kB     00:00
2025-10-13 13:28:22.393145 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 13:28:22.393170 | controller | Last metadata expiration check: 0:00:01 ago on Mon 13 Oct 2025 09:28:20 AM EDT.
2025-10-13 13:28:22.393196 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 13:28:22.393221 | controller | Completion plugin: Generating completion cache...
2025-10-13 13:28:22.393246 | controller | Metadata cache created.
2025-10-13 13:28:22.393273 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.014226
2025-10-13 13:28:22.413712 | 
2025-10-13 13:28:22.413797 | PLAY RECAP
2025-10-13 13:28:22.413837 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 13:28:22.413862 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 13:28:22.413880 | 
2025-10-13 13:28:22.518998 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 13:28:22.519827 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 13:28:23.110673 | 
2025-10-13 13:28:23.110784 | PLAY [all]
2025-10-13 13:28:23.134522 | 
2025-10-13 13:28:23.134629 | TASK [Install binary dependencies]
2025-10-13 13:28:23.219733 | controller | ok
2025-10-13 13:28:23.252794 | 
2025-10-13 13:28:23.252950 | TASK [bindep : Include find tasks]
2025-10-13 13:28:23.286935 | controller | ok
2025-10-13 13:28:23.299393 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 13:28:23.308758 | 
2025-10-13 13:28:23.308865 | TASK [bindep : Look for bindep.txt]
2025-10-13 13:28:23.764513 | controller | ok
2025-10-13 13:28:23.774293 | 
2025-10-13 13:28:23.774401 | TASK [bindep : Define bindep_file fact]
2025-10-13 13:28:23.806180 | controller | ok
2025-10-13 13:28:23.813038 | 
2025-10-13 13:28:23.813108 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 13:28:23.837613 | controller | skipping: Conditional result was False
2025-10-13 13:28:23.844322 | 
2025-10-13 13:28:23.844398 | TASK [bindep : Define bindep_file fact]
2025-10-13 13:28:23.868881 | controller | skipping: Conditional result was False
2025-10-13 13:28:23.877387 | 
2025-10-13 13:28:23.877495 | TASK [bindep : Look for bindep fallback file]
2025-10-13 13:28:23.922361 | controller | skipping: Conditional result was False
2025-10-13 13:28:23.929321 | 
2025-10-13 13:28:23.929402 | TASK [bindep : Define bindep_file fact]
2025-10-13 13:28:24.000295 | controller | skipping: Conditional result was False
2025-10-13 13:28:24.014339 | 
2025-10-13 13:28:24.014462 | TASK [bindep : Include bindep tasks]
2025-10-13 13:28:24.080981 | controller | ok
2025-10-13 13:28:24.101130 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 13:28:24.118515 | 
2025-10-13 13:28:24.118637 | TASK [bindep : Look for bindep command]
2025-10-13 13:28:24.183983 | controller | skipping: Conditional result was False
2025-10-13 13:28:24.215649 | 
2025-10-13 13:28:24.215774 | TASK [bindep : Check for system bindep]
2025-10-13 13:28:24.756470 | controller | ok: Runtime: 0:00:00.008010
2025-10-13 13:28:24.762331 | 
2025-10-13 13:28:24.762401 | TASK [bindep : Define bindep_command fact]
2025-10-13 13:28:24.806921 | controller | skipping: Conditional result was False
2025-10-13 13:28:24.814222 | 
2025-10-13 13:28:24.814319 | TASK [bindep : Include install tasks]
2025-10-13 13:28:24.858847 | controller | ok
2025-10-13 13:28:24.872780 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 13:28:24.884138 | 
2025-10-13 13:28:24.884273 | TASK [bindep : Create temp dir for bindep]
2025-10-13 13:28:25.307080 | controller | changed
2025-10-13 13:28:25.317343 | 
2025-10-13 13:28:25.317504 | TASK [Ensure we have pip dependencies]
2025-10-13 13:28:25.343037 | controller | ok
2025-10-13 13:28:25.392566 | 
2025-10-13 13:28:25.392707 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 09:28:25.711295 | controller | /usr/bin/pip3
2025-10-13 09:28:25.732018 | controller | /usr/bin/python3: No module named wheel
2025-10-13 13:28:25.934481 | controller | ok: Runtime: 0:00:00.030737
2025-10-13 13:28:25.940831 | 
2025-10-13 13:28:25.940906 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 13:28:25.982306 | controller | ok: "/var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 13:28:25.998914 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 13:28:26.009185 | 
2025-10-13 13:28:26.009253 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 13:28:29.700764 | controller | changed
2025-10-13 13:28:29.711439 | 
2025-10-13 13:28:29.711528 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 13:28:29.759952 | controller | skipping: Conditional result was False
2025-10-13 13:28:29.767772 | 
2025-10-13 13:28:29.768103 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 13:28:29.824273 | controller | skipping: Conditional result was False
2025-10-13 13:28:29.832512 | 
2025-10-13 13:28:29.832594 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 13:28:29.877488 | controller | skipping: Conditional result was False
2025-10-13 13:28:29.885429 | 
2025-10-13 13:28:29.885507 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 13:28:29.910081 | controller | skipping: Conditional result was False
2025-10-13 13:28:29.917443 | 
2025-10-13 13:28:29.917515 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 13:28:30.454537 | controller | skipping: Conditional result was False
2025-10-13 13:28:30.460948 | 
2025-10-13 13:28:30.461046 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 13:28:30.518739 | controller | skipping: Conditional result was False
2025-10-13 13:28:30.525213 | 
2025-10-13 13:28:30.525282 | TASK [ensure-pip : Install pip from source]
2025-10-13 13:28:30.563184 | controller | skipping: Conditional result was False
2025-10-13 13:28:30.570673 | 
2025-10-13 13:28:30.570780 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 09:28:30.938330 | controller | /usr/bin/python3
2025-10-13 13:28:31.152558 | controller | ok: Runtime: 0:00:00.005367
2025-10-13 13:28:31.165108 | 
2025-10-13 13:28:31.165251 | TASK [ensure-pip : Set host default]
2025-10-13 13:28:31.253962 | controller | ok
2025-10-13 13:28:31.259600 | 
2025-10-13 13:28:31.259664 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 13:28:31.313451 | controller | ok
2025-10-13 13:28:31.323208 | 
2025-10-13 13:28:31.323273 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 13:28:35.734632 | controller | changed
2025-10-13 13:28:35.742816 | 
2025-10-13 13:28:35.742890 | TASK [bindep : Define bindep_command]
2025-10-13 13:28:35.792489 | controller | ok
2025-10-13 13:28:35.802130 | 
2025-10-13 13:28:35.802242 | LOOP [bindep : Include package tasks]
2025-10-13 13:28:35.904801 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 13:28:35.904947 | controller | ok: All items complete
2025-10-13 13:28:35.904971 | 
2025-10-13 13:28:35.922080 | controller | included: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 13:28:35.938559 | 
2025-10-13 13:28:35.938931 | TASK [bindep : Define bindep_run fact]
2025-10-13 13:28:35.966773 | controller | ok
2025-10-13 13:28:35.972214 | 
2025-10-13 13:28:35.972279 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 09:28:37.628198 | controller | podman
2025-10-13 09:28:37.668810 | controller | python3-jmespath
2025-10-13 09:28:37.668860 | controller | python3-libvirt
2025-10-13 09:28:37.668876 | controller | python3-lxml
2025-10-13 09:28:37.668893 | controller | python3-netaddr
2025-10-13 13:28:38.006812 | controller | ok: Runtime: 0:00:01.391055
2025-10-13 13:28:38.021648 | 
2025-10-13 13:28:38.021815 | TASK [bindep : Install distro packages from bindep]
2025-10-13 13:29:40.039744 | controller | changed
2025-10-13 13:29:40.060412 | 
2025-10-13 13:29:40.060517 | TASK [bindep : Check that packages are installed]
2025-10-13 13:29:41.596089 | controller | ok: Runtime: 0:00:01.104819
2025-10-13 13:29:41.601909 | 
2025-10-13 13:29:41.601973 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 13:29:41.636146 | controller | skipping: Conditional result was False
2025-10-13 13:29:41.649272 | 
2025-10-13 13:29:41.649456 | TASK [Run test-setup role]
2025-10-13 13:29:41.676514 | controller | ok
2025-10-13 13:29:41.706893 | 
2025-10-13 13:29:41.707028 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 13:29:41.952066 | controller | ok
2025-10-13 13:29:41.965382 | 
2025-10-13 13:29:41.965467 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 13:29:42.499180 | controller | skipping: Conditional result was False
2025-10-13 13:29:42.539543 | 
2025-10-13 13:29:42.539664 | TASK [bindep : Remove bindep temp dir]
2025-10-13 13:29:42.972646 | controller | ok
2025-10-13 13:29:42.998324 | 
2025-10-13 13:29:42.998467 | PLAY RECAP
2025-10-13 13:29:42.998526 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 13:29:42.998561 | 
2025-10-13 13:29:43.131251 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 13:29:43.132161 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 13:29:43.756528 | 
2025-10-13 13:29:43.756660 | PLAY [all]
2025-10-13 13:29:43.779170 | 
2025-10-13 13:29:43.779393 | TASK [Abort when test_command variable is undefined]
2025-10-13 13:29:43.805622 | controller | skipping: Conditional result was False
2025-10-13 13:29:43.812693 | 
2025-10-13 13:29:43.812772 | TASK [Convert test_command to list]
2025-10-13 13:29:43.848312 | controller | skipping: Conditional result was False
2025-10-13 13:29:43.855961 | 
2025-10-13 13:29:43.856056 | TASK [Use test_command list]
2025-10-13 13:29:43.905932 | controller | ok
2025-10-13 13:29:43.911299 | 
2025-10-13 13:29:43.911359 | LOOP [Run test_command]
2025-10-13 13:29:44.339207 | controller | no check to run
2025-10-13 13:29:44.339399 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008031
2025-10-13 13:29:44.401212 | 
2025-10-13 13:29:44.401339 | PLAY RECAP
2025-10-13 13:29:44.401395 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 13:29:44.401434 | 
2025-10-13 13:29:44.528221 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 13:29:44.529372 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 13:29:45.174534 | 
2025-10-13 13:29:45.174673 | PLAY [all]
2025-10-13 13:29:45.196302 | 
2025-10-13 13:29:45.196530 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 13:29:45.603715 | controller | changed: non-zero return code
2025-10-13 13:29:45.608993 | 
2025-10-13 13:29:45.609083 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 13:29:45.632710 | controller | skipping: Conditional result was False
2025-10-13 13:29:45.638988 | 
2025-10-13 13:29:45.639086 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 13:29:45.683570 | 
2025-10-13 13:29:45.684400 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 13:29:45.719377 | 
2025-10-13 13:29:45.719590 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 13:29:45.734043 | controller | skipping: Conditional result was False
2025-10-13 13:29:45.742398 | 
2025-10-13 13:29:45.742494 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 13:29:45.768135 | 
2025-10-13 13:29:45.768452 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 13:29:45.798662 | controller | skipping: Conditional result was False
2025-10-13 13:29:45.808076 | 
2025-10-13 13:29:45.808185 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 13:29:45.833990 | controller | skipping: Conditional result was False
2025-10-13 13:29:45.843350 | 
2025-10-13 13:29:45.843451 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 13:29:45.860292 | controller | skipping: Conditional result was False
2025-10-13 13:29:45.891888 | 
2025-10-13 13:29:45.891959 | PLAY RECAP
2025-10-13 13:29:45.892002 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 13:29:45.892052 | 
2025-10-13 13:29:46.004335 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 13:29:46.005257 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 13:29:46.570830 | 
2025-10-13 13:29:46.570964 | PLAY [all]
2025-10-13 13:29:46.589885 | 
2025-10-13 13:29:46.589971 | TASK [include_role : fetch-output]
2025-10-13 13:29:46.618872 | controller | ok
2025-10-13 13:29:46.635459 | 
2025-10-13 13:29:46.635539 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 13:29:46.690007 | controller | skipping: Conditional result was False
2025-10-13 13:29:46.697948 | 
2025-10-13 13:29:46.698107 | TASK [fetch-output : Set log path for single node]
2025-10-13 13:29:46.775950 | controller | ok
2025-10-13 13:29:46.785290 | 
2025-10-13 13:29:46.785368 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 13:29:47.207106 | controller -> localhost | ok: "/var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/logs"
2025-10-13 13:29:47.426391 | controller -> localhost | changed: "/var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/artifacts"
2025-10-13 13:29:47.663403 | controller -> localhost | changed: "/var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/docs"
2025-10-13 13:29:47.677155 | 
2025-10-13 13:29:47.677267 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 13:29:48.347230 | controller | changed: .d..t...... ./
2025-10-13 13:29:48.347468 | controller | changed: All items complete
2025-10-13 13:29:48.347506 | 
2025-10-13 13:29:48.892831 | controller | changed: .d..t...... ./
2025-10-13 13:29:49.405167 | controller | changed: .d..t...... ./
2025-10-13 13:29:49.428534 | 
2025-10-13 13:29:49.428682 | TASK [include_role : fetch-output-openshift]
2025-10-13 13:29:49.444119 | controller | skipping: Conditional result was False
2025-10-13 13:29:49.453697 | 
2025-10-13 13:29:49.453825 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 13:29:49.914627 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.021852
2025-10-13 13:29:50.155221 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013084
2025-10-13 13:29:50.194436 | 
2025-10-13 13:29:50.194612 | PLAY [all]
2025-10-13 13:29:50.214069 | 
2025-10-13 13:29:50.214201 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 13:29:50.691066 | controller | changed
2025-10-13 13:29:50.716857 | 
2025-10-13 13:29:50.716943 | PLAY RECAP
2025-10-13 13:29:50.717004 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 13:29:50.717055 | 
2025-10-13 13:29:50.809566 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 13:29:50.810397 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 13:29:51.533213 | 
2025-10-13 13:29:51.533422 | PLAY [localhost]
2025-10-13 13:29:51.553754 | 
2025-10-13 13:29:51.553898 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 13:29:51.972301 | localhost | changed
2025-10-13 13:29:51.987217 | 
2025-10-13 13:29:51.987470 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 13:29:52.030646 | localhost | ok
2025-10-13 13:29:52.043458 | 
2025-10-13 13:29:52.043615 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 13:29:52.492356 | localhost | changed
2025-10-13 13:29:52.498233 | 
2025-10-13 13:29:52.498346 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 13:29:53.187288 | localhost | changed
2025-10-13 13:29:53.192593 | 
2025-10-13 13:29:53.192657 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 13:29:53.626213 | localhost | Identity added: /var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/tmp/ansible.6ju4jpmy (/var/lib/zuul/builds/e100a7b381c645d0929217c051d1ad72/work/tmp/ansible.6ju4jpmy)
2025-10-13 13:29:53.626403 | localhost | ok: Runtime: 0:00:00.016040
2025-10-13 13:29:53.630648 | 
2025-10-13 13:29:53.630715 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 13:29:53.992138 | localhost | ok: Runtime: 0:00:00.006621
2025-10-13 13:29:53.997050 | 
2025-10-13 13:29:53.997134 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 13:29:54.062288 | localhost | changed
2025-10-13 13:29:54.066591 | 
2025-10-13 13:29:54.066659 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 13:29:54.504815 | localhost | changed
2025-10-13 13:29:54.524898 | 
2025-10-13 13:29:54.524967 | PLAY [localhost]
2025-10-13 13:29:54.537542 | 
2025-10-13 13:29:54.537606 | TASK [Generate bulk log download script]
2025-10-13 13:29:54.555857 | localhost | ok
2025-10-13 13:29:54.569916 | 
2025-10-13 13:29:54.569993 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 13:29:54.608955 | localhost | ok: All assertions passed
2025-10-13 13:29:54.613600 | 
2025-10-13 13:29:54.613662 | TASK [local-log-download : Create download script]
2025-10-13 13:29:55.117203 | localhost -> localhost | changed
2025-10-13 13:29:55.129326 | 
2025-10-13 13:29:55.129424 | TASK [Register quick-download link]
2025-10-13 13:29:55.148791 | localhost | ok
2025-10-13 13:29:55.197563 | 
2025-10-13 13:29:55.197665 | PLAY [logserver.rdoproject.org]
2025-10-13 13:29:55.207954 | 
2025-10-13 13:29:55.208136 | TASK [Set zuul-log-path fact]
2025-10-13 13:29:55.224364 | logserver.rdoproject.org | ok
2025-10-13 13:29:55.233855 | 
2025-10-13 13:29:55.233945 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 13:29:55.262894 | logserver.rdoproject.org | ok
2025-10-13 13:29:55.271488 | 
2025-10-13 13:29:55.271590 | TASK [upload-logs : Create log directories]
2025-10-13 13:29:55.934835 | logserver.rdoproject.org | changed
2025-10-13 13:29:55.942108 | 
2025-10-13 13:29:55.942244 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 13:29:56.233670 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009799
2025-10-13 13:29:56.238947 | 
2025-10-13 13:29:56.239046 | TASK [upload-logs : Upload logs to log server]
2025-10-13 13:29:57.047143 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 13:29:57.055047 | 
2025-10-13 13:29:57.055140 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 13:29:57.140568 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 13:29:57.152821 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 13:29:57.166901 | 
2025-10-13 13:29:57.167043 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 13:29:57.217180 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 13:29:57.217452 | 
2025-10-13 13:29:57.217974 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 13:29:57.226383 | 
2025-10-13 13:29:57.226505 | LOOP [upload-logs : Upload console log and json output]