2026-01-08 12:02:32.329144 | Job console starting...
2026-01-08 12:02:32.342994 | Updating repositories
2026-01-08 12:02:32.370499 | Preparing job workspace
2026-01-08 12:02:35.870464 | Running Ansible setup...
2026-01-08 12:02:39.805337 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-01-08 12:02:40.389479 | 
2026-01-08 12:02:40.389624 | PLAY [localhost]
2026-01-08 12:02:40.398597 | 
2026-01-08 12:02:40.398680 | TASK [Gathering Facts]
2026-01-08 12:02:41.456604 | localhost | ok
2026-01-08 12:02:41.497362 | 
2026-01-08 12:02:41.497605 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-08 12:02:41.956498 | localhost -> localhost | changed
2026-01-08 12:02:41.962248 | 
2026-01-08 12:02:41.962331 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-08 12:02:42.840302 | localhost -> localhost | changed
2026-01-08 12:02:42.849158 | 
2026-01-08 12:02:42.849226 | TASK [Setup log path fact]
2026-01-08 12:02:42.871719 | localhost | ok
2026-01-08 12:02:42.888890 | 
2026-01-08 12:02:42.888979 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-08 12:02:42.916877 | localhost | ok
2026-01-08 12:02:42.924508 | 
2026-01-08 12:02:42.924577 | TASK [emit-job-header : Print job information]
2026-01-08 12:02:42.973635 | # Job Information
2026-01-08 12:02:42.973842 | Ansible Version: 2.15.12
2026-01-08 12:02:42.973871 | Job: cifmw-molecule-cifmw_setup
2026-01-08 12:02:42.973892 | Pipeline: github-check
2026-01-08 12:02:42.973910 | Executor: ze03.softwarefactory-project.io
2026-01-08 12:02:42.973928 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3193
2026-01-08 12:02:42.973948 | Log URL (when completed): https://logserver.rdoproject.org/568/rdoproject.org/56884583d4b241a88f02762fa890fb68/
2026-01-08 12:02:42.973967 | Event ID: bb9a1f40-ec89-11f0-9b09-eaf310094f71
2026-01-08 12:02:42.977529 | 
2026-01-08 12:02:42.977588 | LOOP [emit-job-header : Print node information]
2026-01-08 12:02:43.133414 | localhost | ok:
2026-01-08 12:02:43.133569 | localhost | # Node Information
2026-01-08 12:02:43.133595 | localhost | Inventory Hostname: controller
2026-01-08 12:02:43.133617 | localhost | Hostname: np0005577853
2026-01-08 12:02:43.133636 | localhost | Username: zuul
2026-01-08 12:02:43.133655 | localhost | Distro: CentOS 9
2026-01-08 12:02:43.133673 | localhost | Provider: vexxhost-nodepool-tripleo
2026-01-08 12:02:43.133690 | localhost | Region: RegionOne
2026-01-08 12:02:43.133706 | localhost | Label: cloud-centos-9-stream-tripleo
2026-01-08 12:02:43.133792 | localhost | Product Name: OpenStack Nova
2026-01-08 12:02:43.133827 | localhost | Interface IP: 38.102.83.220
2026-01-08 12:02:43.156447 | 
2026-01-08 12:02:43.156544 | PLAY [all]
2026-01-08 12:02:43.163003 | 
2026-01-08 12:02:43.163085 | TASK [Gather network facts]
2026-01-08 12:02:43.742649 | controller | ok
2026-01-08 12:02:43.757859 | 
2026-01-08 12:02:43.757966 | TASK [include_role : start-zuul-console]
2026-01-08 12:02:43.786244 | controller | ok
2026-01-08 12:02:43.797541 | 
2026-01-08 12:02:43.797604 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-08 12:02:44.244235 | controller | ok
2026-01-08 12:02:44.256699 | 
2026-01-08 12:02:44.256809 | TASK [include_role : add-build-sshkey]
2026-01-08 12:02:44.285826 | controller | ok
2026-01-08 12:02:44.307561 | 
2026-01-08 12:02:44.307816 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-08 12:02:44.564800 | controller -> localhost | ok
2026-01-08 12:02:44.571333 | 
2026-01-08 12:02:44.571399 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-08 12:02:44.600762 | controller | ok
2026-01-08 12:02:44.615011 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-08 12:02:44.621428 | 
2026-01-08 12:02:44.621492 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-08 12:02:45.811659 | controller -> localhost | Generating public/private rsa key pair.
2026-01-08 12:02:45.811875 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/56884583d4b241a88f02762fa890fb68_id_rsa.
2026-01-08 12:02:45.811906 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/56884583d4b241a88f02762fa890fb68_id_rsa.pub.
2026-01-08 12:02:45.811929 | controller -> localhost | The key fingerprint is:
2026-01-08 12:02:45.811949 | controller -> localhost | SHA256:a7G4glPO24AXOv9Jv7fOHs5nxzMFO+aQAHcXcmaXTo4 zuul-build-sshkey
2026-01-08 12:02:45.811970 | controller -> localhost | The key's randomart image is:
2026-01-08 12:02:45.811989 | controller -> localhost | +---[RSA 3072]----+
2026-01-08 12:02:45.812007 | controller -> localhost | |            . =.o|
2026-01-08 12:02:45.812026 | controller -> localhost | |        . . .=.+ |
2026-01-08 12:02:45.812044 | controller -> localhost | |         o . .=  |
2026-01-08 12:02:45.812062 | controller -> localhost | |          .  E.o |
2026-01-08 12:02:45.812080 | controller -> localhost | |    .   S  . . o |
2026-01-08 12:02:45.812097 | controller -> localhost | |   o.. . +  o + .|
2026-01-08 12:02:45.812115 | controller -> localhost | |  +=o o + .  = o |
2026-01-08 12:02:45.812133 | controller -> localhost | |  o+++ = +..o *  |
2026-01-08 12:02:45.812151 | controller -> localhost | |   .o+= o=B+ . o |
2026-01-08 12:02:45.812168 | controller -> localhost | +----[SHA256]-----+
2026-01-08 12:02:45.812209 | controller -> localhost | ok: Runtime: 0:00:00.774936
2026-01-08 12:02:45.817919 | 
2026-01-08 12:02:45.817984 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-08 12:02:45.836931 | controller | ok
2026-01-08 12:02:45.858158 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-08 12:02:45.878027 | 
2026-01-08 12:02:45.878120 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-08 12:02:45.927263 | controller | skipping: Conditional result was False
2026-01-08 12:02:45.933015 | 
2026-01-08 12:02:45.933083 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-08 12:02:46.431844 | controller | changed
2026-01-08 12:02:46.436917 | 
2026-01-08 12:02:46.436978 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-08 12:02:46.729255 | controller | ok
2026-01-08 12:02:46.734255 | 
2026-01-08 12:02:46.734318 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-08 12:02:47.713777 | controller | changed
2026-01-08 12:02:47.723351 | 
2026-01-08 12:02:47.723473 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-08 12:02:48.580106 | controller | changed
2026-01-08 12:02:48.586362 | 
2026-01-08 12:02:48.586457 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-08 12:02:48.610716 | controller | skipping: Conditional result was False
2026-01-08 12:02:48.616940 | 
2026-01-08 12:02:48.617043 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-08 12:02:49.052671 | controller -> localhost | changed
2026-01-08 12:02:49.067464 | 
2026-01-08 12:02:49.067578 | TASK [add-build-sshkey : Add back temp key]
2026-01-08 12:02:49.380141 | controller -> localhost | Identity added: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/56884583d4b241a88f02762fa890fb68_id_rsa (zuul-build-sshkey)
2026-01-08 12:02:49.380317 | controller -> localhost | ok: Runtime: 0:00:00.008918
2026-01-08 12:02:49.385824 | 
2026-01-08 12:02:49.385885 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-08 12:02:49.785334 | controller | ok
2026-01-08 12:02:49.796019 | 
2026-01-08 12:02:49.796171 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-08 12:02:49.833285 | controller | skipping: Conditional result was False
2026-01-08 12:02:49.847284 | 
2026-01-08 12:02:49.847422 | TASK [include_role : validate-host]
2026-01-08 12:02:49.880670 | controller | ok
2026-01-08 12:02:49.909652 | 
2026-01-08 12:02:49.909827 | TASK [validate-host : Define zuul_info_dir fact]
2026-01-08 12:02:49.953672 | controller | ok
2026-01-08 12:02:49.959505 | 
2026-01-08 12:02:49.959570 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2026-01-08 12:02:50.239083 | controller -> localhost | ok
2026-01-08 12:02:50.244172 | 
2026-01-08 12:02:50.244234 | TASK [validate-host : Collect information about the host]
2026-01-08 12:02:52.019644 | controller | ok
2026-01-08 12:02:52.032797 | 
2026-01-08 12:02:52.032940 | TASK [validate-host : Sanitize hostname]
2026-01-08 12:02:52.118109 | controller | ok
2026-01-08 12:02:52.124621 | 
2026-01-08 12:02:52.124696 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2026-01-08 12:02:52.616997 | controller -> localhost | changed
2026-01-08 12:02:52.622773 | 
2026-01-08 12:02:52.622869 | TASK [validate-host : Collect information about zuul worker]
2026-01-08 12:02:53.038436 | controller | ok
2026-01-08 12:02:53.043602 | 
2026-01-08 12:02:53.043671 | TASK [validate-host : Write out all zuul information for each host]
2026-01-08 12:02:53.529198 | controller -> localhost | changed
2026-01-08 12:02:53.540247 | 
2026-01-08 12:02:53.540315 | TASK [include_role : prepare-workspace-openshift]
2026-01-08 12:02:53.554249 | controller | skipping: Conditional result was False
2026-01-08 12:02:53.560340 | 
2026-01-08 12:02:53.560437 | TASK [include_role : remove-zuul-sshkey]
2026-01-08 12:02:53.577067 | controller | skipping: Conditional result was False
2026-01-08 12:02:53.584568 | 
2026-01-08 12:02:53.584662 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-08 12:02:53.871142 | controller | ok: "logs"
2026-01-08 12:02:53.871807 | controller | ok: All items complete
2026-01-08 12:02:53.871890 | 
2026-01-08 12:02:54.069558 | controller | ok: "artifacts"
2026-01-08 12:02:54.271505 | controller | ok: "docs"
2026-01-08 12:02:54.286297 | 
2026-01-08 12:02:54.286390 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-08 12:02:54.600363 | controller | changed: "logs"
2026-01-08 12:02:54.845083 | controller | changed: "artifacts"
2026-01-08 12:02:55.103205 | controller | changed: "docs"
2026-01-08 12:02:55.156874 | 
2026-01-08 12:02:55.156990 | PLAY RECAP
2026-01-08 12:02:55.157058 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-01-08 12:02:55.157095 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-08 12:02:55.157118 | 
2026-01-08 12:02:55.283400 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-01-08 12:02:55.285030 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2026-01-08 12:02:55.938763 | 
2026-01-08 12:02:55.938893 | PLAY [localhost]
2026-01-08 12:02:55.959638 | 
2026-01-08 12:02:55.959755 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2026-01-08 12:02:56.311301 | localhost | ok
2026-01-08 12:02:56.316307 | 
2026-01-08 12:02:56.316380 | TASK [configure-ssh-config-fips : Setup ssh config]
2026-01-08 12:02:57.008170 | localhost | changed
2026-01-08 12:02:57.030497 | 
2026-01-08 12:02:57.030649 | PLAY [all]
2026-01-08 12:02:57.046525 | 
2026-01-08 12:02:57.046620 | TASK [include_role : prepare-workspace]
2026-01-08 12:02:57.075486 | controller | ok
2026-01-08 12:02:57.094762 | 
2026-01-08 12:02:57.094930 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-08 12:02:57.493939 | controller | ok
2026-01-08 12:02:57.503019 | 
2026-01-08 12:02:57.503095 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-08 12:02:59.453926 | controller | Output suppressed because no_log was given
2026-01-08 12:02:59.466686 | 
2026-01-08 12:02:59.466803 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-08 12:02:59.790855 | controller | changed: "logs"
2026-01-08 12:03:00.038164 | controller | changed: "artifacts"
2026-01-08 12:03:00.279907 | controller | changed: "docs"
2026-01-08 12:03:00.290574 | 
2026-01-08 12:03:00.290786 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-08 12:03:00.545160 | controller | changed: "logs"
2026-01-08 12:03:00.545383 | controller | changed: All items complete
2026-01-08 12:03:00.545420 | 
2026-01-08 12:03:00.810363 | controller | changed: "artifacts"
2026-01-08 12:03:01.064449 | controller | changed: "docs"
2026-01-08 12:03:01.078658 | 
2026-01-08 12:03:01.078788 | TASK [Check if worker can sudo]
2026-01-08 12:03:01.629059 | controller | ok: Runtime: 0:00:00.052792
2026-01-08 12:03:01.634345 | 
2026-01-08 12:03:01.634415 | TASK [configure-mirrors : Gather needed facts]
2026-01-08 12:03:01.691333 | controller | skipping: Conditional result was False
2026-01-08 12:03:01.703921 | 
2026-01-08 12:03:01.704120 | TASK [configure-mirrors : Set up infrastructure mirrors]
2026-01-08 12:03:01.792957 | controller | ok
2026-01-08 12:03:01.804440 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2026-01-08 12:03:01.835936 | 
2026-01-08 12:03:01.836053 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2026-01-08 12:03:02.201613 | controller | ok
2026-01-08 12:03:02.207225 | 
2026-01-08 12:03:02.207286 | LOOP [configure-mirrors : Include OS-specific variables]
2026-01-08 12:03:02.286228 | controller | ok: "/var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2026-01-08 12:03:02.302913 | 
2026-01-08 12:03:02.303053 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2026-01-08 12:03:03.348648 | controller | changed
2026-01-08 12:03:03.354327 | 
2026-01-08 12:03:03.354386 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2026-01-08 12:03:03.413132 | controller | ok: "/var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2026-01-08 12:03:03.413337 | controller | ok: All items complete
2026-01-08 12:03:03.413364 | 
2026-01-08 12:03:03.457807 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2026-01-08 12:03:03.464376 | 
2026-01-08 12:03:03.464462 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2026-01-08 12:03:04.437567 | controller | changed: "etc/yum.repos.d/centos.repo"
2026-01-08 12:03:05.470092 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2026-01-08 12:03:05.494353 | 
2026-01-08 12:03:05.494491 | TASK [configure-mirrors : Disable deltrarpm]
2026-01-08 12:03:05.953291 | controller | changed: section and option added
2026-01-08 12:03:05.991702 | 
2026-01-08 12:03:05.991896 | LOOP [configure-mirrors : Update yum/dnf cache]
2026-01-08 12:03:06.653032 | controller | 29 files removed
2026-01-08 12:03:06.653441 | controller | ok: Item: dnf clean all Runtime: 0:00:00.263016
2026-01-08 12:03:06.653699 | controller | changed: All items complete
2026-01-08 12:03:06.653804 | 
2026-01-08 12:03:17.465545 | 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
2026-01-08 12:03:17.465665 | controller | DNF version: 4.14.0
2026-01-08 12:03:17.465689 | controller | cachedir: /var/cache/dnf
2026-01-08 12:03:17.465708 | controller | Making cache files for all metadata files.
2026-01-08 12:03:17.465747 | controller | baseos: has expired and will be refreshed.
2026-01-08 12:03:17.465769 | controller | appstream: has expired and will be refreshed.
2026-01-08 12:03:17.465786 | controller | crb: has expired and will be refreshed.
2026-01-08 12:03:17.465812 | controller | extras-common: has expired and will be refreshed.
2026-01-08 12:03:17.465829 | controller | repo: downloading from remote: baseos
2026-01-08 12:03:17.465845 | controller | CentOS Stream 9 - BaseOS                         70 MB/s | 8.8 MB     00:00
2026-01-08 12:03:17.465862 | controller | baseos: using metadata from Mon 05 Jan 2026 11:44:55 AM EST.
2026-01-08 12:03:17.465877 | controller | repo: downloading from remote: appstream
2026-01-08 12:03:17.465893 | controller | CentOS Stream 9 - AppStream                      85 MB/s |  26 MB     00:00
2026-01-08 12:03:17.465909 | controller | appstream: using metadata from Mon 05 Jan 2026 11:48:20 AM EST.
2026-01-08 12:03:17.465925 | controller | repo: downloading from remote: crb
2026-01-08 12:03:17.465941 | controller | CentOS Stream 9 - CRB                            84 MB/s | 7.4 MB     00:00
2026-01-08 12:03:17.465957 | controller | crb: using metadata from Mon 05 Jan 2026 11:52:30 AM EST.
2026-01-08 12:03:17.465973 | controller | repo: downloading from remote: extras-common
2026-01-08 12:03:17.465989 | controller | CentOS Stream 9 - Extras packages               1.5 MB/s |  20 kB     00:00
2026-01-08 12:03:17.466004 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2026-01-08 12:03:17.466020 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2026-01-08 12:03:17.466035 | controller | Completion plugin: Generating completion cache...
2026-01-08 12:03:17.466050 | controller | Metadata cache created.
2026-01-08 12:03:17.466075 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.520066
2026-01-08 12:03:17.497326 | 
2026-01-08 12:03:17.497487 | PLAY RECAP
2026-01-08 12:03:17.497571 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-01-08 12:03:17.497629 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-08 12:03:17.497669 | 
2026-01-08 12:03:17.635336 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2026-01-08 12:03:17.636171 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-08 12:03:18.261145 | 
2026-01-08 12:03:18.261290 | PLAY [all]
2026-01-08 12:03:18.286711 | 
2026-01-08 12:03:18.286845 | TASK [Install binary dependencies]
2026-01-08 12:03:18.343976 | controller | ok
2026-01-08 12:03:18.364490 | 
2026-01-08 12:03:18.364626 | TASK [bindep : Include find tasks]
2026-01-08 12:03:18.392929 | controller | ok
2026-01-08 12:03:18.400131 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-08 12:03:18.405937 | 
2026-01-08 12:03:18.406005 | TASK [bindep : Look for bindep.txt]
2026-01-08 12:03:18.846082 | controller | ok
2026-01-08 12:03:18.853375 | 
2026-01-08 12:03:18.853498 | TASK [bindep : Define bindep_file fact]
2026-01-08 12:03:18.899496 | controller | ok
2026-01-08 12:03:18.904749 | 
2026-01-08 12:03:18.904815 | TASK [bindep : Look for other-requirements.txt]
2026-01-08 12:03:18.928751 | controller | skipping: Conditional result was False
2026-01-08 12:03:18.934798 | 
2026-01-08 12:03:18.934887 | TASK [bindep : Define bindep_file fact]
2026-01-08 12:03:18.958866 | controller | skipping: Conditional result was False
2026-01-08 12:03:18.964604 | 
2026-01-08 12:03:18.964671 | TASK [bindep : Look for bindep fallback file]
2026-01-08 12:03:18.988064 | controller | skipping: Conditional result was False
2026-01-08 12:03:18.993535 | 
2026-01-08 12:03:18.993602 | TASK [bindep : Define bindep_file fact]
2026-01-08 12:03:19.017075 | controller | skipping: Conditional result was False
2026-01-08 12:03:19.022566 | 
2026-01-08 12:03:19.022631 | TASK [bindep : Include bindep tasks]
2026-01-08 12:03:19.052232 | controller | ok
2026-01-08 12:03:19.058830 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2026-01-08 12:03:19.066792 | 
2026-01-08 12:03:19.066867 | TASK [bindep : Look for bindep command]
2026-01-08 12:03:19.127620 | controller | skipping: Conditional result was False
2026-01-08 12:03:19.150435 | 
2026-01-08 12:03:19.150550 | TASK [bindep : Check for system bindep]
2026-01-08 12:03:19.686109 | controller | ok: Runtime: 0:00:00.007112
2026-01-08 12:03:19.692700 | 
2026-01-08 12:03:19.692900 | TASK [bindep : Define bindep_command fact]
2026-01-08 12:03:19.719397 | controller | skipping: Conditional result was False
2026-01-08 12:03:19.727442 | 
2026-01-08 12:03:19.727525 | TASK [bindep : Include install tasks]
2026-01-08 12:03:19.757913 | controller | ok
2026-01-08 12:03:19.765249 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2026-01-08 12:03:19.773788 | 
2026-01-08 12:03:19.773848 | TASK [bindep : Create temp dir for bindep]
2026-01-08 12:03:20.163317 | controller | changed
2026-01-08 12:03:20.172144 | 
2026-01-08 12:03:20.172217 | TASK [Ensure we have pip dependencies]
2026-01-08 12:03:20.191155 | controller | ok
2026-01-08 12:03:20.215078 | 
2026-01-08 12:03:20.215153 | TASK [ensure-pip : Check if pip is installed]
2026-01-08 07:03:20.506458 | controller | /usr/bin/pip3
2026-01-08 07:03:20.530342 | controller | /usr/bin/python3: No module named wheel
2026-01-08 12:03:20.746141 | controller | ok: Runtime: 0:00:00.035581
2026-01-08 12:03:20.753368 | 
2026-01-08 12:03:20.753475 | LOOP [ensure-pip : Install pip from packages]
2026-01-08 12:03:20.806591 | controller | ok: "/var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2026-01-08 12:03:20.817011 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2026-01-08 12:03:20.839605 | 
2026-01-08 12:03:20.839763 | TASK [ensure-pip : Install Python 3 pip]
2026-01-08 12:03:22.720830 | controller | changed
2026-01-08 12:03:22.735663 | 
2026-01-08 12:03:22.735845 | TASK [ensure-pip : Check for EPEL repository]
2026-01-08 12:03:22.775091 | controller | skipping: Conditional result was False
2026-01-08 12:03:22.785432 | 
2026-01-08 12:03:22.785578 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2026-01-08 12:03:22.841472 | controller | skipping: Conditional result was False
2026-01-08 12:03:22.854937 | 
2026-01-08 12:03:22.855214 | TASK [ensure-pip : Install Python 2 pip]
2026-01-08 12:03:22.912357 | controller | skipping: Conditional result was False
2026-01-08 12:03:22.927512 | 
2026-01-08 12:03:22.927709 | TASK [ensure-pip : Ensure setuptools]
2026-01-08 12:03:22.955429 | controller | skipping: Conditional result was False
2026-01-08 12:03:22.972181 | 
2026-01-08 12:03:22.972334 | TASK [ensure-pip : Check for ensurepip module]
2026-01-08 12:03:23.528333 | controller | skipping: Conditional result was False
2026-01-08 12:03:23.534440 | 
2026-01-08 12:03:23.534523 | TASK [ensure-pip : Ensure python3-venv]
2026-01-08 12:03:23.568631 | controller | skipping: Conditional result was False
2026-01-08 12:03:23.576170 | 
2026-01-08 12:03:23.576307 | TASK [ensure-pip : Install pip from source]
2026-01-08 12:03:23.590672 | controller | skipping: Conditional result was False
2026-01-08 12:03:23.597529 | 
2026-01-08 12:03:23.597673 | TASK [ensure-pip : Probe for venv python full path]
2026-01-08 07:03:23.925689 | controller | /usr/bin/python3
2026-01-08 12:03:24.130011 | controller | ok: Runtime: 0:00:00.008977
2026-01-08 12:03:24.135886 | 
2026-01-08 12:03:24.135950 | TASK [ensure-pip : Set host default]
2026-01-08 12:03:24.185273 | controller | ok
2026-01-08 12:03:24.192038 | 
2026-01-08 12:03:24.192106 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2026-01-08 12:03:24.242678 | controller | ok
2026-01-08 12:03:24.252291 | 
2026-01-08 12:03:24.252371 | TASK [bindep : Install bindep into temporary venv]
2026-01-08 12:03:28.369565 | controller | changed
2026-01-08 12:03:28.383647 | 
2026-01-08 12:03:28.383831 | TASK [bindep : Define bindep_command]
2026-01-08 12:03:28.439896 | controller | ok
2026-01-08 12:03:28.451474 | 
2026-01-08 12:03:28.451671 | LOOP [bindep : Include package tasks]
2026-01-08 12:03:28.505644 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2026-01-08 12:03:28.506443 | controller | ok: All items complete
2026-01-08 12:03:28.506508 | 
2026-01-08 12:03:28.528168 | controller | included: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2026-01-08 12:03:28.547934 | 
2026-01-08 12:03:28.548096 | TASK [bindep : Define bindep_run fact]
2026-01-08 12:03:28.602425 | controller | ok
2026-01-08 12:03:28.609289 | 
2026-01-08 12:03:28.609350 | TASK [bindep : Get list of packages to install from bindep]
2026-01-08 07:03:29.939838 | controller | podman
2026-01-08 07:03:29.982860 | controller | python3-jmespath
2026-01-08 07:03:29.982910 | controller | python3-libvirt
2026-01-08 07:03:29.982918 | controller | python3-lxml
2026-01-08 07:03:29.982924 | controller | python3-netaddr
2026-01-08 12:03:30.152802 | controller | ok: Runtime: 0:00:01.083595
2026-01-08 12:03:30.158654 | 
2026-01-08 12:03:30.158742 | TASK [bindep : Install distro packages from bindep]
2026-01-08 12:04:14.598612 | controller | changed
2026-01-08 12:04:14.616572 | 
2026-01-08 12:04:14.616771 | TASK [bindep : Check that packages are installed]
2026-01-08 12:04:16.689203 | controller | ok: Runtime: 0:00:01.291298
2026-01-08 12:04:16.702449 | 
2026-01-08 12:04:16.702633 | TASK [bindep : Fail if we cannot install all packages]
2026-01-08 12:04:16.740163 | controller | skipping: Conditional result was False
2026-01-08 12:04:16.766479 | 
2026-01-08 12:04:16.766663 | TASK [Run test-setup role]
2026-01-08 12:04:16.796955 | controller | ok
2026-01-08 12:04:16.831394 | 
2026-01-08 12:04:16.831525 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-08 12:04:17.102715 | controller | ok
2026-01-08 12:04:17.114268 | 
2026-01-08 12:04:17.114407 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-08 12:04:17.664284 | controller | skipping: Conditional result was False
2026-01-08 12:04:17.707954 | 
2026-01-08 12:04:17.708084 | TASK [bindep : Remove bindep temp dir]
2026-01-08 12:04:18.082907 | controller | ok
2026-01-08 12:04:18.105630 | 
2026-01-08 12:04:18.105832 | PLAY RECAP
2026-01-08 12:04:18.105930 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2026-01-08 12:04:18.105979 | 
2026-01-08 12:04:18.223177 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-08 12:04:18.225086 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2026-01-08 12:04:18.777329 | 
2026-01-08 12:04:18.777434 | PLAY [all]
2026-01-08 12:04:18.796035 | 
2026-01-08 12:04:18.796117 | TASK [Abort when test_command variable is undefined]
2026-01-08 12:04:18.820575 | controller | skipping: Conditional result was False
2026-01-08 12:04:18.825938 | 
2026-01-08 12:04:18.826015 | TASK [Convert test_command to list]
2026-01-08 12:04:18.860270 | controller | skipping: Conditional result was False
2026-01-08 12:04:18.866867 | 
2026-01-08 12:04:18.866935 | TASK [Use test_command list]
2026-01-08 12:04:18.921403 | controller | ok
2026-01-08 12:04:18.931276 | 
2026-01-08 12:04:18.931363 | LOOP [Run test_command]
2026-01-08 12:04:19.363608 | controller | no check to run
2026-01-08 12:04:19.363871 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006300
2026-01-08 12:04:19.405031 | 
2026-01-08 12:04:19.405159 | PLAY RECAP
2026-01-08 12:04:19.405217 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2026-01-08 12:04:19.405248 | 
2026-01-08 12:04:19.506907 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2026-01-08 12:04:19.507761 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-08 12:04:20.117546 | 
2026-01-08 12:04:20.117698 | PLAY [all]
2026-01-08 12:04:20.142755 | 
2026-01-08 12:04:20.142884 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-08 12:04:20.516711 | controller | changed: non-zero return code
2026-01-08 12:04:20.524852 | 
2026-01-08 12:04:20.524949 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-08 12:04:20.551022 | controller | skipping: Conditional result was False
2026-01-08 12:04:20.559185 | 
2026-01-08 12:04:20.559300 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-08 12:04:20.584228 | 
2026-01-08 12:04:20.584449 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-08 12:04:20.609910 | 
2026-01-08 12:04:20.610107 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-08 12:04:20.636031 | controller | skipping: Conditional result was False
2026-01-08 12:04:20.646902 | 
2026-01-08 12:04:20.647013 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-08 12:04:20.680967 | 
2026-01-08 12:04:20.681168 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-08 12:04:20.708350 | controller | skipping: Conditional result was False
2026-01-08 12:04:20.716781 | 
2026-01-08 12:04:20.716892 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-08 12:04:20.751296 | controller | skipping: Conditional result was False
2026-01-08 12:04:20.757351 | 
2026-01-08 12:04:20.757417 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-08 12:04:20.785257 | controller | skipping: Conditional result was False
2026-01-08 12:04:20.813047 | 
2026-01-08 12:04:20.813148 | PLAY RECAP
2026-01-08 12:04:20.813192 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-08 12:04:20.813211 | 
2026-01-08 12:04:20.918038 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-08 12:04:20.920066 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-01-08 12:04:21.580224 | 
2026-01-08 12:04:21.580327 | PLAY [all]
2026-01-08 12:04:21.598695 | 
2026-01-08 12:04:21.598782 | TASK [include_role : fetch-output]
2026-01-08 12:04:21.647847 | controller | ok
2026-01-08 12:04:21.665181 | 
2026-01-08 12:04:21.665277 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-08 12:04:21.742037 | controller | skipping: Conditional result was False
2026-01-08 12:04:21.747846 | 
2026-01-08 12:04:21.747932 | TASK [fetch-output : Set log path for single node]
2026-01-08 12:04:21.785369 | controller | ok
2026-01-08 12:04:21.790629 | 
2026-01-08 12:04:21.790717 | LOOP [fetch-output : Ensure local output dirs]
2026-01-08 12:04:22.189011 | controller -> localhost | ok: "/var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/logs"
2026-01-08 12:04:22.421907 | controller -> localhost | changed: "/var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/artifacts"
2026-01-08 12:04:22.691221 | controller -> localhost | changed: "/var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/docs"
2026-01-08 12:04:22.720377 | 
2026-01-08 12:04:22.720632 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-08 12:04:23.401344 | controller | changed: .d..t...... ./
2026-01-08 12:04:23.401536 | controller | changed: All items complete
2026-01-08 12:04:23.401563 | 
2026-01-08 12:04:23.952965 | controller | changed: .d..t...... ./
2026-01-08 12:04:24.432219 | controller | changed: .d..t...... ./
2026-01-08 12:04:24.464112 | 
2026-01-08 12:04:24.464330 | TASK [include_role : fetch-output-openshift]
2026-01-08 12:04:24.491683 | controller | skipping: Conditional result was False
2026-01-08 12:04:24.504696 | 
2026-01-08 12:04:24.504881 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-08 12:04:25.007193 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.019820
2026-01-08 12:04:25.273859 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013363
2026-01-08 12:04:25.330456 | 
2026-01-08 12:04:25.330576 | PLAY [all]
2026-01-08 12:04:25.351584 | 
2026-01-08 12:04:25.351676 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-01-08 12:04:25.863130 | controller | changed
2026-01-08 12:04:25.916918 | 
2026-01-08 12:04:25.917040 | PLAY RECAP
2026-01-08 12:04:25.917097 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2026-01-08 12:04:25.917126 | 
2026-01-08 12:04:26.019859 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-01-08 12:04:26.020777 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2026-01-08 12:04:26.685783 | 
2026-01-08 12:04:26.685956 | PLAY [localhost]
2026-01-08 12:04:26.704348 | 
2026-01-08 12:04:26.704465 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-08 12:04:27.121326 | localhost | changed
2026-01-08 12:04:27.127952 | 
2026-01-08 12:04:27.128063 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-08 12:04:27.149254 | localhost | ok
2026-01-08 12:04:27.160793 | 
2026-01-08 12:04:27.160902 | TASK [add-fileserver : Create SSH private key tempfile]
2026-01-08 12:04:27.536661 | localhost | changed
2026-01-08 12:04:27.548924 | 
2026-01-08 12:04:27.549097 | TASK [add-fileserver : Create SSH private key from secret]
2026-01-08 12:04:28.232621 | localhost | changed
2026-01-08 12:04:28.238042 | 
2026-01-08 12:04:28.238112 | TASK [add-fileserver : Add fileserver ssh key]
2026-01-08 12:04:28.639905 | localhost | Identity added: /var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/tmp/ansible.ir6enebf (/var/lib/zuul/builds/56884583d4b241a88f02762fa890fb68/work/tmp/ansible.ir6enebf)
2026-01-08 12:04:28.640208 | localhost | ok: Runtime: 0:00:00.012933
2026-01-08 12:04:28.665437 | 
2026-01-08 12:04:28.665620 | TASK [add-fileserver : Remove SSH private key from disk]
2026-01-08 12:04:28.974975 | localhost | ok: Runtime: 0:00:00.005009
2026-01-08 12:04:28.986828 | 
2026-01-08 12:04:28.986981 | TASK [add-fileserver : Add fileserver to inventory]
2026-01-08 12:04:29.051176 | localhost | changed
2026-01-08 12:04:29.057475 | 
2026-01-08 12:04:29.057572 | TASK [add-fileserver : Add fileserver server to known hosts]
2026-01-08 12:04:29.472237 | localhost | changed
2026-01-08 12:04:29.502407 | 
2026-01-08 12:04:29.502499 | PLAY [localhost]
2026-01-08 12:04:29.515022 | 
2026-01-08 12:04:29.515174 | TASK [Generate bulk log download script]
2026-01-08 12:04:29.533583 | localhost | ok
2026-01-08 12:04:29.545516 | 
2026-01-08 12:04:29.545601 | TASK [local-log-download : Check API endpoint is defined]
2026-01-08 12:04:29.584745 | localhost | ok: All assertions passed
2026-01-08 12:04:29.589753 | 
2026-01-08 12:04:29.589816 | TASK [local-log-download : Create download script]
2026-01-08 12:04:30.018030 | localhost -> localhost | changed
2026-01-08 12:04:30.035174 | 
2026-01-08 12:04:30.035303 | TASK [Register quick-download link]
2026-01-08 12:04:30.068634 | localhost | ok
2026-01-08 12:04:30.140183 | 
2026-01-08 12:04:30.140279 | PLAY [logserver.rdoproject.org]
2026-01-08 12:04:30.149959 | 
2026-01-08 12:04:30.150018 | TASK [Set zuul-log-path fact]
2026-01-08 12:04:30.167090 | logserver.rdoproject.org | ok
2026-01-08 12:04:30.176878 | 
2026-01-08 12:04:30.176955 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-08 12:04:30.203498 | logserver.rdoproject.org | ok
2026-01-08 12:04:30.210864 | 
2026-01-08 12:04:30.210982 | TASK [upload-logs : Create log directories]
2026-01-08 12:04:30.859249 | logserver.rdoproject.org | changed
2026-01-08 12:04:30.863219 | 
2026-01-08 12:04:30.863324 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-01-08 12:04:31.258861 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008820
2026-01-08 12:04:31.266177 | 
2026-01-08 12:04:31.266800 | TASK [upload-logs : Upload logs to log server]
2026-01-08 12:04:32.020145 | logserver.rdoproject.org | Output suppressed because no_log was given
2026-01-08 12:04:32.026459 | 
2026-01-08 12:04:32.026600 | LOOP [upload-logs : Compress console log and json output]
2026-01-08 12:04:32.094190 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-08 12:04:32.105905 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-08 12:04:32.123973 | 
2026-01-08 12:04:32.124164 | LOOP [upload-logs : Upload compressed console log and json output]
2026-01-08 12:04:32.175155 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-08 12:04:32.175649 | 
2026-01-08 12:04:32.178398 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-08 12:04:32.186393 | 
2026-01-08 12:04:32.186494 | LOOP [upload-logs : Upload console log and json output]