2025-12-05 15:33:32.284359 | Job console starting...
2025-12-05 15:33:32.301348 | Updating repositories
2025-12-05 15:33:32.365524 | Preparing job workspace
2025-12-05 15:33:36.791520 | Running Ansible setup...
2025-12-05 15:33:41.047625 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:33:41.632574 | 
2025-12-05 15:33:41.632690 | PLAY [localhost]
2025-12-05 15:33:41.641893 | 
2025-12-05 15:33:41.641968 | TASK [Gathering Facts]
2025-12-05 15:33:42.668828 | localhost | ok
2025-12-05 15:33:42.684219 | 
2025-12-05 15:33:42.684312 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-05 15:33:43.160319 | localhost -> localhost | changed
2025-12-05 15:33:43.165850 | 
2025-12-05 15:33:43.165929 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-05 15:33:44.053196 | localhost -> localhost | changed
2025-12-05 15:33:44.061793 | 
2025-12-05 15:33:44.061863 | TASK [Setup log path fact]
2025-12-05 15:33:44.082707 | localhost | ok
2025-12-05 15:33:44.099752 | 
2025-12-05 15:33:44.099915 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:33:44.129418 | localhost | ok
2025-12-05 15:33:44.137142 | 
2025-12-05 15:33:44.137211 | TASK [emit-job-header : Print job information]
2025-12-05 15:33:44.175094 | # Job Information
2025-12-05 15:33:44.175224 | Ansible Version: 2.15.12
2025-12-05 15:33:44.175250 | Job: cifmw-molecule-fix_python_encodings
2025-12-05 15:33:44.175270 | Pipeline: github-check
2025-12-05 15:33:44.175288 | Executor: ze01.softwarefactory-project.io
2025-12-05 15:33:44.175305 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539
2025-12-05 15:33:44.175323 | Log URL (when completed): https://logserver.rdoproject.org/d32/rdoproject.org/d32797e87b6c434d96af804a24bd1808/
2025-12-05 15:33:44.175342 | Event ID: 757b9e30-d1ef-11f0-97eb-f505e6ea5a00
2025-12-05 15:33:44.178858 | 
2025-12-05 15:33:44.178921 | LOOP [emit-job-header : Print node information]
2025-12-05 15:33:44.317616 | localhost | ok:
2025-12-05 15:33:44.317830 | localhost | # Node Information
2025-12-05 15:33:44.317860 | localhost | Inventory Hostname: controller
2025-12-05 15:33:44.317885 | localhost | Hostname: np0005547427
2025-12-05 15:33:44.317906 | localhost | Username: zuul
2025-12-05 15:33:44.317927 | localhost | Distro: CentOS 9
2025-12-05 15:33:44.317946 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-05 15:33:44.317965 | localhost | Region: RegionOne
2025-12-05 15:33:44.317983 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-05 15:33:44.318001 | localhost | Product Name: OpenStack Nova
2025-12-05 15:33:44.318043 | localhost | Interface IP: 38.102.83.245
2025-12-05 15:33:44.345970 | 
2025-12-05 15:33:44.346045 | PLAY [all]
2025-12-05 15:33:44.356727 | 
2025-12-05 15:33:44.356815 | TASK [Gather network facts]
2025-12-05 15:33:44.843000 | controller | ok
2025-12-05 15:33:44.861445 | 
2025-12-05 15:33:44.861550 | TASK [include_role : start-zuul-console]
2025-12-05 15:33:44.901594 | controller | ok
2025-12-05 15:33:44.934830 | 
2025-12-05 15:33:44.934955 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-05 15:33:45.543881 | controller | ok
2025-12-05 15:33:45.567296 | 
2025-12-05 15:33:45.567416 | TASK [include_role : add-build-sshkey]
2025-12-05 15:33:45.616863 | controller | ok
2025-12-05 15:33:45.637249 | 
2025-12-05 15:33:45.637365 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 15:33:45.988438 | controller -> localhost | ok
2025-12-05 15:33:45.995088 | 
2025-12-05 15:33:45.995155 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 15:33:46.023726 | controller | ok
2025-12-05 15:33:46.036735 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 15:33:46.042393 | 
2025-12-05 15:33:46.042512 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 15:33:47.469882 | controller -> localhost | Generating public/private rsa key pair.
2025-12-05 15:33:47.470084 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/d32797e87b6c434d96af804a24bd1808_id_rsa.
2025-12-05 15:33:47.470116 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/d32797e87b6c434d96af804a24bd1808_id_rsa.pub.
2025-12-05 15:33:47.470138 | controller -> localhost | The key fingerprint is:
2025-12-05 15:33:47.470158 | controller -> localhost | SHA256:YO7LJQnip4f0Wh1bJ0nE7QbyFPzWLVkL2z8F6JB5cSs zuul-build-sshkey
2025-12-05 15:33:47.470176 | controller -> localhost | The key's randomart image is:
2025-12-05 15:33:47.470195 | controller -> localhost | +---[RSA 3072]----+
2025-12-05 15:33:47.470213 | controller -> localhost | |       ooo o.o.  |
2025-12-05 15:33:47.470231 | controller -> localhost | |      ..= = +.o. |
2025-12-05 15:33:47.470249 | controller -> localhost | |      o+.+ =EB.o |
2025-12-05 15:33:47.470267 | controller -> localhost | |     o o..= *.+ .|
2025-12-05 15:33:47.470284 | controller -> localhost | |  . . o So.  . ..|
2025-12-05 15:33:47.470301 | controller -> localhost | | ... + = o     ..|
2025-12-05 15:33:47.470318 | controller -> localhost | | ..oo * .       .|
2025-12-05 15:33:47.470335 | controller -> localhost | |  .+o. +         |
2025-12-05 15:33:47.470352 | controller -> localhost | |  oo  o          |
2025-12-05 15:33:47.470368 | controller -> localhost | +----[SHA256]-----+
2025-12-05 15:33:47.470413 | controller -> localhost | ok: Runtime: 0:00:00.553162
2025-12-05 15:33:47.483690 | 
2025-12-05 15:33:47.483763 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 15:33:47.516928 | controller | ok
2025-12-05 15:33:47.528833 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 15:33:47.537215 | 
2025-12-05 15:33:47.537287 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 15:33:47.561853 | controller | skipping: Conditional result was False
2025-12-05 15:33:47.568119 | 
2025-12-05 15:33:47.568278 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 15:33:48.077574 | controller | changed
2025-12-05 15:33:48.100536 | 
2025-12-05 15:33:48.100624 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 15:33:48.406611 | controller | ok
2025-12-05 15:33:48.412465 | 
2025-12-05 15:33:48.412558 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 15:33:49.382289 | controller | changed
2025-12-05 15:33:49.387623 | 
2025-12-05 15:33:49.387688 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 15:33:50.180727 | controller | changed
2025-12-05 15:33:50.186991 | 
2025-12-05 15:33:50.187143 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 15:33:50.235949 | controller | skipping: Conditional result was False
2025-12-05 15:33:50.244785 | 
2025-12-05 15:33:50.244875 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 15:33:50.618738 | controller -> localhost | changed
2025-12-05 15:33:50.630672 | 
2025-12-05 15:33:50.630763 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 15:33:50.936225 | controller -> localhost | Identity added: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/d32797e87b6c434d96af804a24bd1808_id_rsa (zuul-build-sshkey)
2025-12-05 15:33:50.936423 | controller -> localhost | ok: Runtime: 0:00:00.027335
2025-12-05 15:33:50.942823 | 
2025-12-05 15:33:50.942883 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 15:33:51.326934 | controller | ok
2025-12-05 15:33:51.331596 | 
2025-12-05 15:33:51.331678 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 15:33:51.415285 | controller | skipping: Conditional result was False
2025-12-05 15:33:51.425318 | 
2025-12-05 15:33:51.425426 | TASK [include_role : validate-host]
2025-12-05 15:33:51.444568 | controller | ok
2025-12-05 15:33:51.469733 | 
2025-12-05 15:33:51.469872 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-05 15:33:51.498743 | controller | ok
2025-12-05 15:33:51.504595 | 
2025-12-05 15:33:51.504689 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-05 15:33:51.800727 | controller -> localhost | ok
2025-12-05 15:33:51.808907 | 
2025-12-05 15:33:51.809056 | TASK [validate-host : Collect information about the host]
2025-12-05 15:33:52.559104 | controller | ok
2025-12-05 15:33:52.572331 | 
2025-12-05 15:33:52.572429 | TASK [validate-host : Sanitize hostname]
2025-12-05 15:33:52.621529 | controller | ok
2025-12-05 15:33:52.626497 | 
2025-12-05 15:33:52.626564 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-05 15:33:53.178212 | controller -> localhost | changed
2025-12-05 15:33:53.184547 | 
2025-12-05 15:33:53.184627 | TASK [validate-host : Collect information about zuul worker]
2025-12-05 15:33:53.596213 | controller | ok
2025-12-05 15:33:53.601200 | 
2025-12-05 15:33:53.601262 | TASK [validate-host : Write out all zuul information for each host]
2025-12-05 15:33:54.180353 | controller -> localhost | changed
2025-12-05 15:33:54.190230 | 
2025-12-05 15:33:54.190316 | TASK [include_role : prepare-workspace-openshift]
2025-12-05 15:33:54.224553 | controller | skipping: Conditional result was False
2025-12-05 15:33:54.231074 | 
2025-12-05 15:33:54.231158 | TASK [include_role : remove-zuul-sshkey]
2025-12-05 15:33:54.255122 | controller | skipping: Conditional result was False
2025-12-05 15:33:54.261161 | 
2025-12-05 15:33:54.261246 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:33:54.546184 | controller | ok: "logs"
2025-12-05 15:33:54.546413 | controller | ok: All items complete
2025-12-05 15:33:54.546442 | 
2025-12-05 15:33:54.785106 | controller | ok: "artifacts"
2025-12-05 15:33:55.007668 | controller | ok: "docs"
2025-12-05 15:33:55.024075 | 
2025-12-05 15:33:55.024182 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:33:55.298724 | controller | changed: "logs"
2025-12-05 15:33:55.515600 | controller | changed: "artifacts"
2025-12-05 15:33:55.727911 | controller | changed: "docs"
2025-12-05 15:33:55.765201 | 
2025-12-05 15:33:55.765315 | PLAY RECAP
2025-12-05 15:33:55.765358 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-05 15:33:55.765386 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:33:55.765404 | 
2025-12-05 15:33:55.864577 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:33:55.865470 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:33:56.474404 | 
2025-12-05 15:33:56.474547 | PLAY [localhost]
2025-12-05 15:33:56.492083 | 
2025-12-05 15:33:56.492185 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-05 15:33:56.918509 | localhost | ok
2025-12-05 15:33:56.924903 | 
2025-12-05 15:33:56.925000 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-05 15:33:57.709356 | localhost | changed
2025-12-05 15:33:57.746184 | 
2025-12-05 15:33:57.746304 | PLAY [all]
2025-12-05 15:33:57.769354 | 
2025-12-05 15:33:57.769501 | TASK [include_role : prepare-workspace]
2025-12-05 15:33:57.800074 | controller | ok
2025-12-05 15:33:57.814458 | 
2025-12-05 15:33:57.814561 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-05 15:33:58.202815 | controller | ok
2025-12-05 15:33:58.218137 | 
2025-12-05 15:33:58.218431 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-05 15:33:59.796469 | controller | Output suppressed because no_log was given
2025-12-05 15:33:59.815927 | 
2025-12-05 15:33:59.816045 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:34:00.057577 | controller | changed: "logs"
2025-12-05 15:34:00.273079 | controller | changed: "artifacts"
2025-12-05 15:34:00.490759 | controller | changed: "docs"
2025-12-05 15:34:00.506737 | 
2025-12-05 15:34:00.506901 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:34:00.782626 | controller | changed: "logs"
2025-12-05 15:34:00.783086 | controller | changed: All items complete
2025-12-05 15:34:00.783174 | 
2025-12-05 15:34:01.022521 | controller | changed: "artifacts"
2025-12-05 15:34:01.288505 | controller | changed: "docs"
2025-12-05 15:34:01.312106 | 
2025-12-05 15:34:01.312255 | TASK [Check if worker can sudo]
2025-12-05 15:34:01.864473 | controller | ok: Runtime: 0:00:00.032480
2025-12-05 15:34:01.876651 | 
2025-12-05 15:34:01.876785 | TASK [configure-mirrors : Gather needed facts]
2025-12-05 15:34:01.955333 | controller | skipping: Conditional result was False
2025-12-05 15:34:01.967443 | 
2025-12-05 15:34:01.967636 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-05 15:34:02.033267 | controller | ok
2025-12-05 15:34:02.051884 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-05 15:34:02.058923 | 
2025-12-05 15:34:02.059079 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-05 15:34:02.483194 | controller | ok
2025-12-05 15:34:02.489944 | 
2025-12-05 15:34:02.490051 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-05 15:34:02.549250 | controller | ok: "/var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-05 15:34:02.564713 | 
2025-12-05 15:34:02.564825 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-05 15:34:03.412370 | controller | changed
2025-12-05 15:34:03.418468 | 
2025-12-05 15:34:03.418531 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-05 15:34:03.485032 | controller | ok: "/var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-05 15:34:03.485196 | controller | ok: All items complete
2025-12-05 15:34:03.485221 | 
2025-12-05 15:34:03.555053 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-05 15:34:03.564239 | 
2025-12-05 15:34:03.564330 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-05 15:34:04.463782 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-05 15:34:05.278380 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-05 15:34:05.287565 | 
2025-12-05 15:34:05.287687 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-05 15:34:05.746953 | controller | changed: section and option added
2025-12-05 15:34:05.781484 | 
2025-12-05 15:34:05.781659 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-05 15:34:06.392934 | controller | 29 files removed
2025-12-05 15:34:06.393690 | controller | ok: Item: dnf clean all Runtime: 0:00:00.273161
2025-12-05 15:34:06.393832 | controller | changed: All items complete
2025-12-05 15:34:06.393905 | 
2025-12-05 15:34:17.737549 | 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:17.737820 | controller | DNF version: 4.14.0
2025-12-05 15:34:17.737921 | controller | cachedir: /var/cache/dnf
2025-12-05 15:34:17.737989 | controller | Making cache files for all metadata files.
2025-12-05 15:34:17.738266 | controller | baseos: has expired and will be refreshed.
2025-12-05 15:34:17.738344 | controller | appstream: has expired and will be refreshed.
2025-12-05 15:34:17.738398 | controller | crb: has expired and will be refreshed.
2025-12-05 15:34:17.738475 | controller | extras-common: has expired and will be refreshed.
2025-12-05 15:34:17.738549 | controller | repo: downloading from remote: baseos
2025-12-05 15:34:17.738618 | controller | CentOS Stream 9 - BaseOS                         52 MB/s | 8.8 MB     00:00
2025-12-05 15:34:17.738673 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-05 15:34:17.738724 | controller | repo: downloading from remote: appstream
2025-12-05 15:34:17.738773 | controller | CentOS Stream 9 - AppStream                      74 MB/s |  25 MB     00:00
2025-12-05 15:34:17.738821 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-05 15:34:17.738873 | controller | repo: downloading from remote: crb
2025-12-05 15:34:17.738925 | controller | CentOS Stream 9 - CRB                            44 MB/s | 7.3 MB     00:00
2025-12-05 15:34:17.738976 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-05 15:34:17.739175 | controller | repo: downloading from remote: extras-common
2025-12-05 15:34:17.739243 | controller | CentOS Stream 9 - Extras packages               1.6 MB/s |  20 kB     00:00
2025-12-05 15:34:17.739296 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-05 15:34:17.739344 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-05 15:34:17.739395 | controller | Completion plugin: Generating completion cache...
2025-12-05 15:34:17.739445 | controller | Metadata cache created.
2025-12-05 15:34:17.739525 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.081393
2025-12-05 15:34:17.776629 | 
2025-12-05 15:34:17.776826 | PLAY RECAP
2025-12-05 15:34:17.776962 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-05 15:34:17.777112 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:34:17.777189 | 
2025-12-05 15:34:17.886460 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:34:17.888104 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:34:18.421211 | 
2025-12-05 15:34:18.421327 | PLAY [all]
2025-12-05 15:34:18.443376 | 
2025-12-05 15:34:18.443472 | TASK [Install binary dependencies]
2025-12-05 15:34:18.524275 | controller | ok
2025-12-05 15:34:18.543550 | 
2025-12-05 15:34:18.543645 | TASK [bindep : Include find tasks]
2025-12-05 15:34:18.572456 | controller | ok
2025-12-05 15:34:18.579853 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-05 15:34:18.585661 | 
2025-12-05 15:34:18.585727 | TASK [bindep : Look for bindep.txt]
2025-12-05 15:34:19.004081 | controller | ok
2025-12-05 15:34:19.028568 | 
2025-12-05 15:34:19.028779 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:34:19.073554 | controller | ok
2025-12-05 15:34:19.079733 | 
2025-12-05 15:34:19.079809 | TASK [bindep : Look for other-requirements.txt]
2025-12-05 15:34:19.099789 | controller | skipping: Conditional result was False
2025-12-05 15:34:19.111444 | 
2025-12-05 15:34:19.111660 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:34:19.138537 | controller | skipping: Conditional result was False
2025-12-05 15:34:19.147189 | 
2025-12-05 15:34:19.147291 | TASK [bindep : Look for bindep fallback file]
2025-12-05 15:34:19.172369 | controller | skipping: Conditional result was False
2025-12-05 15:34:19.182654 | 
2025-12-05 15:34:19.182765 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:34:19.207944 | controller | skipping: Conditional result was False
2025-12-05 15:34:19.216541 | 
2025-12-05 15:34:19.216690 | TASK [bindep : Include bindep tasks]
2025-12-05 15:34:19.251386 | controller | ok
2025-12-05 15:34:19.261448 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-05 15:34:19.273372 | 
2025-12-05 15:34:19.273493 | TASK [bindep : Look for bindep command]
2025-12-05 15:34:19.298876 | controller | skipping: Conditional result was False
2025-12-05 15:34:19.307976 | 
2025-12-05 15:34:19.308118 | TASK [bindep : Check for system bindep]
2025-12-05 15:34:19.855984 | controller | ok: Runtime: 0:00:00.005202
2025-12-05 15:34:19.869490 | 
2025-12-05 15:34:19.869683 | TASK [bindep : Define bindep_command fact]
2025-12-05 15:34:19.896305 | controller | skipping: Conditional result was False
2025-12-05 15:34:19.904739 | 
2025-12-05 15:34:19.904848 | TASK [bindep : Include install tasks]
2025-12-05 15:34:19.934440 | controller | ok
2025-12-05 15:34:19.942550 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-05 15:34:19.954587 | 
2025-12-05 15:34:19.954688 | TASK [bindep : Create temp dir for bindep]
2025-12-05 15:34:20.323036 | controller | changed
2025-12-05 15:34:20.330650 | 
2025-12-05 15:34:20.330731 | TASK [Ensure we have pip dependencies]
2025-12-05 15:34:20.353057 | controller | ok
2025-12-05 15:34:20.385586 | 
2025-12-05 15:34:20.385706 | TASK [ensure-pip : Check if pip is installed]
2025-12-05 10:34:20.672338 | controller | /usr/bin/pip3
2025-12-05 10:34:20.719697 | controller | /usr/bin/python3: No module named wheel
2025-12-05 15:34:20.916272 | controller | ok: Runtime: 0:00:00.060287
2025-12-05 15:34:20.928656 | 
2025-12-05 15:34:20.928802 | LOOP [ensure-pip : Install pip from packages]
2025-12-05 15:34:20.974845 | controller | ok: "/var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-05 15:34:20.989325 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-05 15:34:21.005090 | 
2025-12-05 15:34:21.005262 | TASK [ensure-pip : Install Python 3 pip]
2025-12-05 15:34:22.901339 | controller | changed
2025-12-05 15:34:22.909886 | 
2025-12-05 15:34:22.909955 | TASK [ensure-pip : Check for EPEL repository]
2025-12-05 15:34:22.957543 | controller | skipping: Conditional result was False
2025-12-05 15:34:22.964236 | 
2025-12-05 15:34:22.964307 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-05 15:34:22.998651 | controller | skipping: Conditional result was False
2025-12-05 15:34:23.005379 | 
2025-12-05 15:34:23.005449 | TASK [ensure-pip : Install Python 2 pip]
2025-12-05 15:34:23.039916 | controller | skipping: Conditional result was False
2025-12-05 15:34:23.046252 | 
2025-12-05 15:34:23.046340 | TASK [ensure-pip : Ensure setuptools]
2025-12-05 15:34:23.060838 | controller | skipping: Conditional result was False
2025-12-05 15:34:23.067707 | 
2025-12-05 15:34:23.067772 | TASK [ensure-pip : Check for ensurepip module]
2025-12-05 15:34:23.596493 | controller | skipping: Conditional result was False
2025-12-05 15:34:23.604631 | 
2025-12-05 15:34:23.604724 | TASK [ensure-pip : Ensure python3-venv]
2025-12-05 15:34:23.619915 | controller | skipping: Conditional result was False
2025-12-05 15:34:23.629627 | 
2025-12-05 15:34:23.629720 | TASK [ensure-pip : Install pip from source]
2025-12-05 15:34:23.644306 | controller | skipping: Conditional result was False
2025-12-05 15:34:23.653667 | 
2025-12-05 15:34:23.654164 | TASK [ensure-pip : Probe for venv python full path]
2025-12-05 10:34:23.923245 | controller | /usr/bin/python3
2025-12-05 15:34:24.192994 | controller | ok: Runtime: 0:00:00.006687
2025-12-05 15:34:24.198823 | 
2025-12-05 15:34:24.198900 | TASK [ensure-pip : Set host default]
2025-12-05 15:34:24.268595 | controller | ok
2025-12-05 15:34:24.274039 | 
2025-12-05 15:34:24.274112 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-05 15:34:24.352770 | controller | ok
2025-12-05 15:34:24.366897 | 
2025-12-05 15:34:24.366990 | TASK [bindep : Install bindep into temporary venv]
2025-12-05 15:34:28.657005 | controller | changed
2025-12-05 15:34:28.662479 | 
2025-12-05 15:34:28.662542 | TASK [bindep : Define bindep_command]
2025-12-05 15:34:28.702217 | controller | ok
2025-12-05 15:34:28.707648 | 
2025-12-05 15:34:28.707718 | LOOP [bindep : Include package tasks]
2025-12-05 15:34:28.782832 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-05 15:34:28.783639 | controller | ok: All items complete
2025-12-05 15:34:28.783708 | 
2025-12-05 15:34:28.810008 | controller | included: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-05 15:34:28.832206 | 
2025-12-05 15:34:28.832329 | TASK [bindep : Define bindep_run fact]
2025-12-05 15:34:28.863823 | controller | ok
2025-12-05 15:34:28.871128 | 
2025-12-05 15:34:28.871231 | TASK [bindep : Get list of packages to install from bindep]
2025-12-05 10:34:30.188790 | controller | podman
2025-12-05 10:34:30.220022 | controller | python3-jmespath
2025-12-05 10:34:30.220088 | controller | python3-libvirt
2025-12-05 10:34:30.220097 | controller | python3-lxml
2025-12-05 10:34:30.220109 | controller | python3-netaddr
2025-12-05 15:34:30.411577 | controller | ok: Runtime: 0:00:01.058500
2025-12-05 15:34:30.424576 | 
2025-12-05 15:34:30.424719 | TASK [bindep : Install distro packages from bindep]
2025-12-05 15:35:31.894564 | controller | changed
2025-12-05 15:35:31.904301 | 
2025-12-05 15:35:31.904393 | TASK [bindep : Check that packages are installed]
2025-12-05 15:35:33.441781 | controller | ok: Runtime: 0:00:01.114779
2025-12-05 15:35:33.447311 | 
2025-12-05 15:35:33.447374 | TASK [bindep : Fail if we cannot install all packages]
2025-12-05 15:35:33.481334 | controller | skipping: Conditional result was False
2025-12-05 15:35:33.492852 | 
2025-12-05 15:35:33.497842 | TASK [Run test-setup role]
2025-12-05 15:35:33.540744 | controller | ok
2025-12-05 15:35:33.575558 | 
2025-12-05 15:35:33.575695 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-05 15:35:33.812281 | controller | ok
2025-12-05 15:35:33.822208 | 
2025-12-05 15:35:33.822373 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-05 15:35:34.358343 | controller | skipping: Conditional result was False
2025-12-05 15:35:34.401334 | 
2025-12-05 15:35:34.401459 | TASK [bindep : Remove bindep temp dir]
2025-12-05 15:35:34.747500 | controller | ok
2025-12-05 15:35:34.763469 | 
2025-12-05 15:35:34.763572 | PLAY RECAP
2025-12-05 15:35:34.763615 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-05 15:35:34.763637 | 
2025-12-05 15:35:34.923896 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:35:34.924770 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:35:35.901506 | 
2025-12-05 15:35:35.901643 | PLAY [all]
2025-12-05 15:35:35.933033 | 
2025-12-05 15:35:35.933174 | TASK [Abort when test_command variable is undefined]
2025-12-05 15:35:36.009425 | controller | skipping: Conditional result was False
2025-12-05 15:35:36.016349 | 
2025-12-05 15:35:36.016467 | TASK [Convert test_command to list]
2025-12-05 15:35:36.096220 | controller | skipping: Conditional result was False
2025-12-05 15:35:36.103910 | 
2025-12-05 15:35:36.103984 | TASK [Use test_command list]
2025-12-05 15:35:36.199357 | controller | ok
2025-12-05 15:35:36.205857 | 
2025-12-05 15:35:36.205922 | LOOP [Run test_command]
2025-12-05 15:35:36.755301 | controller | no check to run
2025-12-05 15:35:36.755486 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.003767
2025-12-05 15:35:36.782646 | 
2025-12-05 15:35:36.782808 | PLAY RECAP
2025-12-05 15:35:36.782902 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:35:36.782931 | 
2025-12-05 15:35:36.910971 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:35:36.911874 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:35:37.628440 | 
2025-12-05 15:35:37.628545 | PLAY [all]
2025-12-05 15:35:37.669923 | 
2025-12-05 15:35:37.670114 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-05 15:35:38.129269 | controller | changed: non-zero return code
2025-12-05 15:35:38.143283 | 
2025-12-05 15:35:38.143435 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-05 15:35:38.177909 | controller | skipping: Conditional result was False
2025-12-05 15:35:38.187351 | 
2025-12-05 15:35:38.187435 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-05 15:35:38.229356 | 
2025-12-05 15:35:38.229518 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-05 15:35:38.282627 | 
2025-12-05 15:35:38.282875 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-05 15:35:38.313003 | controller | skipping: Conditional result was False
2025-12-05 15:35:38.319462 | 
2025-12-05 15:35:38.319566 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-05 15:35:38.363833 | 
2025-12-05 15:35:38.364008 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-05 15:35:38.402329 | controller | skipping: Conditional result was False
2025-12-05 15:35:38.409348 | 
2025-12-05 15:35:38.409476 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-05 15:35:38.464129 | controller | skipping: Conditional result was False
2025-12-05 15:35:38.470688 | 
2025-12-05 15:35:38.470786 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-05 15:35:38.515072 | controller | skipping: Conditional result was False
2025-12-05 15:35:38.552752 | 
2025-12-05 15:35:38.552846 | PLAY RECAP
2025-12-05 15:35:38.552904 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-05 15:35:38.552926 | 
2025-12-05 15:35:38.722214 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:35:38.723082 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:35:39.702268 | 
2025-12-05 15:35:39.702394 | PLAY [all]
2025-12-05 15:35:39.724335 | 
2025-12-05 15:35:39.724425 | TASK [include_role : fetch-output]
2025-12-05 15:35:39.796044 | controller | ok
2025-12-05 15:35:39.828867 | 
2025-12-05 15:35:39.839049 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 15:35:39.957481 | controller | skipping: Conditional result was False
2025-12-05 15:35:39.963914 | 
2025-12-05 15:35:39.963979 | TASK [fetch-output : Set log path for single node]
2025-12-05 15:35:40.033312 | controller | ok
2025-12-05 15:35:40.038741 | 
2025-12-05 15:35:40.038808 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 15:35:40.551793 | controller -> localhost | ok: "/var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/logs"
2025-12-05 15:35:40.861007 | controller -> localhost | changed: "/var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/artifacts"
2025-12-05 15:35:41.503845 | controller -> localhost | changed: "/var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/docs"
2025-12-05 15:35:41.519960 | 
2025-12-05 15:35:41.520167 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 15:35:43.244837 | controller | changed: .d..t...... ./
2025-12-05 15:35:43.245105 | controller | changed: All items complete
2025-12-05 15:35:43.245137 | 
2025-12-05 15:35:44.122326 | controller | changed: .d..t...... ./
2025-12-05 15:35:44.838089 | controller | changed: .d..t...... ./
2025-12-05 15:35:44.857065 | 
2025-12-05 15:35:44.857196 | TASK [include_role : fetch-output-openshift]
2025-12-05 15:35:44.929615 | controller | skipping: Conditional result was False
2025-12-05 15:35:44.936177 | 
2025-12-05 15:35:44.936255 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-05 15:35:46.043719 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.024834
2025-12-05 15:35:46.695072 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.024877
2025-12-05 15:35:46.833347 | 
2025-12-05 15:35:46.833463 | PLAY [all]
2025-12-05 15:35:46.862560 | 
2025-12-05 15:35:46.862710 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-05 15:35:47.433463 | controller | changed
2025-12-05 15:35:47.488157 | 
2025-12-05 15:35:47.488278 | PLAY RECAP
2025-12-05 15:35:47.488335 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:35:47.488357 | 
2025-12-05 15:35:47.785720 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:35:47.786548 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-05 15:35:48.851830 | 
2025-12-05 15:35:48.851956 | PLAY [localhost]
2025-12-05 15:35:48.870912 | 
2025-12-05 15:35:48.871046 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-05 15:35:49.369347 | localhost | changed
2025-12-05 15:35:49.374212 | 
2025-12-05 15:35:49.374300 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-05 15:35:49.402362 | localhost | ok
2025-12-05 15:35:49.412738 | 
2025-12-05 15:35:49.412817 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-05 15:35:49.894188 | localhost | changed
2025-12-05 15:35:49.900438 | 
2025-12-05 15:35:49.900511 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-05 15:35:50.956203 | localhost | changed
2025-12-05 15:35:50.961417 | 
2025-12-05 15:35:50.961484 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-05 15:35:51.499880 | localhost | Identity added: /var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/tmp/ansible.hijyoyhi (/var/lib/zuul/builds/d32797e87b6c434d96af804a24bd1808/work/tmp/ansible.hijyoyhi)
2025-12-05 15:35:51.500127 | localhost | ok: Runtime: 0:00:00.023444
2025-12-05 15:35:51.511800 | 
2025-12-05 15:35:51.511882 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-05 15:35:51.959776 | localhost | ok: Runtime: 0:00:00.004840
2025-12-05 15:35:51.964564 | 
2025-12-05 15:35:51.964632 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-05 15:35:52.013380 | localhost | changed
2025-12-05 15:35:52.017919 | 
2025-12-05 15:35:52.017997 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-05 15:35:52.464883 | localhost | changed
2025-12-05 15:35:52.492960 | 
2025-12-05 15:35:52.493111 | PLAY [localhost]
2025-12-05 15:35:52.510184 | 
2025-12-05 15:35:52.510259 | TASK [Generate bulk log download script]
2025-12-05 15:35:52.529705 | localhost | ok
2025-12-05 15:35:52.550323 | 
2025-12-05 15:35:52.550439 | TASK [local-log-download : Check API endpoint is defined]
2025-12-05 15:35:52.593671 | localhost | ok: All assertions passed
2025-12-05 15:35:52.601725 | 
2025-12-05 15:35:52.601883 | TASK [local-log-download : Create download script]
2025-12-05 15:35:53.156526 | localhost -> localhost | changed
2025-12-05 15:35:53.220870 | 
2025-12-05 15:35:53.221010 | TASK [Register quick-download link]
2025-12-05 15:35:53.269911 | localhost | ok
2025-12-05 15:35:53.302206 | 
2025-12-05 15:35:53.302392 | PLAY [logserver.rdoproject.org]
2025-12-05 15:35:53.324833 | 
2025-12-05 15:35:53.324959 | TASK [Set zuul-log-path fact]
2025-12-05 15:35:53.351407 | logserver.rdoproject.org | ok
2025-12-05 15:35:53.363331 | 
2025-12-05 15:35:53.363433 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:35:53.389737 | logserver.rdoproject.org | ok
2025-12-05 15:35:53.395414 | 
2025-12-05 15:35:53.395495 | TASK [upload-logs : Create log directories]
2025-12-05 15:35:54.300348 | logserver.rdoproject.org | changed
2025-12-05 15:35:54.308168 | 
2025-12-05 15:35:54.308247 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-05 15:35:54.686538 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008384
2025-12-05 15:35:54.691263 | 
2025-12-05 15:35:54.691329 | TASK [upload-logs : Upload logs to log server]
2025-12-05 15:35:55.704846 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-05 15:35:55.708951 | 
2025-12-05 15:35:55.709043 | LOOP [upload-logs : Compress console log and json output]
2025-12-05 15:35:55.762259 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:55.771898 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:55.780158 | 
2025-12-05 15:35:55.780289 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-05 15:35:55.830326 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:55.830578 | 
2025-12-05 15:35:55.831177 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:35:55.841723 | 
2025-12-05 15:35:55.841851 | LOOP [upload-logs : Upload console log and json output]