2025-12-05 15:33:23.378728 | Job console starting...
2025-12-05 15:33:23.387077 | Updating repositories
2025-12-05 15:33:23.420411 | Preparing job workspace
2025-12-05 15:33:27.082143 | Running Ansible setup...
2025-12-05 15:33:31.063788 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:33:31.776338 | 
2025-12-05 15:33:31.776451 | PLAY [localhost]
2025-12-05 15:33:31.786341 | 
2025-12-05 15:33:31.786419 | TASK [Gathering Facts]
2025-12-05 15:33:33.473244 | localhost | ok
2025-12-05 15:33:33.497879 | 
2025-12-05 15:33:33.497991 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-05 15:33:34.251521 | localhost -> localhost | changed
2025-12-05 15:33:34.257178 | 
2025-12-05 15:33:34.257245 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-05 15:33:35.647919 | localhost -> localhost | changed
2025-12-05 15:33:35.656711 | 
2025-12-05 15:33:35.656777 | TASK [Setup log path fact]
2025-12-05 15:33:35.703380 | localhost | ok
2025-12-05 15:33:35.727816 | 
2025-12-05 15:33:35.727944 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:33:35.790692 | localhost | ok
2025-12-05 15:33:35.799000 | 
2025-12-05 15:33:35.799070 | TASK [emit-job-header : Print job information]
2025-12-05 15:33:35.925746 | # Job Information
2025-12-05 15:33:35.925909 | Ansible Version: 2.15.12
2025-12-05 15:33:35.925936 | Job: cifmw-molecule-polarion
2025-12-05 15:33:35.925955 | Pipeline: github-check
2025-12-05 15:33:35.925972 | Executor: ze04.softwarefactory-project.io
2025-12-05 15:33:35.925991 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539
2025-12-05 15:33:35.926009 | Log URL (when completed): https://logserver.rdoproject.org/6d5/rdoproject.org/6d567a2ff5db4eaf897ff0ced74880a0/
2025-12-05 15:33:35.926028 | Event ID: 757b9e30-d1ef-11f0-97eb-f505e6ea5a00
2025-12-05 15:33:35.929661 | 
2025-12-05 15:33:35.929774 | LOOP [emit-job-header : Print node information]
2025-12-05 15:33:36.145914 | localhost | ok:
2025-12-05 15:33:36.146087 | localhost | # Node Information
2025-12-05 15:33:36.146115 | localhost | Inventory Hostname: controller
2025-12-05 15:33:36.146140 | localhost | Hostname: np0005547434
2025-12-05 15:33:36.146159 | localhost | Username: zuul
2025-12-05 15:33:36.146179 | localhost | Distro: CentOS 9
2025-12-05 15:33:36.146197 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-05 15:33:36.146215 | localhost | Region: RegionOne
2025-12-05 15:33:36.146232 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-05 15:33:36.146248 | localhost | Product Name: OpenStack Nova
2025-12-05 15:33:36.146264 | localhost | Interface IP: 38.102.83.251
2025-12-05 15:33:36.194192 | 
2025-12-05 15:33:36.194305 | PLAY [all]
2025-12-05 15:33:36.210401 | 
2025-12-05 15:33:36.210488 | TASK [Gather network facts]
2025-12-05 15:33:36.647081 | controller | ok
2025-12-05 15:33:36.662428 | 
2025-12-05 15:33:36.662491 | TASK [include_role : start-zuul-console]
2025-12-05 15:33:36.680596 | controller | ok
2025-12-05 15:33:36.696976 | 
2025-12-05 15:33:36.697051 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-05 15:33:37.146333 | controller | ok
2025-12-05 15:33:37.155257 | 
2025-12-05 15:33:37.155317 | TASK [include_role : add-build-sshkey]
2025-12-05 15:33:37.174832 | controller | ok
2025-12-05 15:33:37.188367 | 
2025-12-05 15:33:37.188452 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 15:33:37.459984 | controller -> localhost | ok
2025-12-05 15:33:37.466147 | 
2025-12-05 15:33:37.466212 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 15:33:37.485274 | controller | ok
2025-12-05 15:33:37.510107 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 15:33:37.516647 | 
2025-12-05 15:33:37.516744 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 15:33:38.092888 | controller -> localhost | Generating public/private rsa key pair.
2025-12-05 15:33:38.093101 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/6d567a2ff5db4eaf897ff0ced74880a0_id_rsa.
2025-12-05 15:33:38.093132 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/6d567a2ff5db4eaf897ff0ced74880a0_id_rsa.pub.
2025-12-05 15:33:38.093154 | controller -> localhost | The key fingerprint is:
2025-12-05 15:33:38.093173 | controller -> localhost | SHA256:hyg/KSH9FJh6OWeec/isnfcVj0uReJzVIxArFthuYnM zuul-build-sshkey
2025-12-05 15:33:38.093191 | controller -> localhost | The key's randomart image is:
2025-12-05 15:33:38.093209 | controller -> localhost | +---[RSA 3072]----+
2025-12-05 15:33:38.093227 | controller -> localhost | |        o. o.    |
2025-12-05 15:33:38.093245 | controller -> localhost | |     o . .. o   .|
2025-12-05 15:33:38.093263 | controller -> localhost | |    o . .o . . .o|
2025-12-05 15:33:38.093280 | controller -> localhost | |   o . *.E.  o.+.|
2025-12-05 15:33:38.093297 | controller -> localhost | |  o B * S . . B  |
2025-12-05 15:33:38.093314 | controller -> localhost | |   o @ + .   . = |
2025-12-05 15:33:38.093331 | controller -> localhost | |    . X .     + .|
2025-12-05 15:33:38.093348 | controller -> localhost | |     . B ..  o . |
2025-12-05 15:33:38.093365 | controller -> localhost | |      ..=. .. .  |
2025-12-05 15:33:38.093382 | controller -> localhost | +----[SHA256]-----+
2025-12-05 15:33:38.093425 | controller -> localhost | ok: Runtime: 0:00:00.145501
2025-12-05 15:33:38.100021 | 
2025-12-05 15:33:38.100079 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 15:33:38.139037 | controller | ok
2025-12-05 15:33:38.158745 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 15:33:38.172708 | 
2025-12-05 15:33:38.172773 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 15:33:38.197306 | controller | skipping: Conditional result was False
2025-12-05 15:33:38.203009 | 
2025-12-05 15:33:38.203082 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 15:33:38.682179 | controller | changed
2025-12-05 15:33:38.687704 | 
2025-12-05 15:33:38.687769 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 15:33:38.934876 | controller | ok
2025-12-05 15:33:38.940491 | 
2025-12-05 15:33:38.940551 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 15:33:39.866004 | controller | changed
2025-12-05 15:33:39.870821 | 
2025-12-05 15:33:39.870881 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 15:33:40.669657 | controller | changed
2025-12-05 15:33:40.675027 | 
2025-12-05 15:33:40.675097 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 15:33:40.726938 | controller | skipping: Conditional result was False
2025-12-05 15:33:40.733404 | 
2025-12-05 15:33:40.733471 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 15:33:41.319456 | controller -> localhost | changed
2025-12-05 15:33:41.338895 | 
2025-12-05 15:33:41.338978 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 15:33:41.671464 | controller -> localhost | Identity added: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/6d567a2ff5db4eaf897ff0ced74880a0_id_rsa (zuul-build-sshkey)
2025-12-05 15:33:41.672581 | controller -> localhost | ok: Runtime: 0:00:00.008859
2025-12-05 15:33:41.678635 | 
2025-12-05 15:33:41.678721 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 15:33:42.282312 | controller | ok
2025-12-05 15:33:42.287301 | 
2025-12-05 15:33:42.287361 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 15:33:42.333014 | controller | skipping: Conditional result was False
2025-12-05 15:33:42.342286 | 
2025-12-05 15:33:42.342348 | TASK [include_role : validate-host]
2025-12-05 15:33:42.387877 | controller | ok
2025-12-05 15:33:42.456915 | 
2025-12-05 15:33:42.457039 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-05 15:33:42.515920 | controller | ok
2025-12-05 15:33:42.520528 | 
2025-12-05 15:33:42.520587 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-05 15:33:42.757576 | controller -> localhost | ok
2025-12-05 15:33:42.763500 | 
2025-12-05 15:33:42.763562 | TASK [validate-host : Collect information about the host]
2025-12-05 15:33:43.431658 | controller | ok
2025-12-05 15:33:43.440458 | 
2025-12-05 15:33:43.440519 | TASK [validate-host : Sanitize hostname]
2025-12-05 15:33:43.492721 | controller | ok
2025-12-05 15:33:43.504358 | 
2025-12-05 15:33:43.504486 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-05 15:33:44.071522 | controller -> localhost | changed
2025-12-05 15:33:44.077311 | 
2025-12-05 15:33:44.077380 | TASK [validate-host : Collect information about zuul worker]
2025-12-05 15:33:44.513539 | controller | ok
2025-12-05 15:33:44.518298 | 
2025-12-05 15:33:44.518359 | TASK [validate-host : Write out all zuul information for each host]
2025-12-05 15:33:44.999229 | controller -> localhost | changed
2025-12-05 15:33:45.008694 | 
2025-12-05 15:33:45.008753 | TASK [include_role : prepare-workspace-openshift]
2025-12-05 15:33:45.022038 | controller | skipping: Conditional result was False
2025-12-05 15:33:45.028079 | 
2025-12-05 15:33:45.028153 | TASK [include_role : remove-zuul-sshkey]
2025-12-05 15:33:45.054187 | controller | skipping: Conditional result was False
2025-12-05 15:33:45.060580 | 
2025-12-05 15:33:45.060646 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:33:45.328365 | controller | ok: "logs"
2025-12-05 15:33:45.328841 | controller | ok: All items complete
2025-12-05 15:33:45.328888 | 
2025-12-05 15:33:45.507930 | controller | ok: "artifacts"
2025-12-05 15:33:45.741640 | controller | ok: "docs"
2025-12-05 15:33:45.755453 | 
2025-12-05 15:33:45.755544 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:33:46.009388 | controller | changed: "logs"
2025-12-05 15:33:46.212941 | controller | changed: "artifacts"
2025-12-05 15:33:46.403515 | controller | changed: "docs"
2025-12-05 15:33:46.436291 | 
2025-12-05 15:33:46.436367 | PLAY RECAP
2025-12-05 15:33:46.436408 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-05 15:33:46.436433 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:33:46.436450 | 
2025-12-05 15:33:46.620346 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:33:46.621163 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:33:47.290761 | 
2025-12-05 15:33:47.290867 | PLAY [localhost]
2025-12-05 15:33:47.306674 | 
2025-12-05 15:33:47.306778 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-05 15:33:47.677097 | localhost | ok
2025-12-05 15:33:47.682889 | 
2025-12-05 15:33:47.682970 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-05 15:33:48.416345 | localhost | changed
2025-12-05 15:33:48.454115 | 
2025-12-05 15:33:48.454194 | PLAY [all]
2025-12-05 15:33:48.469786 | 
2025-12-05 15:33:48.469847 | TASK [include_role : prepare-workspace]
2025-12-05 15:33:48.497919 | controller | ok
2025-12-05 15:33:48.512341 | 
2025-12-05 15:33:48.512408 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-05 15:33:48.923026 | controller | ok
2025-12-05 15:33:48.945032 | 
2025-12-05 15:33:48.945126 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-05 15:33:50.728169 | controller | Output suppressed because no_log was given
2025-12-05 15:33:50.743064 | 
2025-12-05 15:33:50.743195 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:33:51.009972 | controller | changed: "logs"
2025-12-05 15:33:51.207551 | controller | changed: "artifacts"
2025-12-05 15:33:51.432289 | controller | changed: "docs"
2025-12-05 15:33:51.476541 | 
2025-12-05 15:33:51.476754 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:33:51.949229 | controller | changed: "logs"
2025-12-05 15:33:51.949447 | controller | changed: All items complete
2025-12-05 15:33:51.949474 | 
2025-12-05 15:33:52.198983 | controller | changed: "artifacts"
2025-12-05 15:33:52.409516 | controller | changed: "docs"
2025-12-05 15:33:52.439420 | 
2025-12-05 15:33:52.439696 | TASK [Check if worker can sudo]
2025-12-05 15:33:53.017383 | controller | ok: Runtime: 0:00:00.039422
2025-12-05 15:33:53.024074 | 
2025-12-05 15:33:53.024137 | TASK [configure-mirrors : Gather needed facts]
2025-12-05 15:33:53.078569 | controller | skipping: Conditional result was False
2025-12-05 15:33:53.084495 | 
2025-12-05 15:33:53.084564 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-05 15:33:53.199028 | controller | ok
2025-12-05 15:33:53.207100 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-05 15:33:53.308163 | 
2025-12-05 15:33:53.308307 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-05 15:33:53.657090 | controller | ok
2025-12-05 15:33:53.664423 | 
2025-12-05 15:33:53.664559 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-05 15:33:53.714572 | controller | ok: "/var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-05 15:33:53.727089 | 
2025-12-05 15:33:53.727199 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-05 15:33:54.576704 | controller | changed
2025-12-05 15:33:54.588971 | 
2025-12-05 15:33:54.589037 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-05 15:33:54.670332 | controller | ok: "/var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-05 15:33:54.670536 | controller | ok: All items complete
2025-12-05 15:33:54.670564 | 
2025-12-05 15:33:54.715082 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-05 15:33:54.721896 | 
2025-12-05 15:33:54.721960 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-05 15:33:55.596292 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-05 15:33:56.343413 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-05 15:33:56.361157 | 
2025-12-05 15:33:56.361268 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-05 15:33:56.820451 | controller | changed: section and option added
2025-12-05 15:33:56.843231 | 
2025-12-05 15:33:56.843351 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-05 15:33:57.420951 | controller | 29 files removed
2025-12-05 15:33:57.421187 | controller | ok: Item: dnf clean all Runtime: 0:00:00.272136
2025-12-05 15:33:57.421243 | controller | changed: All items complete
2025-12-05 15:33:57.421272 | 
2025-12-05 15:34:08.449553 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-12-05 15:34:08.450217 | controller | DNF version: 4.14.0
2025-12-05 15:34:08.450259 | controller | cachedir: /var/cache/dnf
2025-12-05 15:34:08.450282 | controller | Making cache files for all metadata files.
2025-12-05 15:34:08.450300 | controller | baseos: has expired and will be refreshed.
2025-12-05 15:34:08.450318 | controller | appstream: has expired and will be refreshed.
2025-12-05 15:34:08.450334 | controller | crb: has expired and will be refreshed.
2025-12-05 15:34:08.450357 | controller | extras-common: has expired and will be refreshed.
2025-12-05 15:34:08.450373 | controller | repo: downloading from remote: baseos
2025-12-05 15:34:08.450389 | controller | CentOS Stream 9 - BaseOS                         68 MB/s | 8.8 MB     00:00
2025-12-05 15:34:08.450405 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-05 15:34:08.450421 | controller | repo: downloading from remote: appstream
2025-12-05 15:34:08.450437 | controller | CentOS Stream 9 - AppStream                      73 MB/s |  25 MB     00:00
2025-12-05 15:34:08.450452 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-05 15:34:08.450468 | controller | repo: downloading from remote: crb
2025-12-05 15:34:08.450483 | controller | CentOS Stream 9 - CRB                            69 MB/s | 7.3 MB     00:00
2025-12-05 15:34:08.450500 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-05 15:34:08.450516 | controller | repo: downloading from remote: extras-common
2025-12-05 15:34:08.450532 | controller | CentOS Stream 9 - Extras packages               1.6 MB/s |  20 kB     00:00
2025-12-05 15:34:08.450548 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-05 15:34:08.450563 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-05 15:34:08.450579 | controller | Completion plugin: Generating completion cache...
2025-12-05 15:34:08.450595 | controller | Metadata cache created.
2025-12-05 15:34:08.450619 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.797210
2025-12-05 15:34:08.471767 | 
2025-12-05 15:34:08.471817 | PLAY RECAP
2025-12-05 15:34:08.471857 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-05 15:34:08.471881 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:34:08.471898 | 
2025-12-05 15:34:08.564921 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:34:08.565982 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:34:09.232735 | 
2025-12-05 15:34:09.232846 | PLAY [all]
2025-12-05 15:34:09.293035 | 
2025-12-05 15:34:09.293210 | TASK [Install binary dependencies]
2025-12-05 15:34:09.373520 | controller | ok
2025-12-05 15:34:09.397497 | 
2025-12-05 15:34:09.397640 | TASK [bindep : Include find tasks]
2025-12-05 15:34:09.426672 | controller | ok
2025-12-05 15:34:09.434173 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-05 15:34:09.439968 | 
2025-12-05 15:34:09.440096 | TASK [bindep : Look for bindep.txt]
2025-12-05 15:34:09.824411 | controller | ok
2025-12-05 15:34:09.832847 | 
2025-12-05 15:34:09.832963 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:34:09.862831 | controller | ok
2025-12-05 15:34:09.867737 | 
2025-12-05 15:34:09.867799 | TASK [bindep : Look for other-requirements.txt]
2025-12-05 15:34:09.881555 | controller | skipping: Conditional result was False
2025-12-05 15:34:09.887661 | 
2025-12-05 15:34:09.887751 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:34:09.911986 | controller | skipping: Conditional result was False
2025-12-05 15:34:09.917505 | 
2025-12-05 15:34:09.917568 | TASK [bindep : Look for bindep fallback file]
2025-12-05 15:34:09.941518 | controller | skipping: Conditional result was False
2025-12-05 15:34:09.946930 | 
2025-12-05 15:34:09.946996 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:34:09.970869 | controller | skipping: Conditional result was False
2025-12-05 15:34:09.978271 | 
2025-12-05 15:34:09.978353 | TASK [bindep : Include bindep tasks]
2025-12-05 15:34:10.011136 | controller | ok
2025-12-05 15:34:10.019710 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-05 15:34:10.030175 | 
2025-12-05 15:34:10.030258 | TASK [bindep : Look for bindep command]
2025-12-05 15:34:10.065894 | controller | skipping: Conditional result was False
2025-12-05 15:34:10.073218 | 
2025-12-05 15:34:10.073282 | TASK [bindep : Check for system bindep]
2025-12-05 15:34:10.604703 | controller | ok: Runtime: 0:00:00.006739
2025-12-05 15:34:10.610763 | 
2025-12-05 15:34:10.610828 | TASK [bindep : Define bindep_command fact]
2025-12-05 15:34:10.634927 | controller | skipping: Conditional result was False
2025-12-05 15:34:10.647973 | 
2025-12-05 15:34:10.648110 | TASK [bindep : Include install tasks]
2025-12-05 15:34:10.681600 | controller | ok
2025-12-05 15:34:10.689508 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-05 15:34:10.698043 | 
2025-12-05 15:34:10.698104 | TASK [bindep : Create temp dir for bindep]
2025-12-05 15:34:11.061568 | controller | changed
2025-12-05 15:34:11.066749 | 
2025-12-05 15:34:11.066810 | TASK [Ensure we have pip dependencies]
2025-12-05 15:34:11.085385 | controller | ok
2025-12-05 15:34:11.108767 | 
2025-12-05 15:34:11.108833 | TASK [ensure-pip : Check if pip is installed]
2025-12-05 10:34:11.369633 | controller | /usr/bin/pip3
2025-12-05 10:34:11.399676 | controller | /usr/bin/python3: No module named wheel
2025-12-05 15:34:11.634736 | controller | ok: Runtime: 0:00:00.040744
2025-12-05 15:34:11.640658 | 
2025-12-05 15:34:11.640746 | LOOP [ensure-pip : Install pip from packages]
2025-12-05 15:34:11.683193 | controller | ok: "/var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-05 15:34:11.692778 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-05 15:34:11.717261 | 
2025-12-05 15:34:11.717351 | TASK [ensure-pip : Install Python 3 pip]
2025-12-05 15:34:13.605497 | controller | changed
2025-12-05 15:34:13.613572 | 
2025-12-05 15:34:13.613655 | TASK [ensure-pip : Check for EPEL repository]
2025-12-05 15:34:13.682436 | controller | skipping: Conditional result was False
2025-12-05 15:34:13.700468 | 
2025-12-05 15:34:13.700562 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-05 15:34:13.757669 | controller | skipping: Conditional result was False
2025-12-05 15:34:13.763958 | 
2025-12-05 15:34:13.764049 | TASK [ensure-pip : Install Python 2 pip]
2025-12-05 15:34:13.798005 | controller | skipping: Conditional result was False
2025-12-05 15:34:13.804629 | 
2025-12-05 15:34:13.804727 | TASK [ensure-pip : Ensure setuptools]
2025-12-05 15:34:13.832608 | controller | skipping: Conditional result was False
2025-12-05 15:34:13.841054 | 
2025-12-05 15:34:13.841124 | TASK [ensure-pip : Check for ensurepip module]
2025-12-05 15:34:14.379073 | controller | skipping: Conditional result was False
2025-12-05 15:34:14.385104 | 
2025-12-05 15:34:14.385170 | TASK [ensure-pip : Ensure python3-venv]
2025-12-05 15:34:14.422950 | controller | skipping: Conditional result was False
2025-12-05 15:34:14.443705 | 
2025-12-05 15:34:14.443872 | TASK [ensure-pip : Install pip from source]
2025-12-05 15:34:14.469503 | controller | skipping: Conditional result was False
2025-12-05 15:34:14.477588 | 
2025-12-05 15:34:14.477737 | TASK [ensure-pip : Probe for venv python full path]
2025-12-05 10:34:14.728927 | controller | /usr/bin/python3
2025-12-05 15:34:15.012196 | controller | ok: Runtime: 0:00:00.006051
2025-12-05 15:34:15.017994 | 
2025-12-05 15:34:15.018061 | TASK [ensure-pip : Set host default]
2025-12-05 15:34:15.087406 | controller | ok
2025-12-05 15:34:15.094143 | 
2025-12-05 15:34:15.094337 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-05 15:34:15.145881 | controller | ok
2025-12-05 15:34:15.160299 | 
2025-12-05 15:34:15.160374 | TASK [bindep : Install bindep into temporary venv]
2025-12-05 15:34:19.584228 | controller | changed
2025-12-05 15:34:19.595933 | 
2025-12-05 15:34:19.596078 | TASK [bindep : Define bindep_command]
2025-12-05 15:34:19.644516 | controller | ok
2025-12-05 15:34:19.655797 | 
2025-12-05 15:34:19.655928 | LOOP [bindep : Include package tasks]
2025-12-05 15:34:19.744590 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-05 15:34:19.744907 | controller | ok: All items complete
2025-12-05 15:34:19.744964 | 
2025-12-05 15:34:19.766344 | controller | included: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-05 15:34:19.787875 | 
2025-12-05 15:34:19.787964 | TASK [bindep : Define bindep_run fact]
2025-12-05 15:34:19.829884 | controller | ok
2025-12-05 15:34:19.837009 | 
2025-12-05 15:34:19.837094 | TASK [bindep : Get list of packages to install from bindep]
2025-12-05 10:34:21.094887 | controller | podman
2025-12-05 10:34:21.128330 | controller | python3-jmespath
2025-12-05 10:34:21.128476 | controller | python3-libvirt
2025-12-05 10:34:21.128490 | controller | python3-lxml
2025-12-05 10:34:21.128503 | controller | python3-netaddr
2025-12-05 15:34:21.377929 | controller | ok: Runtime: 0:00:01.034049
2025-12-05 15:34:21.390593 | 
2025-12-05 15:34:21.390805 | TASK [bindep : Install distro packages from bindep]
2025-12-05 15:35:23.562347 | controller | changed
2025-12-05 15:35:23.568417 | 
2025-12-05 15:35:23.568480 | TASK [bindep : Check that packages are installed]
2025-12-05 15:35:25.099746 | controller | ok: Runtime: 0:00:01.112723
2025-12-05 15:35:25.106326 | 
2025-12-05 15:35:25.106392 | TASK [bindep : Fail if we cannot install all packages]
2025-12-05 15:35:25.140619 | controller | skipping: Conditional result was False
2025-12-05 15:35:25.151926 | 
2025-12-05 15:35:25.151998 | TASK [Run test-setup role]
2025-12-05 15:35:25.192222 | controller | ok
2025-12-05 15:35:25.224012 | 
2025-12-05 15:35:25.224125 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-05 15:35:25.465229 | controller | ok
2025-12-05 15:35:25.470537 | 
2025-12-05 15:35:25.470602 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-05 15:35:25.999709 | controller | skipping: Conditional result was False
2025-12-05 15:35:26.040810 | 
2025-12-05 15:35:26.043938 | TASK [bindep : Remove bindep temp dir]
2025-12-05 15:35:26.540197 | controller | ok
2025-12-05 15:35:26.565139 | 
2025-12-05 15:35:26.565245 | PLAY RECAP
2025-12-05 15:35:26.565291 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-05 15:35:26.565313 | 
2025-12-05 15:35:26.708111 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:35:26.708975 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:35:28.100641 | 
2025-12-05 15:35:28.100786 | PLAY [all]
2025-12-05 15:35:28.144065 | 
2025-12-05 15:35:28.144217 | TASK [Abort when test_command variable is undefined]
2025-12-05 15:35:28.179180 | controller | skipping: Conditional result was False
2025-12-05 15:35:28.184926 | 
2025-12-05 15:35:28.184999 | TASK [Convert test_command to list]
2025-12-05 15:35:28.259495 | controller | skipping: Conditional result was False
2025-12-05 15:35:28.265744 | 
2025-12-05 15:35:28.265809 | TASK [Use test_command list]
2025-12-05 15:35:28.355106 | controller | ok
2025-12-05 15:35:28.368074 | 
2025-12-05 15:35:28.368137 | LOOP [Run test_command]
2025-12-05 15:35:28.794414 | controller | no check to run
2025-12-05 15:35:28.794596 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004214
2025-12-05 15:35:28.816737 | 
2025-12-05 15:35:28.816791 | PLAY RECAP
2025-12-05 15:35:28.816828 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:35:28.816848 | 
2025-12-05 15:35:28.955513 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:35:28.956372 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:35:29.709604 | 
2025-12-05 15:35:29.710051 | PLAY [all]
2025-12-05 15:35:29.744028 | 
2025-12-05 15:35:29.744156 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-05 15:35:30.121673 | controller | changed: non-zero return code
2025-12-05 15:35:30.136229 | 
2025-12-05 15:35:30.136508 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-05 15:35:30.165909 | controller | skipping: Conditional result was False
2025-12-05 15:35:30.174395 | 
2025-12-05 15:35:30.174487 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-05 15:35:30.215935 | 
2025-12-05 15:35:30.216087 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-05 15:35:30.276848 | 
2025-12-05 15:35:30.277014 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-05 15:35:30.338288 | controller | skipping: Conditional result was False
2025-12-05 15:35:30.344870 | 
2025-12-05 15:35:30.344938 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-05 15:35:30.409017 | 
2025-12-05 15:35:30.409177 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-05 15:35:30.439217 | controller | skipping: Conditional result was False
2025-12-05 15:35:30.445183 | 
2025-12-05 15:35:30.445259 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-05 15:35:30.469193 | controller | skipping: Conditional result was False
2025-12-05 15:35:30.474693 | 
2025-12-05 15:35:30.474772 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-05 15:35:30.498357 | controller | skipping: Conditional result was False
2025-12-05 15:35:30.533654 | 
2025-12-05 15:35:30.533805 | PLAY RECAP
2025-12-05 15:35:30.533852 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-05 15:35:30.533872 | 
2025-12-05 15:35:30.624868 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:35:30.625751 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:35:31.353970 | 
2025-12-05 15:35:31.354134 | PLAY [all]
2025-12-05 15:35:31.376241 | 
2025-12-05 15:35:31.376351 | TASK [include_role : fetch-output]
2025-12-05 15:35:31.424211 | controller | ok
2025-12-05 15:35:31.447725 | 
2025-12-05 15:35:31.447828 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 15:35:31.492009 | controller | skipping: Conditional result was False
2025-12-05 15:35:31.498099 | 
2025-12-05 15:35:31.498166 | TASK [fetch-output : Set log path for single node]
2025-12-05 15:35:31.537097 | controller | ok
2025-12-05 15:35:31.545341 | 
2025-12-05 15:35:31.545419 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 15:35:32.215620 | controller -> localhost | ok: "/var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/logs"
2025-12-05 15:35:32.436184 | controller -> localhost | changed: "/var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/artifacts"
2025-12-05 15:35:32.649377 | controller -> localhost | changed: "/var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/docs"
2025-12-05 15:35:32.666541 | 
2025-12-05 15:35:32.666638 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 15:35:33.277150 | controller | changed: .d..t...... ./
2025-12-05 15:35:33.277336 | controller | changed: All items complete
2025-12-05 15:35:33.277364 | 
2025-12-05 15:35:33.825559 | controller | changed: .d..t...... ./
2025-12-05 15:35:34.285575 | controller | changed: .d..t...... ./
2025-12-05 15:35:34.308430 | 
2025-12-05 15:35:34.308545 | TASK [include_role : fetch-output-openshift]
2025-12-05 15:35:34.346275 | controller | skipping: Conditional result was False
2025-12-05 15:35:34.352760 | 
2025-12-05 15:35:34.352829 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-05 15:35:34.823223 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007443
2025-12-05 15:35:35.038162 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.011875
2025-12-05 15:35:35.087804 | 
2025-12-05 15:35:35.087892 | PLAY [all]
2025-12-05 15:35:35.105214 | 
2025-12-05 15:35:35.105277 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-05 15:35:35.546135 | controller | changed
2025-12-05 15:35:35.575583 | 
2025-12-05 15:35:35.575632 | PLAY RECAP
2025-12-05 15:35:35.575673 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:35:35.575781 | 
2025-12-05 15:35:35.664897 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:35:35.665895 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-05 15:35:36.335029 | 
2025-12-05 15:35:36.335140 | PLAY [localhost]
2025-12-05 15:35:36.352980 | 
2025-12-05 15:35:36.353063 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-05 15:35:36.718069 | localhost | changed
2025-12-05 15:35:36.724512 | 
2025-12-05 15:35:36.724628 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-05 15:35:36.752217 | localhost | ok
2025-12-05 15:35:36.760268 | 
2025-12-05 15:35:36.760332 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-05 15:35:37.187567 | localhost | changed
2025-12-05 15:35:37.194845 | 
2025-12-05 15:35:37.194918 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-05 15:35:37.924812 | localhost | changed
2025-12-05 15:35:37.931954 | 
2025-12-05 15:35:37.932093 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-05 15:35:38.310416 | localhost | Identity added: /var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/tmp/ansible.w0hhsmxb (/var/lib/zuul/builds/6d567a2ff5db4eaf897ff0ced74880a0/work/tmp/ansible.w0hhsmxb)
2025-12-05 15:35:38.310611 | localhost | ok: Runtime: 0:00:00.009011
2025-12-05 15:35:38.315045 | 
2025-12-05 15:35:38.315112 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-05 15:35:38.622565 | localhost | ok: Runtime: 0:00:00.005359
2025-12-05 15:35:38.627728 | 
2025-12-05 15:35:38.627831 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-05 15:35:38.677461 | localhost | changed
2025-12-05 15:35:38.681662 | 
2025-12-05 15:35:38.681755 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-05 15:35:39.122400 | localhost | changed
2025-12-05 15:35:39.151632 | 
2025-12-05 15:35:39.151747 | PLAY [localhost]
2025-12-05 15:35:39.172045 | 
2025-12-05 15:35:39.172106 | TASK [Generate bulk log download script]
2025-12-05 15:35:39.199575 | localhost | ok
2025-12-05 15:35:39.211375 | 
2025-12-05 15:35:39.211435 | TASK [local-log-download : Check API endpoint is defined]
2025-12-05 15:35:39.238318 | localhost | ok: All assertions passed
2025-12-05 15:35:39.243236 | 
2025-12-05 15:35:39.243295 | TASK [local-log-download : Create download script]
2025-12-05 15:35:39.783285 | localhost -> localhost | changed
2025-12-05 15:35:39.793095 | 
2025-12-05 15:35:39.793162 | TASK [Register quick-download link]
2025-12-05 15:35:39.811323 | localhost | ok
2025-12-05 15:35:39.885634 | 
2025-12-05 15:35:39.885744 | PLAY [logserver.rdoproject.org]
2025-12-05 15:35:39.901236 | 
2025-12-05 15:35:39.901305 | TASK [Set zuul-log-path fact]
2025-12-05 15:35:39.927537 | logserver.rdoproject.org | ok
2025-12-05 15:35:39.936814 | 
2025-12-05 15:35:39.936877 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:35:39.964393 | logserver.rdoproject.org | ok
2025-12-05 15:35:39.973572 | 
2025-12-05 15:35:39.973647 | TASK [upload-logs : Create log directories]
2025-12-05 15:35:40.610664 | logserver.rdoproject.org | changed
2025-12-05 15:35:40.614275 | 
2025-12-05 15:35:40.614336 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-05 15:35:40.902719 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009746
2025-12-05 15:35:40.907513 | 
2025-12-05 15:35:40.907607 | TASK [upload-logs : Upload logs to log server]
2025-12-05 15:35:41.771795 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-05 15:35:41.780438 | 
2025-12-05 15:35:41.780530 | LOOP [upload-logs : Compress console log and json output]
2025-12-05 15:35:41.824758 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:41.835909 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:41.840695 | 
2025-12-05 15:35:41.840786 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-05 15:35:41.883513 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:41.883770 | 
2025-12-05 15:35:41.884261 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:41.889893 | 
2025-12-05 15:35:41.890012 | LOOP [upload-logs : Upload console log and json output]