2025-12-01 11:20:35.963449 | Job console starting...
2025-12-01 11:20:35.973218 | Updating repositories
2025-12-01 11:20:36.002543 | Preparing job workspace
2025-12-01 11:20:40.384339 | Running Ansible setup...
2025-12-01 11:20:44.668500 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-01 11:20:45.266705 | 
2025-12-01 11:20:45.266862 | PLAY [localhost]
2025-12-01 11:20:45.275656 | 
2025-12-01 11:20:45.275746 | TASK [Gathering Facts]
2025-12-01 11:20:46.272331 | localhost | ok
2025-12-01 11:20:46.299729 | 
2025-12-01 11:20:46.299819 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-01 11:20:46.685072 | localhost -> localhost | changed
2025-12-01 11:20:46.706937 | 
2025-12-01 11:20:46.707127 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-01 11:20:47.630524 | localhost -> localhost | changed
2025-12-01 11:20:47.652530 | 
2025-12-01 11:20:47.652754 | TASK [Setup log path fact]
2025-12-01 11:20:47.678095 | localhost | ok
2025-12-01 11:20:47.703140 | 
2025-12-01 11:20:47.703297 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-01 11:20:47.739264 | localhost | ok
2025-12-01 11:20:47.750689 | 
2025-12-01 11:20:47.750794 | TASK [emit-job-header : Print job information]
2025-12-01 11:20:47.805652 | # Job Information
2025-12-01 11:20:47.805913 | Ansible Version: 2.15.12
2025-12-01 11:20:47.805963 | Job: cifmw-molecule-cifmw_setup
2025-12-01 11:20:47.806003 | Pipeline: github-check
2025-12-01 11:20:47.806040 | Executor: ze02.softwarefactory-project.io
2025-12-01 11:20:47.806101 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3505
2025-12-01 11:20:47.806144 | Log URL (when completed): https://logserver.rdoproject.org/1f6/rdoproject.org/1f66ce869a4248f99261e0d01ab7587f/
2025-12-01 11:20:47.806184 | Event ID: 8e3602d0-cea7-11f0-850c-489d4625e3c0
2025-12-01 11:20:47.811539 | 
2025-12-01 11:20:47.811744 | LOOP [emit-job-header : Print node information]
2025-12-01 11:20:47.905542 | localhost | ok:
2025-12-01 11:20:47.905715 | localhost | # Node Information
2025-12-01 11:20:47.905744 | localhost | Inventory Hostname: controller
2025-12-01 11:20:47.905767 | localhost | Hostname: np0005541013
2025-12-01 11:20:47.905787 | localhost | Username: zuul
2025-12-01 11:20:47.905808 | localhost | Distro: CentOS 9
2025-12-01 11:20:47.905827 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-01 11:20:47.905844 | localhost | Region: RegionOne
2025-12-01 11:20:47.905862 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-01 11:20:47.905879 | localhost | Product Name: OpenStack Nova
2025-12-01 11:20:47.905896 | localhost | Interface IP: 38.102.83.38
2025-12-01 11:20:47.925498 | 
2025-12-01 11:20:47.925594 | PLAY [all]
2025-12-01 11:20:47.931801 | 
2025-12-01 11:20:47.931861 | TASK [Gather network facts]
2025-12-01 11:20:48.469694 | controller | ok
2025-12-01 11:20:48.503405 | 
2025-12-01 11:20:48.503596 | TASK [include_role : start-zuul-console]
2025-12-01 11:20:48.528754 | controller | ok
2025-12-01 11:20:48.546195 | 
2025-12-01 11:20:48.546305 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-01 11:20:48.980592 | controller | ok
2025-12-01 11:20:49.001006 | 
2025-12-01 11:20:49.001149 | TASK [include_role : add-build-sshkey]
2025-12-01 11:20:49.040332 | controller | ok
2025-12-01 11:20:49.067206 | 
2025-12-01 11:20:49.067344 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-01 11:20:49.368398 | controller -> localhost | ok
2025-12-01 11:20:49.381719 | 
2025-12-01 11:20:49.381859 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-01 11:20:49.423196 | controller | ok
2025-12-01 11:20:49.450629 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-01 11:20:49.458485 | 
2025-12-01 11:20:49.458570 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-01 11:20:50.064264 | controller -> localhost | Generating public/private rsa key pair.
2025-12-01 11:20:50.064536 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/1f66ce869a4248f99261e0d01ab7587f_id_rsa.
2025-12-01 11:20:50.064571 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/1f66ce869a4248f99261e0d01ab7587f_id_rsa.pub.
2025-12-01 11:20:50.064593 | controller -> localhost | The key fingerprint is:
2025-12-01 11:20:50.064613 | controller -> localhost | SHA256:FQxc3HxnjOpbhZR5P+RqzaBxigv4lWbJKi4dckKXEQE zuul-build-sshkey
2025-12-01 11:20:50.064633 | controller -> localhost | The key's randomart image is:
2025-12-01 11:20:50.064653 | controller -> localhost | +---[RSA 3072]----+
2025-12-01 11:20:50.064702 | controller -> localhost | |   E.oo..=oo   = |
2025-12-01 11:20:50.064731 | controller -> localhost | |     .  . o.o *.=|
2025-12-01 11:20:50.064754 | controller -> localhost | |      o   .  +o=.|
2025-12-01 11:20:50.064773 | controller -> localhost | |   . o   . ..o.oo|
2025-12-01 11:20:50.064791 | controller -> localhost | |  . . . S +.= =..|
2025-12-01 11:20:50.064809 | controller -> localhost | |   o + . O o.o.o |
2025-12-01 11:20:50.064827 | controller -> localhost | |    = o * . .o   |
2025-12-01 11:20:50.064844 | controller -> localhost | |   . o o .  .    |
2025-12-01 11:20:50.064862 | controller -> localhost | |    o..          |
2025-12-01 11:20:50.064879 | controller -> localhost | +----[SHA256]-----+
2025-12-01 11:20:50.064947 | controller -> localhost | ok: Runtime: 0:00:00.121759
2025-12-01 11:20:50.071002 | 
2025-12-01 11:20:50.071065 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-01 11:20:50.092605 | controller | ok
2025-12-01 11:20:50.102198 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-01 11:20:50.110342 | 
2025-12-01 11:20:50.110422 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-01 11:20:50.135604 | controller | skipping: Conditional result was False
2025-12-01 11:20:50.141044 | 
2025-12-01 11:20:50.141108 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-01 11:20:50.622906 | controller | changed
2025-12-01 11:20:50.634065 | 
2025-12-01 11:20:50.634200 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-01 11:20:50.905386 | controller | ok
2025-12-01 11:20:50.916431 | 
2025-12-01 11:20:50.916591 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-01 11:20:51.799815 | controller | changed
2025-12-01 11:20:51.810523 | 
2025-12-01 11:20:51.810654 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-01 11:20:52.785315 | controller | changed
2025-12-01 11:20:52.796720 | 
2025-12-01 11:20:52.796879 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-01 11:20:52.830081 | controller | skipping: Conditional result was False
2025-12-01 11:20:52.839873 | 
2025-12-01 11:20:52.839960 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-01 11:20:53.261907 | controller -> localhost | changed
2025-12-01 11:20:53.272681 | 
2025-12-01 11:20:53.272751 | TASK [add-build-sshkey : Add back temp key]
2025-12-01 11:20:53.594093 | controller -> localhost | Identity added: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/1f66ce869a4248f99261e0d01ab7587f_id_rsa (zuul-build-sshkey)
2025-12-01 11:20:53.594451 | controller -> localhost | ok: Runtime: 0:00:00.010009
2025-12-01 11:20:53.606531 | 
2025-12-01 11:20:53.606726 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-01 11:20:53.968192 | controller | ok
2025-12-01 11:20:53.974733 | 
2025-12-01 11:20:53.974822 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-01 11:20:54.009642 | controller | skipping: Conditional result was False
2025-12-01 11:20:54.024211 | 
2025-12-01 11:20:54.024360 | TASK [include_role : validate-host]
2025-12-01 11:20:54.059754 | controller | ok
2025-12-01 11:20:54.093097 | 
2025-12-01 11:20:54.093260 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-01 11:20:54.136257 | controller | ok
2025-12-01 11:20:54.148435 | 
2025-12-01 11:20:54.148595 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-01 11:20:54.389714 | controller -> localhost | ok
2025-12-01 11:20:54.403017 | 
2025-12-01 11:20:54.403121 | TASK [validate-host : Collect information about the host]
2025-12-01 11:20:55.283474 | controller | ok
2025-12-01 11:20:55.295646 | 
2025-12-01 11:20:55.295788 | TASK [validate-host : Sanitize hostname]
2025-12-01 11:20:55.361123 | controller | ok
2025-12-01 11:20:55.368200 | 
2025-12-01 11:20:55.368292 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-01 11:20:55.833158 | controller -> localhost | changed
2025-12-01 11:20:55.841196 | 
2025-12-01 11:20:55.841283 | TASK [validate-host : Collect information about zuul worker]
2025-12-01 11:20:56.278651 | controller | ok
2025-12-01 11:20:56.283441 | 
2025-12-01 11:20:56.283532 | TASK [validate-host : Write out all zuul information for each host]
2025-12-01 11:20:56.774888 | controller -> localhost | changed
2025-12-01 11:20:56.785138 | 
2025-12-01 11:20:56.785216 | TASK [include_role : prepare-workspace-openshift]
2025-12-01 11:20:56.810630 | controller | skipping: Conditional result was False
2025-12-01 11:20:56.818046 | 
2025-12-01 11:20:56.818133 | TASK [include_role : remove-zuul-sshkey]
2025-12-01 11:20:56.843827 | controller | skipping: Conditional result was False
2025-12-01 11:20:56.852115 | 
2025-12-01 11:20:56.852209 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-01 11:20:57.142788 | controller | ok: "logs"
2025-12-01 11:20:57.143356 | controller | ok: All items complete
2025-12-01 11:20:57.143421 | 
2025-12-01 11:20:57.364519 | controller | ok: "artifacts"
2025-12-01 11:20:57.599772 | controller | ok: "docs"
2025-12-01 11:20:57.615342 | 
2025-12-01 11:20:57.615550 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-01 11:20:58.312722 | controller | changed: "logs"
2025-12-01 11:20:58.565251 | controller | changed: "artifacts"
2025-12-01 11:20:58.867623 | controller | changed: "docs"
2025-12-01 11:20:58.901279 | 
2025-12-01 11:20:58.901405 | PLAY RECAP
2025-12-01 11:20:58.901461 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-01 11:20:58.901497 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-01 11:20:58.901522 | 
2025-12-01 11:20:59.002485 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-01 11:20:59.003618 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-01 11:20:59.612515 | 
2025-12-01 11:20:59.612624 | PLAY [localhost]
2025-12-01 11:20:59.628384 | 
2025-12-01 11:20:59.628498 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-01 11:21:00.060639 | localhost | ok
2025-12-01 11:21:00.076842 | 
2025-12-01 11:21:00.077051 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-01 11:21:00.804470 | localhost | changed
2025-12-01 11:21:00.825891 | 
2025-12-01 11:21:00.826019 | PLAY [all]
2025-12-01 11:21:00.842603 | 
2025-12-01 11:21:00.842731 | TASK [include_role : prepare-workspace]
2025-12-01 11:21:00.863415 | controller | ok
2025-12-01 11:21:00.879768 | 
2025-12-01 11:21:00.879914 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-01 11:21:01.315471 | controller | ok
2025-12-01 11:21:01.331891 | 
2025-12-01 11:21:01.332074 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-01 11:21:03.058443 | controller | Output suppressed because no_log was given
2025-12-01 11:21:03.080855 | 
2025-12-01 11:21:03.080996 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-01 11:21:03.338378 | controller | changed: "logs"
2025-12-01 11:21:03.573547 | controller | changed: "artifacts"
2025-12-01 11:21:03.843433 | controller | changed: "docs"
2025-12-01 11:21:03.857817 | 
2025-12-01 11:21:03.857975 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-01 11:21:04.171247 | controller | changed: "logs"
2025-12-01 11:21:04.171564 | controller | changed: All items complete
2025-12-01 11:21:04.171609 | 
2025-12-01 11:21:04.423795 | controller | changed: "artifacts"
2025-12-01 11:21:04.665802 | controller | changed: "docs"
2025-12-01 11:21:04.697148 | 
2025-12-01 11:21:04.697293 | TASK [Check if worker can sudo]
2025-12-01 11:21:05.262729 | controller | ok: Runtime: 0:00:00.059125
2025-12-01 11:21:05.275534 | 
2025-12-01 11:21:05.275742 | TASK [configure-mirrors : Gather needed facts]
2025-12-01 11:21:05.344928 | controller | skipping: Conditional result was False
2025-12-01 11:21:05.354140 | 
2025-12-01 11:21:05.354282 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-01 11:21:05.416550 | controller | ok
2025-12-01 11:21:05.427647 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-01 11:21:05.435728 | 
2025-12-01 11:21:05.435811 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-01 11:21:05.792114 | controller | ok
2025-12-01 11:21:05.805297 | 
2025-12-01 11:21:05.805453 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-01 11:21:05.898820 | controller | ok: "/var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-01 11:21:05.907422 | 
2025-12-01 11:21:05.907544 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-01 11:21:07.203372 | controller | changed
2025-12-01 11:21:07.212493 | 
2025-12-01 11:21:07.212576 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-01 11:21:07.305533 | controller | ok: "/var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-01 11:21:07.306204 | controller | ok: All items complete
2025-12-01 11:21:07.306292 | 
2025-12-01 11:21:07.386288 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-01 11:21:07.395756 | 
2025-12-01 11:21:07.395913 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-01 11:21:08.304948 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-01 11:21:09.177329 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-01 11:21:09.199179 | 
2025-12-01 11:21:09.199348 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-01 11:21:09.689728 | controller | changed: section and option added
2025-12-01 11:21:09.732310 | 
2025-12-01 11:21:09.732458 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-01 11:21:10.360728 | controller | 29 files removed
2025-12-01 11:21:10.361208 | controller | ok: Item: dnf clean all Runtime: 0:00:00.283739
2025-12-01 11:21:10.361333 | controller | changed: All items complete
2025-12-01 11:21:10.361396 | 
2025-12-01 11:21:21.686481 | 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-01 11:21:21.686730 | controller | DNF version: 4.14.0
2025-12-01 11:21:21.686835 | controller | cachedir: /var/cache/dnf
2025-12-01 11:21:21.686920 | controller | Making cache files for all metadata files.
2025-12-01 11:21:21.686998 | controller | baseos: has expired and will be refreshed.
2025-12-01 11:21:21.687077 | controller | appstream: has expired and will be refreshed.
2025-12-01 11:21:21.687147 | controller | crb: has expired and will be refreshed.
2025-12-01 11:21:21.687254 | controller | extras-common: has expired and will be refreshed.
2025-12-01 11:21:21.687304 | controller | repo: downloading from remote: baseos
2025-12-01 11:21:21.687356 | controller | CentOS Stream 9 - BaseOS                         64 MB/s | 8.8 MB     00:00
2025-12-01 11:21:21.687407 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST.
2025-12-01 11:21:21.687456 | controller | repo: downloading from remote: appstream
2025-12-01 11:21:21.687505 | controller | CentOS Stream 9 - AppStream                      78 MB/s |  25 MB     00:00
2025-12-01 11:21:21.687555 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST.
2025-12-01 11:21:21.687645 | controller | repo: downloading from remote: crb
2025-12-01 11:21:21.687741 | controller | CentOS Stream 9 - CRB                            33 MB/s | 7.3 MB     00:00
2025-12-01 11:21:21.687795 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST.
2025-12-01 11:21:21.687845 | controller | repo: downloading from remote: extras-common
2025-12-01 11:21:21.687895 | controller | CentOS Stream 9 - Extras packages               1.3 MB/s |  20 kB     00:00
2025-12-01 11:21:21.687943 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-01 11:21:21.687991 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-01 11:21:21.688040 | controller | Completion plugin: Generating completion cache...
2025-12-01 11:21:21.688088 | controller | Metadata cache created.
2025-12-01 11:21:21.688159 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.065102
2025-12-01 11:21:21.717600 | 
2025-12-01 11:21:21.717818 | PLAY RECAP
2025-12-01 11:21:21.717935 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-01 11:21:21.717995 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-01 11:21:21.718034 | 
2025-12-01 11:21:21.853098 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-01 11:21:21.853930 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-01 11:21:22.535895 | 
2025-12-01 11:21:22.536052 | PLAY [all]
2025-12-01 11:21:22.557273 | 
2025-12-01 11:21:22.557368 | TASK [Install binary dependencies]
2025-12-01 11:21:22.636552 | controller | ok
2025-12-01 11:21:22.669040 | 
2025-12-01 11:21:22.669152 | TASK [bindep : Include find tasks]
2025-12-01 11:21:22.703183 | controller | ok
2025-12-01 11:21:22.713498 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-01 11:21:22.722221 | 
2025-12-01 11:21:22.722319 | TASK [bindep : Look for bindep.txt]
2025-12-01 11:21:23.142790 | controller | ok
2025-12-01 11:21:23.149366 | 
2025-12-01 11:21:23.149437 | TASK [bindep : Define bindep_file fact]
2025-12-01 11:21:23.180963 | controller | ok
2025-12-01 11:21:23.186187 | 
2025-12-01 11:21:23.186254 | TASK [bindep : Look for other-requirements.txt]
2025-12-01 11:21:23.211214 | controller | skipping: Conditional result was False
2025-12-01 11:21:23.217688 | 
2025-12-01 11:21:23.217758 | TASK [bindep : Define bindep_file fact]
2025-12-01 11:21:23.252584 | controller | skipping: Conditional result was False
2025-12-01 11:21:23.258494 | 
2025-12-01 11:21:23.258559 | TASK [bindep : Look for bindep fallback file]
2025-12-01 11:21:23.303994 | controller | skipping: Conditional result was False
2025-12-01 11:21:23.309805 | 
2025-12-01 11:21:23.309872 | TASK [bindep : Define bindep_file fact]
2025-12-01 11:21:23.345007 | controller | skipping: Conditional result was False
2025-12-01 11:21:23.351742 | 
2025-12-01 11:21:23.351820 | TASK [bindep : Include bindep tasks]
2025-12-01 11:21:23.403196 | controller | ok
2025-12-01 11:21:23.409843 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-01 11:21:23.417908 | 
2025-12-01 11:21:23.417975 | TASK [bindep : Look for bindep command]
2025-12-01 11:21:23.453177 | controller | skipping: Conditional result was False
2025-12-01 11:21:23.460710 | 
2025-12-01 11:21:23.460787 | TASK [bindep : Check for system bindep]
2025-12-01 11:21:23.997847 | controller | ok: Runtime: 0:00:00.008924
2025-12-01 11:21:24.011742 | 
2025-12-01 11:21:24.011901 | TASK [bindep : Define bindep_command fact]
2025-12-01 11:21:24.053456 | controller | skipping: Conditional result was False
2025-12-01 11:21:24.071332 | 
2025-12-01 11:21:24.071509 | TASK [bindep : Include install tasks]
2025-12-01 11:21:24.129816 | controller | ok
2025-12-01 11:21:24.139532 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-01 11:21:24.151629 | 
2025-12-01 11:21:24.151730 | TASK [bindep : Create temp dir for bindep]
2025-12-01 11:21:24.585742 | controller | changed
2025-12-01 11:21:24.597570 | 
2025-12-01 11:21:24.597728 | TASK [Ensure we have pip dependencies]
2025-12-01 11:21:24.625921 | controller | ok
2025-12-01 11:21:24.666261 | 
2025-12-01 11:21:24.666412 | TASK [ensure-pip : Check if pip is installed]
2025-12-01 06:21:24.978942 | controller | /usr/bin/pip3
2025-12-01 06:21:25.006784 | controller | /usr/bin/python3: No module named wheel
2025-12-01 11:21:25.203982 | controller | ok: Runtime: 0:00:00.046447
2025-12-01 11:21:25.212455 | 
2025-12-01 11:21:25.212584 | LOOP [ensure-pip : Install pip from packages]
2025-12-01 11:21:25.258154 | controller | ok: "/var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-01 11:21:25.269006 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-01 11:21:25.283393 | 
2025-12-01 11:21:25.283571 | TASK [ensure-pip : Install Python 3 pip]
2025-12-01 11:21:27.677582 | controller | changed
2025-12-01 11:21:27.688922 | 
2025-12-01 11:21:27.689050 | TASK [ensure-pip : Check for EPEL repository]
2025-12-01 11:21:27.757908 | controller | skipping: Conditional result was False
2025-12-01 11:21:27.770503 | 
2025-12-01 11:21:27.770642 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-01 11:21:27.829451 | controller | skipping: Conditional result was False
2025-12-01 11:21:27.843110 | 
2025-12-01 11:21:27.843251 | TASK [ensure-pip : Install Python 2 pip]
2025-12-01 11:21:27.891563 | controller | skipping: Conditional result was False
2025-12-01 11:21:27.905131 | 
2025-12-01 11:21:27.905262 | TASK [ensure-pip : Ensure setuptools]
2025-12-01 11:21:27.932594 | controller | skipping: Conditional result was False
2025-12-01 11:21:27.945777 | 
2025-12-01 11:21:27.945926 | TASK [ensure-pip : Check for ensurepip module]
2025-12-01 11:21:28.495643 | controller | skipping: Conditional result was False
2025-12-01 11:21:28.509128 | 
2025-12-01 11:21:28.509316 | TASK [ensure-pip : Ensure python3-venv]
2025-12-01 11:21:28.537779 | controller | skipping: Conditional result was False
2025-12-01 11:21:28.551636 | 
2025-12-01 11:21:28.551829 | TASK [ensure-pip : Install pip from source]
2025-12-01 11:21:28.579826 | controller | skipping: Conditional result was False
2025-12-01 11:21:28.592216 | 
2025-12-01 11:21:28.592347 | TASK [ensure-pip : Probe for venv python full path]
2025-12-01 06:21:28.899410 | controller | /usr/bin/python3
2025-12-01 11:21:29.139754 | controller | ok: Runtime: 0:00:00.010923
2025-12-01 11:21:29.152092 | 
2025-12-01 11:21:29.152270 | TASK [ensure-pip : Set host default]
2025-12-01 11:21:29.231918 | controller | ok
2025-12-01 11:21:29.243171 | 
2025-12-01 11:21:29.243304 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-01 11:21:29.322172 | controller | ok
2025-12-01 11:21:29.350365 | 
2025-12-01 11:21:29.350536 | TASK [bindep : Install bindep into temporary venv]
2025-12-01 11:21:33.537974 | controller | changed
2025-12-01 11:21:33.543960 | 
2025-12-01 11:21:33.544032 | TASK [bindep : Define bindep_command]
2025-12-01 11:21:33.588808 | controller | ok
2025-12-01 11:21:33.599979 | 
2025-12-01 11:21:33.600113 | LOOP [bindep : Include package tasks]
2025-12-01 11:21:33.680117 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-01 11:21:33.680529 | controller | ok: All items complete
2025-12-01 11:21:33.680598 | 
2025-12-01 11:21:33.722814 | controller | included: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-01 11:21:33.740432 | 
2025-12-01 11:21:33.740601 | TASK [bindep : Define bindep_run fact]
2025-12-01 11:21:33.784592 | controller | ok
2025-12-01 11:21:33.791990 | 
2025-12-01 11:21:33.792112 | TASK [bindep : Get list of packages to install from bindep]
2025-12-01 06:21:35.361443 | controller | podman
2025-12-01 06:21:35.402410 | controller | python3-jmespath
2025-12-01 06:21:35.402700 | controller | python3-libvirt
2025-12-01 06:21:35.402723 | controller | python3-lxml
2025-12-01 06:21:35.402744 | controller | python3-netaddr
2025-12-01 11:21:35.843213 | controller | ok: Runtime: 0:00:01.321641
2025-12-01 11:21:35.856694 | 
2025-12-01 11:21:35.856950 | TASK [bindep : Install distro packages from bindep]
2025-12-01 11:22:51.575887 | controller | changed
2025-12-01 11:22:51.587493 | 
2025-12-01 11:22:51.587627 | TASK [bindep : Check that packages are installed]
2025-12-01 11:22:53.639812 | controller | ok: Runtime: 0:00:01.561819
2025-12-01 11:22:53.652168 | 
2025-12-01 11:22:53.652326 | TASK [bindep : Fail if we cannot install all packages]
2025-12-01 11:22:53.689982 | controller | skipping: Conditional result was False
2025-12-01 11:22:53.711583 | 
2025-12-01 11:22:53.711744 | TASK [Run test-setup role]
2025-12-01 11:22:53.740899 | controller | ok
2025-12-01 11:22:53.772114 | 
2025-12-01 11:22:53.772216 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-01 11:22:54.012629 | controller | ok
2025-12-01 11:22:54.023386 | 
2025-12-01 11:22:54.023527 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-01 11:22:54.583103 | controller | skipping: Conditional result was False
2025-12-01 11:22:54.626449 | 
2025-12-01 11:22:54.626627 | TASK [bindep : Remove bindep temp dir]
2025-12-01 11:22:55.075656 | controller | ok
2025-12-01 11:22:55.100100 | 
2025-12-01 11:22:55.100212 | PLAY RECAP
2025-12-01 11:22:55.100296 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-01 11:22:55.100340 | 
2025-12-01 11:22:55.218767 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-01 11:22:55.220856 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-01 11:22:55.788349 | 
2025-12-01 11:22:55.788452 | PLAY [all]
2025-12-01 11:22:55.807136 | 
2025-12-01 11:22:55.807210 | TASK [Abort when test_command variable is undefined]
2025-12-01 11:22:55.842771 | controller | skipping: Conditional result was False
2025-12-01 11:22:55.849360 | 
2025-12-01 11:22:55.849444 | TASK [Convert test_command to list]
2025-12-01 11:22:55.884853 | controller | skipping: Conditional result was False
2025-12-01 11:22:55.891427 | 
2025-12-01 11:22:55.891499 | TASK [Use test_command list]
2025-12-01 11:22:55.963810 | controller | ok
2025-12-01 11:22:55.971136 | 
2025-12-01 11:22:55.971226 | LOOP [Run test_command]
2025-12-01 11:22:56.379179 | controller | no check to run
2025-12-01 11:22:56.379482 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006197
2025-12-01 11:22:56.432834 | 
2025-12-01 11:22:56.432956 | PLAY RECAP
2025-12-01 11:22:56.433012 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-01 11:22:56.433038 | 
2025-12-01 11:22:56.528079 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-01 11:22:56.529777 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-01 11:22:57.120837 | 
2025-12-01 11:22:57.120950 | PLAY [all]
2025-12-01 11:22:57.144485 | 
2025-12-01 11:22:57.144644 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-01 11:22:57.540380 | controller | changed: non-zero return code
2025-12-01 11:22:57.552746 | 
2025-12-01 11:22:57.552908 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-01 11:22:57.582574 | controller | skipping: Conditional result was False
2025-12-01 11:22:57.594566 | 
2025-12-01 11:22:57.594762 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-01 11:22:57.636408 | 
2025-12-01 11:22:57.636733 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-01 11:22:57.678714 | 
2025-12-01 11:22:57.678993 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-01 11:22:57.707120 | controller | skipping: Conditional result was False
2025-12-01 11:22:57.720209 | 
2025-12-01 11:22:57.720362 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-01 11:22:57.763651 | 
2025-12-01 11:22:57.763974 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-01 11:22:57.793021 | controller | skipping: Conditional result was False
2025-12-01 11:22:57.806209 | 
2025-12-01 11:22:57.806406 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-01 11:22:57.834972 | controller | skipping: Conditional result was False
2025-12-01 11:22:57.847630 | 
2025-12-01 11:22:57.847804 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-01 11:22:57.875600 | controller | skipping: Conditional result was False
2025-12-01 11:22:57.920867 | 
2025-12-01 11:22:57.920983 | PLAY RECAP
2025-12-01 11:22:57.921030 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-01 11:22:57.921054 | 
2025-12-01 11:22:58.024350 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-01 11:22:58.025183 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-01 11:22:58.638810 | 
2025-12-01 11:22:58.638924 | PLAY [all]
2025-12-01 11:22:58.659042 | 
2025-12-01 11:22:58.659135 | TASK [include_role : fetch-output]
2025-12-01 11:22:58.708641 | controller | ok
2025-12-01 11:22:58.727310 | 
2025-12-01 11:22:58.727411 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-01 11:22:58.794481 | controller | skipping: Conditional result was False
2025-12-01 11:22:58.806699 | 
2025-12-01 11:22:58.806808 | TASK [fetch-output : Set log path for single node]
2025-12-01 11:22:58.852516 | controller | ok
2025-12-01 11:22:58.859827 | 
2025-12-01 11:22:58.859916 | LOOP [fetch-output : Ensure local output dirs]
2025-12-01 11:22:59.288287 | controller -> localhost | ok: "/var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/logs"
2025-12-01 11:22:59.540579 | controller -> localhost | changed: "/var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/artifacts"
2025-12-01 11:22:59.795763 | controller -> localhost | changed: "/var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/docs"
2025-12-01 11:22:59.822858 | 
2025-12-01 11:22:59.823074 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-01 11:23:00.664340 | controller | changed: .d..t...... ./
2025-12-01 11:23:00.664755 | controller | changed: All items complete
2025-12-01 11:23:00.664860 | 
2025-12-01 11:23:01.224080 | controller | changed: .d..t...... ./
2025-12-01 11:23:01.752871 | controller | changed: .d..t...... ./
2025-12-01 11:23:01.786757 | 
2025-12-01 11:23:01.786992 | TASK [include_role : fetch-output-openshift]
2025-12-01 11:23:01.806116 | controller | skipping: Conditional result was False
2025-12-01 11:23:01.821041 | 
2025-12-01 11:23:01.821197 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-01 11:23:02.268343 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014669
2025-12-01 11:23:02.515623 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012824
2025-12-01 11:23:02.580657 | 
2025-12-01 11:23:02.580826 | PLAY [all]
2025-12-01 11:23:02.603822 | 
2025-12-01 11:23:02.603998 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-01 11:23:03.042602 | controller | changed
2025-12-01 11:23:03.090389 | 
2025-12-01 11:23:03.090497 | PLAY RECAP
2025-12-01 11:23:03.090556 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-01 11:23:03.090587 | 
2025-12-01 11:23:03.196198 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-01 11:23:03.197904 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-01 11:23:03.813898 | 
2025-12-01 11:23:03.814067 | PLAY [localhost]
2025-12-01 11:23:03.832816 | 
2025-12-01 11:23:03.832927 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-01 11:23:04.265230 | localhost | changed
2025-12-01 11:23:04.275970 | 
2025-12-01 11:23:04.276131 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-01 11:23:04.302422 | localhost | ok
2025-12-01 11:23:04.319742 | 
2025-12-01 11:23:04.319885 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-01 11:23:04.723868 | localhost | changed
2025-12-01 11:23:04.737816 | 
2025-12-01 11:23:04.738018 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-01 11:23:05.577360 | localhost | changed
2025-12-01 11:23:05.582615 | 
2025-12-01 11:23:05.582698 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-01 11:23:06.006883 | localhost | Identity added: /var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/tmp/ansible.73v5emly (/var/lib/zuul/builds/1f66ce869a4248f99261e0d01ab7587f/work/tmp/ansible.73v5emly)
2025-12-01 11:23:06.007280 | localhost | ok: Runtime: 0:00:00.016179
2025-12-01 11:23:06.018507 | 
2025-12-01 11:23:06.018710 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-01 11:23:06.337452 | localhost | ok: Runtime: 0:00:00.010452
2025-12-01 11:23:06.342926 | 
2025-12-01 11:23:06.342997 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-01 11:23:06.431055 | localhost | changed
2025-12-01 11:23:06.441230 | 
2025-12-01 11:23:06.441369 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-01 11:23:06.888737 | localhost | changed
2025-12-01 11:23:06.933374 | 
2025-12-01 11:23:06.933560 | PLAY [localhost]
2025-12-01 11:23:06.951982 | 
2025-12-01 11:23:06.952071 | TASK [Generate bulk log download script]
2025-12-01 11:23:06.977170 | localhost | ok
2025-12-01 11:23:06.994975 | 
2025-12-01 11:23:06.995120 | TASK [local-log-download : Check API endpoint is defined]
2025-12-01 11:23:07.048498 | localhost | ok: All assertions passed
2025-12-01 11:23:07.055908 | 
2025-12-01 11:23:07.056018 | TASK [local-log-download : Create download script]
2025-12-01 11:23:07.542560 | localhost -> localhost | changed
2025-12-01 11:23:07.563293 | 
2025-12-01 11:23:07.563438 | TASK [Register quick-download link]
2025-12-01 11:23:07.595174 | localhost | ok
2025-12-01 11:23:07.659704 | 
2025-12-01 11:23:07.659844 | PLAY [logserver.rdoproject.org]
2025-12-01 11:23:07.670016 | 
2025-12-01 11:23:07.670082 | TASK [Set zuul-log-path fact]
2025-12-01 11:23:07.698484 | logserver.rdoproject.org | ok
2025-12-01 11:23:07.707385 | 
2025-12-01 11:23:07.707451 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-01 11:23:07.736565 | logserver.rdoproject.org | ok
2025-12-01 11:23:07.743945 | 
2025-12-01 11:23:07.744030 | TASK [upload-logs : Create log directories]
2025-12-01 11:23:08.654144 | logserver.rdoproject.org | changed
2025-12-01 11:23:08.660976 | 
2025-12-01 11:23:08.661116 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-01 11:23:08.992751 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006553
2025-12-01 11:23:08.997516 | 
2025-12-01 11:23:08.997581 | TASK [upload-logs : Upload logs to log server]
2025-12-01 11:23:09.671710 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-01 11:23:09.678067 | 
2025-12-01 11:23:09.678202 | LOOP [upload-logs : Compress console log and json output]
2025-12-01 11:23:09.722909 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 11:23:09.744210 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 11:23:09.754140 | 
2025-12-01 11:23:09.754335 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-01 11:23:09.796777 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 11:23:09.797043 | 
2025-12-01 11:23:09.801733 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-01 11:23:09.808292 | 
2025-12-01 11:23:09.808429 | LOOP [upload-logs : Upload console log and json output]