2025-10-13 06:07:23.003872 | Job console starting...
2025-10-13 06:07:23.018445 | Updating repositories
2025-10-13 06:07:23.115927 | Preparing job workspace
2025-10-13 06:07:27.911040 | Running Ansible setup...
2025-10-13 06:07:31.792546 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:07:32.376450 | 
2025-10-13 06:07:32.376598 | PLAY [localhost]
2025-10-13 06:07:32.385787 | 
2025-10-13 06:07:32.385876 | TASK [Gathering Facts]
2025-10-13 06:07:33.344712 | localhost | ok
2025-10-13 06:07:33.357921 | 
2025-10-13 06:07:33.357994 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 06:07:33.760650 | localhost -> localhost | changed
2025-10-13 06:07:33.768751 | 
2025-10-13 06:07:33.768821 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 06:07:34.756032 | localhost -> localhost | changed
2025-10-13 06:07:34.764597 | 
2025-10-13 06:07:34.764663 | TASK [Setup log path fact]
2025-10-13 06:07:34.797040 | localhost | ok
2025-10-13 06:07:34.808805 | 
2025-10-13 06:07:34.808871 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:07:34.835821 | localhost | ok
2025-10-13 06:07:34.843809 | 
2025-10-13 06:07:34.843872 | TASK [emit-job-header : Print job information]
2025-10-13 06:07:34.871240 | # Job Information
2025-10-13 06:07:34.871379 | Ansible Version: 2.15.12
2025-10-13 06:07:34.871404 | Job: cifmw-molecule-cifmw_helpers
2025-10-13 06:07:34.871424 | Pipeline: github-check
2025-10-13 06:07:34.871442 | Executor: ze04.softwarefactory-project.io
2025-10-13 06:07:34.871460 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-13 06:07:34.871480 | Log URL (when completed): https://logserver.rdoproject.org/e25/rdoproject.org/e25ec455fd454e149a3494d7f7ddcc05/
2025-10-13 06:07:34.871498 | Event ID: a3968a60-a7fa-11f0-8c52-d08cf4908dcc
2025-10-13 06:07:34.875097 | 
2025-10-13 06:07:34.875156 | LOOP [emit-job-header : Print node information]
2025-10-13 06:07:34.964568 | localhost | ok:
2025-10-13 06:07:34.964961 | localhost | # Node Information
2025-10-13 06:07:34.965006 | localhost | Inventory Hostname: controller
2025-10-13 06:07:34.965038 | localhost | Hostname: np0005482064
2025-10-13 06:07:34.965065 | localhost | Username: zuul
2025-10-13 06:07:34.965109 | localhost | Distro: CentOS 9
2025-10-13 06:07:34.965134 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 06:07:34.965158 | localhost | Region: RegionOne
2025-10-13 06:07:34.965181 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 06:07:34.965204 | localhost | Product Name: OpenStack Nova
2025-10-13 06:07:34.965227 | localhost | Interface IP: 38.102.83.192
2025-10-13 06:07:34.990566 | 
2025-10-13 06:07:34.990641 | PLAY [all]
2025-10-13 06:07:34.999937 | 
2025-10-13 06:07:35.000019 | TASK [Gather network facts]
2025-10-13 06:07:35.549995 | controller | ok
2025-10-13 06:07:35.585896 | 
2025-10-13 06:07:35.585984 | TASK [include_role : start-zuul-console]
2025-10-13 06:07:35.605862 | controller | ok
2025-10-13 06:07:35.620707 | 
2025-10-13 06:07:35.620773 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 06:07:36.051550 | controller | ok
2025-10-13 06:07:36.077379 | 
2025-10-13 06:07:36.077454 | TASK [include_role : add-build-sshkey]
2025-10-13 06:07:36.118712 | controller | ok
2025-10-13 06:07:36.141241 | 
2025-10-13 06:07:36.141318 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 06:07:36.437880 | controller -> localhost | ok
2025-10-13 06:07:36.443764 | 
2025-10-13 06:07:36.443825 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 06:07:36.472511 | controller | ok
2025-10-13 06:07:36.485359 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 06:07:36.491072 | 
2025-10-13 06:07:36.491133 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 06:07:37.314178 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 06:07:37.314376 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/e25ec455fd454e149a3494d7f7ddcc05_id_rsa.
2025-10-13 06:07:37.314411 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/e25ec455fd454e149a3494d7f7ddcc05_id_rsa.pub.
2025-10-13 06:07:37.314434 | controller -> localhost | The key fingerprint is:
2025-10-13 06:07:37.314454 | controller -> localhost | SHA256:08A+u1sqNPLhfxH1SQYJevjoodA+uecKbccPj7+Mvmo zuul-build-sshkey
2025-10-13 06:07:37.314474 | controller -> localhost | The key's randomart image is:
2025-10-13 06:07:37.314492 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 06:07:37.314509 | controller -> localhost | |          ...o   |
2025-10-13 06:07:37.314527 | controller -> localhost | |       . o  o o  |
2025-10-13 06:07:37.314544 | controller -> localhost | |        = .. + . |
2025-10-13 06:07:37.314562 | controller -> localhost | |     . . *.   o  |
2025-10-13 06:07:37.314579 | controller -> localhost | |    . . S o.     |
2025-10-13 06:07:37.314596 | controller -> localhost | |    .++= =.      |
2025-10-13 06:07:37.314613 | controller -> localhost | |    .=Bo* ..     |
2025-10-13 06:07:37.314629 | controller -> localhost | |     oE+.@.      |
2025-10-13 06:07:37.314646 | controller -> localhost | |     .+O@=*.     |
2025-10-13 06:07:37.314663 | controller -> localhost | +----[SHA256]-----+
2025-10-13 06:07:37.314932 | controller -> localhost | ok: Runtime: 0:00:00.263366
2025-10-13 06:07:37.320821 | 
2025-10-13 06:07:37.320894 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 06:07:37.349279 | controller | ok
2025-10-13 06:07:37.359628 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 06:07:37.382076 | 
2025-10-13 06:07:37.382151 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 06:07:37.416432 | controller | skipping: Conditional result was False
2025-10-13 06:07:37.422966 | 
2025-10-13 06:07:37.423030 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 06:07:37.913720 | controller | changed
2025-10-13 06:07:37.918540 | 
2025-10-13 06:07:37.918601 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 06:07:38.224980 | controller | ok
2025-10-13 06:07:38.231829 | 
2025-10-13 06:07:38.231910 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 06:07:39.207173 | controller | changed
2025-10-13 06:07:39.212785 | 
2025-10-13 06:07:39.212849 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 06:07:40.275882 | controller | changed
2025-10-13 06:07:40.286630 | 
2025-10-13 06:07:40.286757 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 06:07:40.301774 | controller | skipping: Conditional result was False
2025-10-13 06:07:40.309503 | 
2025-10-13 06:07:40.309589 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 06:07:40.692167 | controller -> localhost | changed
2025-10-13 06:07:40.701844 | 
2025-10-13 06:07:40.701908 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 06:07:40.945784 | controller -> localhost | Identity added: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/e25ec455fd454e149a3494d7f7ddcc05_id_rsa (zuul-build-sshkey)
2025-10-13 06:07:40.945967 | controller -> localhost | ok: Runtime: 0:00:00.008674
2025-10-13 06:07:40.951447 | 
2025-10-13 06:07:40.951505 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 06:07:41.370889 | controller | ok
2025-10-13 06:07:41.375562 | 
2025-10-13 06:07:41.375626 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 06:07:41.413159 | controller | skipping: Conditional result was False
2025-10-13 06:07:41.423005 | 
2025-10-13 06:07:41.423064 | TASK [include_role : validate-host]
2025-10-13 06:07:41.462503 | controller | ok
2025-10-13 06:07:41.487875 | 
2025-10-13 06:07:41.487959 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 06:07:41.516578 | controller | ok
2025-10-13 06:07:41.521050 | 
2025-10-13 06:07:41.521106 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 06:07:41.777734 | controller -> localhost | ok
2025-10-13 06:07:41.784424 | 
2025-10-13 06:07:41.784498 | TASK [validate-host : Collect information about the host]
2025-10-13 06:07:42.705227 | controller | ok
2025-10-13 06:07:42.713837 | 
2025-10-13 06:07:42.713897 | TASK [validate-host : Sanitize hostname]
2025-10-13 06:07:42.773476 | controller | ok
2025-10-13 06:07:42.778605 | 
2025-10-13 06:07:42.778668 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 06:07:43.231045 | controller -> localhost | changed
2025-10-13 06:07:43.237745 | 
2025-10-13 06:07:43.237822 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 06:07:43.737921 | controller | ok
2025-10-13 06:07:43.751719 | 
2025-10-13 06:07:43.751836 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 06:07:44.248591 | controller -> localhost | changed
2025-10-13 06:07:44.260087 | 
2025-10-13 06:07:44.260270 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 06:07:44.283995 | controller | skipping: Conditional result was False
2025-10-13 06:07:44.290136 | 
2025-10-13 06:07:44.290200 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 06:07:44.314291 | controller | skipping: Conditional result was False
2025-10-13 06:07:44.330533 | 
2025-10-13 06:07:44.330623 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:07:44.659321 | controller | ok: "logs"
2025-10-13 06:07:44.659524 | controller | ok: All items complete
2025-10-13 06:07:44.659565 | 
2025-10-13 06:07:44.906425 | controller | ok: "artifacts"
2025-10-13 06:07:45.169994 | controller | ok: "docs"
2025-10-13 06:07:45.179234 | 
2025-10-13 06:07:45.179381 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:07:45.464866 | controller | changed: "logs"
2025-10-13 06:07:45.709493 | controller | changed: "artifacts"
2025-10-13 06:07:45.973709 | controller | changed: "docs"
2025-10-13 06:07:46.014767 | 
2025-10-13 06:07:46.014878 | PLAY RECAP
2025-10-13 06:07:46.014918 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 06:07:46.014943 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:07:46.014961 | 
2025-10-13 06:07:46.134556 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:07:46.135455 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:07:46.674072 | 
2025-10-13 06:07:46.674242 | PLAY [localhost]
2025-10-13 06:07:46.690100 | 
2025-10-13 06:07:46.690168 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 06:07:47.066409 | localhost | ok
2025-10-13 06:07:47.076377 | 
2025-10-13 06:07:47.076457 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 06:07:47.670864 | localhost | changed
2025-10-13 06:07:47.693861 | 
2025-10-13 06:07:47.693926 | PLAY [all]
2025-10-13 06:07:47.708870 | 
2025-10-13 06:07:47.708929 | TASK [include_role : prepare-workspace]
2025-10-13 06:07:47.726862 | controller | ok
2025-10-13 06:07:47.741227 | 
2025-10-13 06:07:47.741293 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 06:07:48.161602 | controller | ok
2025-10-13 06:07:48.185166 | 
2025-10-13 06:07:48.185494 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 06:07:50.109081 | controller | Output suppressed because no_log was given
2025-10-13 06:07:50.118398 | 
2025-10-13 06:07:50.118462 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:07:50.402963 | controller | changed: "logs"
2025-10-13 06:07:50.672546 | controller | changed: "artifacts"
2025-10-13 06:07:50.933872 | controller | changed: "docs"
2025-10-13 06:07:50.952633 | 
2025-10-13 06:07:50.952859 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:07:51.224037 | controller | changed: "logs"
2025-10-13 06:07:51.224316 | controller | changed: All items complete
2025-10-13 06:07:51.224344 | 
2025-10-13 06:07:51.457544 | controller | changed: "artifacts"
2025-10-13 06:07:51.712848 | controller | changed: "docs"
2025-10-13 06:07:51.749451 | 
2025-10-13 06:07:51.749633 | TASK [Check if worker can sudo]
2025-10-13 06:07:52.304149 | controller | ok: Runtime: 0:00:00.067860
2025-10-13 06:07:52.312806 | 
2025-10-13 06:07:52.312890 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 06:07:52.368366 | controller | skipping: Conditional result was False
2025-10-13 06:07:52.376092 | 
2025-10-13 06:07:52.376174 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 06:07:52.442416 | controller | ok
2025-10-13 06:07:52.459896 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 06:07:52.473165 | 
2025-10-13 06:07:52.473266 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 06:07:52.807363 | controller | ok
2025-10-13 06:07:52.812851 | 
2025-10-13 06:07:52.812913 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 06:07:52.897807 | controller | ok: "/var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 06:07:52.912310 | 
2025-10-13 06:07:52.912458 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 06:07:53.943400 | controller | changed
2025-10-13 06:07:53.950885 | 
2025-10-13 06:07:53.951014 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 06:07:54.026372 | controller | ok: "/var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 06:07:54.026712 | controller | ok: All items complete
2025-10-13 06:07:54.026766 | 
2025-10-13 06:07:54.091808 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 06:07:54.098709 | 
2025-10-13 06:07:54.098779 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 06:07:55.134447 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 06:07:56.190608 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 06:07:56.210086 | 
2025-10-13 06:07:56.210229 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 06:07:56.707064 | controller | changed: section and option added
2025-10-13 06:07:56.745307 | 
2025-10-13 06:07:56.745440 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 06:07:57.669186 | controller | 29 files removed
2025-10-13 06:07:57.669562 | controller | ok: Item: dnf clean all Runtime: 0:00:00.546217
2025-10-13 06:07:57.669645 | controller | changed: All items complete
2025-10-13 06:07:57.669727 | 
2025-10-13 06:08:08.068460 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-10-13 06:08:08.068622 | controller | DNF version: 4.14.0
2025-10-13 06:08:08.068682 | controller | cachedir: /var/cache/dnf
2025-10-13 06:08:08.068761 | controller | Making cache files for all metadata files.
2025-10-13 06:08:08.068804 | controller | baseos: has expired and will be refreshed.
2025-10-13 06:08:08.068841 | controller | appstream: has expired and will be refreshed.
2025-10-13 06:08:08.068877 | controller | crb: has expired and will be refreshed.
2025-10-13 06:08:08.068928 | controller | extras-common: has expired and will be refreshed.
2025-10-13 06:08:08.068965 | controller | repo: downloading from remote: baseos
2025-10-13 06:08:08.069001 | controller | CentOS Stream 9 - BaseOS                         66 MB/s | 8.8 MB     00:00
2025-10-13 06:08:08.069037 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 06:08:08.069073 | controller | repo: downloading from remote: appstream
2025-10-13 06:08:08.069109 | controller | CentOS Stream 9 - AppStream                      94 MB/s |  25 MB     00:00
2025-10-13 06:08:08.069144 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 06:08:08.069178 | controller | repo: downloading from remote: crb
2025-10-13 06:08:08.069214 | controller | CentOS Stream 9 - CRB                            88 MB/s | 7.2 MB     00:00
2025-10-13 06:08:08.069249 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 06:08:08.069285 | controller | repo: downloading from remote: extras-common
2025-10-13 06:08:08.069320 | controller | CentOS Stream 9 - Extras packages               1.3 MB/s |  20 kB     00:00
2025-10-13 06:08:08.069356 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 06:08:08.069391 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 06:08:08.069426 | controller | Completion plugin: Generating completion cache...
2025-10-13 06:08:08.069461 | controller | Metadata cache created.
2025-10-13 06:08:08.069515 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.038729
2025-10-13 06:08:08.097666 | 
2025-10-13 06:08:08.097831 | PLAY RECAP
2025-10-13 06:08:08.097930 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 06:08:08.097989 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:08:08.098030 | 
2025-10-13 06:08:08.212594 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:08:08.214404 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:08:08.769808 | 
2025-10-13 06:08:08.769912 | PLAY [all]
2025-10-13 06:08:08.790993 | 
2025-10-13 06:08:08.791071 | TASK [Install binary dependencies]
2025-10-13 06:08:08.841330 | controller | ok
2025-10-13 06:08:08.861023 | 
2025-10-13 06:08:08.861134 | TASK [bindep : Include find tasks]
2025-10-13 06:08:08.890380 | controller | ok
2025-10-13 06:08:08.897630 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 06:08:08.912849 | 
2025-10-13 06:08:08.913013 | TASK [bindep : Look for bindep.txt]
2025-10-13 06:08:09.355832 | controller | ok
2025-10-13 06:08:09.369503 | 
2025-10-13 06:08:09.369649 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:08:09.421459 | controller | ok
2025-10-13 06:08:09.433250 | 
2025-10-13 06:08:09.433392 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 06:08:09.464935 | controller | skipping: Conditional result was False
2025-10-13 06:08:09.477670 | 
2025-10-13 06:08:09.477859 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:08:09.515486 | controller | skipping: Conditional result was False
2025-10-13 06:08:09.527540 | 
2025-10-13 06:08:09.527712 | TASK [bindep : Look for bindep fallback file]
2025-10-13 06:08:09.565002 | controller | skipping: Conditional result was False
2025-10-13 06:08:09.577376 | 
2025-10-13 06:08:09.577524 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:08:09.604100 | controller | skipping: Conditional result was False
2025-10-13 06:08:09.616404 | 
2025-10-13 06:08:09.616543 | TASK [bindep : Include bindep tasks]
2025-10-13 06:08:09.656795 | controller | ok
2025-10-13 06:08:09.670449 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 06:08:09.681276 | 
2025-10-13 06:08:09.681361 | TASK [bindep : Look for bindep command]
2025-10-13 06:08:09.706303 | controller | skipping: Conditional result was False
2025-10-13 06:08:09.721023 | 
2025-10-13 06:08:09.721480 | TASK [bindep : Check for system bindep]
2025-10-13 06:08:10.273668 | controller | ok: Runtime: 0:00:00.006452
2025-10-13 06:08:10.285395 | 
2025-10-13 06:08:10.285533 | TASK [bindep : Define bindep_command fact]
2025-10-13 06:08:10.323229 | controller | skipping: Conditional result was False
2025-10-13 06:08:10.335313 | 
2025-10-13 06:08:10.335458 | TASK [bindep : Include install tasks]
2025-10-13 06:08:10.372518 | controller | ok
2025-10-13 06:08:10.388616 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 06:08:10.409900 | 
2025-10-13 06:08:10.410106 | TASK [bindep : Create temp dir for bindep]
2025-10-13 06:08:10.827281 | controller | changed
2025-10-13 06:08:10.838986 | 
2025-10-13 06:08:10.839117 | TASK [Ensure we have pip dependencies]
2025-10-13 06:08:10.866891 | controller | ok
2025-10-13 06:08:10.906456 | 
2025-10-13 06:08:10.906550 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 02:08:11.220811 | controller | /usr/bin/pip3
2025-10-13 02:08:11.271380 | controller | /usr/bin/python3: No module named wheel
2025-10-13 06:08:11.441302 | controller | ok: Runtime: 0:00:00.063826
2025-10-13 06:08:11.454617 | 
2025-10-13 06:08:11.454796 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 06:08:11.503397 | controller | ok: "/var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 06:08:11.521761 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 06:08:11.544635 | 
2025-10-13 06:08:11.544805 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 06:08:14.023422 | controller | changed
2025-10-13 06:08:14.028809 | 
2025-10-13 06:08:14.028868 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 06:08:14.084550 | controller | skipping: Conditional result was False
2025-10-13 06:08:14.097721 | 
2025-10-13 06:08:14.097875 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 06:08:14.137866 | controller | skipping: Conditional result was False
2025-10-13 06:08:14.146329 | 
2025-10-13 06:08:14.146417 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 06:08:14.181188 | controller | skipping: Conditional result was False
2025-10-13 06:08:14.189851 | 
2025-10-13 06:08:14.189945 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 06:08:14.204490 | controller | skipping: Conditional result was False
2025-10-13 06:08:14.212525 | 
2025-10-13 06:08:14.212624 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 06:08:14.749761 | controller | skipping: Conditional result was False
2025-10-13 06:08:14.763083 | 
2025-10-13 06:08:14.763227 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 06:08:14.790065 | controller | skipping: Conditional result was False
2025-10-13 06:08:14.803332 | 
2025-10-13 06:08:14.803470 | TASK [ensure-pip : Install pip from source]
2025-10-13 06:08:14.830628 | controller | skipping: Conditional result was False
2025-10-13 06:08:14.843284 | 
2025-10-13 06:08:14.843425 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 02:08:15.108439 | controller | /usr/bin/python3
2025-10-13 06:08:15.389666 | controller | ok: Runtime: 0:00:00.008070
2025-10-13 06:08:15.404294 | 
2025-10-13 06:08:15.404440 | TASK [ensure-pip : Set host default]
2025-10-13 06:08:15.531425 | controller | ok
2025-10-13 06:08:15.538973 | 
2025-10-13 06:08:15.539046 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 06:08:15.592571 | controller | ok
2025-10-13 06:08:15.607307 | 
2025-10-13 06:08:15.607383 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 06:08:19.721910 | controller | changed
2025-10-13 06:08:19.728628 | 
2025-10-13 06:08:19.728786 | TASK [bindep : Define bindep_command]
2025-10-13 06:08:19.768732 | controller | ok
2025-10-13 06:08:19.774310 | 
2025-10-13 06:08:19.774372 | LOOP [bindep : Include package tasks]
2025-10-13 06:08:19.840109 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 06:08:19.840557 | controller | ok: All items complete
2025-10-13 06:08:19.840622 | 
2025-10-13 06:08:19.858827 | controller | included: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 06:08:19.870484 | 
2025-10-13 06:08:19.870543 | TASK [bindep : Define bindep_run fact]
2025-10-13 06:08:19.899817 | controller | ok
2025-10-13 06:08:19.904725 | 
2025-10-13 06:08:19.904786 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 02:08:21.441138 | controller | podman
2025-10-13 02:08:21.507104 | controller | python3-jmespath
2025-10-13 02:08:21.507174 | controller | python3-libvirt
2025-10-13 02:08:21.507283 | controller | python3-lxml
2025-10-13 02:08:21.507300 | controller | python3-netaddr
2025-10-13 06:08:21.938168 | controller | ok: Runtime: 0:00:01.302369
2025-10-13 06:08:21.943859 | 
2025-10-13 06:08:21.943923 | TASK [bindep : Install distro packages from bindep]
2025-10-13 06:09:23.640897 | controller | changed
2025-10-13 06:09:23.650815 | 
2025-10-13 06:09:23.650916 | TASK [bindep : Check that packages are installed]
2025-10-13 06:09:25.696061 | controller | ok: Runtime: 0:00:01.217478
2025-10-13 06:09:25.709623 | 
2025-10-13 06:09:25.709813 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 06:09:25.757320 | controller | skipping: Conditional result was False
2025-10-13 06:09:25.781449 | 
2025-10-13 06:09:25.781599 | TASK [Run test-setup role]
2025-10-13 06:09:25.804915 | controller | ok
2025-10-13 06:09:25.829515 | 
2025-10-13 06:09:25.829605 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 06:09:26.114079 | controller | ok
2025-10-13 06:09:26.121552 | 
2025-10-13 06:09:26.121639 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 06:09:26.662319 | controller | skipping: Conditional result was False
2025-10-13 06:09:26.692398 | 
2025-10-13 06:09:26.692523 | TASK [bindep : Remove bindep temp dir]
2025-10-13 06:09:27.095028 | controller | ok
2025-10-13 06:09:27.104804 | 
2025-10-13 06:09:27.104855 | PLAY RECAP
2025-10-13 06:09:27.104896 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 06:09:27.104915 | 
2025-10-13 06:09:27.211001 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:09:27.211888 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:09:27.734520 | 
2025-10-13 06:09:27.734624 | PLAY [all]
2025-10-13 06:09:27.754222 | 
2025-10-13 06:09:27.754299 | TASK [Abort when test_command variable is undefined]
2025-10-13 06:09:27.793453 | controller | skipping: Conditional result was False
2025-10-13 06:09:27.799020 | 
2025-10-13 06:09:27.799090 | TASK [Convert test_command to list]
2025-10-13 06:09:27.842702 | controller | skipping: Conditional result was False
2025-10-13 06:09:27.849077 | 
2025-10-13 06:09:27.849145 | TASK [Use test_command list]
2025-10-13 06:09:27.903819 | controller | ok
2025-10-13 06:09:27.914670 | 
2025-10-13 06:09:27.914804 | LOOP [Run test_command]
2025-10-13 06:09:28.347226 | controller | no check to run
2025-10-13 06:09:28.347756 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005008
2025-10-13 06:09:28.406408 | 
2025-10-13 06:09:28.406556 | PLAY RECAP
2025-10-13 06:09:28.406636 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:09:28.406720 | 
2025-10-13 06:09:28.511579 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:09:28.513336 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:09:29.072233 | 
2025-10-13 06:09:29.072343 | PLAY [all]
2025-10-13 06:09:29.092597 | 
2025-10-13 06:09:29.092700 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 06:09:29.507968 | controller | changed: non-zero return code
2025-10-13 06:09:29.513365 | 
2025-10-13 06:09:29.513438 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 06:09:29.537280 | controller | skipping: Conditional result was False
2025-10-13 06:09:29.543798 | 
2025-10-13 06:09:29.543866 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 06:09:29.574176 | 
2025-10-13 06:09:29.574300 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 06:09:29.603730 | 
2025-10-13 06:09:29.603853 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 06:09:29.617760 | controller | skipping: Conditional result was False
2025-10-13 06:09:29.624521 | 
2025-10-13 06:09:29.624589 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 06:09:29.655510 | 
2025-10-13 06:09:29.655640 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 06:09:29.679471 | controller | skipping: Conditional result was False
2025-10-13 06:09:29.685366 | 
2025-10-13 06:09:29.685431 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 06:09:29.709137 | controller | skipping: Conditional result was False
2025-10-13 06:09:29.714877 | 
2025-10-13 06:09:29.714963 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 06:09:29.728762 | controller | skipping: Conditional result was False
2025-10-13 06:09:29.754036 | 
2025-10-13 06:09:29.754096 | PLAY RECAP
2025-10-13 06:09:29.754139 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 06:09:29.754158 | 
2025-10-13 06:09:29.848182 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:09:29.849833 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:09:30.470513 | 
2025-10-13 06:09:30.470655 | PLAY [all]
2025-10-13 06:09:30.489204 | 
2025-10-13 06:09:30.489272 | TASK [include_role : fetch-output]
2025-10-13 06:09:30.528178 | controller | ok
2025-10-13 06:09:30.544844 | 
2025-10-13 06:09:30.544917 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 06:09:30.620837 | controller | skipping: Conditional result was False
2025-10-13 06:09:30.629080 | 
2025-10-13 06:09:30.629176 | TASK [fetch-output : Set log path for single node]
2025-10-13 06:09:30.689480 | controller | ok
2025-10-13 06:09:30.700612 | 
2025-10-13 06:09:30.700731 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 06:09:31.147171 | controller -> localhost | ok: "/var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/logs"
2025-10-13 06:09:31.406410 | controller -> localhost | changed: "/var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/artifacts"
2025-10-13 06:09:31.626962 | controller -> localhost | changed: "/var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/docs"
2025-10-13 06:09:31.644952 | 
2025-10-13 06:09:31.645083 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 06:09:32.363476 | controller | changed: .d..t...... ./
2025-10-13 06:09:32.363976 | controller | changed: All items complete
2025-10-13 06:09:32.364045 | 
2025-10-13 06:09:32.851272 | controller | changed: .d..t...... ./
2025-10-13 06:09:33.345269 | controller | changed: .d..t...... ./
2025-10-13 06:09:33.357872 | 
2025-10-13 06:09:33.357989 | TASK [include_role : fetch-output-openshift]
2025-10-13 06:09:33.372063 | controller | skipping: Conditional result was False
2025-10-13 06:09:33.377889 | 
2025-10-13 06:09:33.377952 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 06:09:33.755584 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012406
2025-10-13 06:09:33.975865 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015941
2025-10-13 06:09:34.014193 | 
2025-10-13 06:09:34.014306 | PLAY [all]
2025-10-13 06:09:34.032748 | 
2025-10-13 06:09:34.032811 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 06:09:34.511476 | controller | changed
2025-10-13 06:09:34.535722 | 
2025-10-13 06:09:34.535775 | PLAY RECAP
2025-10-13 06:09:34.535812 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:09:34.535832 | 
2025-10-13 06:09:34.623591 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:09:34.624444 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 06:09:35.209910 | 
2025-10-13 06:09:35.210025 | PLAY [localhost]
2025-10-13 06:09:35.227612 | 
2025-10-13 06:09:35.227704 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 06:09:35.591252 | localhost | changed
2025-10-13 06:09:35.608481 | 
2025-10-13 06:09:35.608598 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 06:09:35.638748 | localhost | ok
2025-10-13 06:09:35.649822 | 
2025-10-13 06:09:35.649916 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 06:09:35.996579 | localhost | changed
2025-10-13 06:09:36.001415 | 
2025-10-13 06:09:36.001484 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 06:09:36.668377 | localhost | changed
2025-10-13 06:09:36.673481 | 
2025-10-13 06:09:36.673546 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 06:09:37.076210 | localhost | Identity added: /var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/tmp/ansible.lfl6b52p (/var/lib/zuul/builds/e25ec455fd454e149a3494d7f7ddcc05/work/tmp/ansible.lfl6b52p)
2025-10-13 06:09:37.076385 | localhost | ok: Runtime: 0:00:00.014330
2025-10-13 06:09:37.080795 | 
2025-10-13 06:09:37.080862 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 06:09:37.357354 | localhost | ok: Runtime: 0:00:00.008374
2025-10-13 06:09:37.367975 | 
2025-10-13 06:09:37.368286 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 06:09:37.434524 | localhost | changed
2025-10-13 06:09:37.445434 | 
2025-10-13 06:09:37.445574 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 06:09:37.909460 | localhost | changed
2025-10-13 06:09:37.947743 | 
2025-10-13 06:09:37.947884 | PLAY [localhost]
2025-10-13 06:09:37.964013 | 
2025-10-13 06:09:37.964094 | TASK [Generate bulk log download script]
2025-10-13 06:09:37.994403 | localhost | ok
2025-10-13 06:09:38.005780 | 
2025-10-13 06:09:38.005844 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 06:09:38.033315 | localhost | ok: All assertions passed
2025-10-13 06:09:38.037734 | 
2025-10-13 06:09:38.037794 | TASK [local-log-download : Create download script]
2025-10-13 06:09:38.418406 | localhost -> localhost | changed
2025-10-13 06:09:38.432642 | 
2025-10-13 06:09:38.432737 | TASK [Register quick-download link]
2025-10-13 06:09:38.461252 | localhost | ok
2025-10-13 06:09:38.497776 | 
2025-10-13 06:09:38.497875 | PLAY [logserver.rdoproject.org]
2025-10-13 06:09:38.507561 | 
2025-10-13 06:09:38.507629 | TASK [Set zuul-log-path fact]
2025-10-13 06:09:38.523789 | logserver.rdoproject.org | ok
2025-10-13 06:09:38.532775 | 
2025-10-13 06:09:38.532841 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:09:38.558709 | logserver.rdoproject.org | ok
2025-10-13 06:09:38.564112 | 
2025-10-13 06:09:38.564174 | TASK [upload-logs : Create log directories]
2025-10-13 06:09:39.266744 | logserver.rdoproject.org | changed
2025-10-13 06:09:39.273353 | 
2025-10-13 06:09:39.273483 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 06:09:39.595748 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008072
2025-10-13 06:09:39.605389 | 
2025-10-13 06:09:39.605521 | TASK [upload-logs : Upload logs to log server]
2025-10-13 06:09:40.381006 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 06:09:40.387391 | 
2025-10-13 06:09:40.387559 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 06:09:40.456925 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:40.467983 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:40.472830 | 
2025-10-13 06:09:40.472971 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 06:09:40.518090 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:40.518526 | 
2025-10-13 06:09:40.521190 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:40.535116 | 
2025-10-13 06:09:40.535274 | LOOP [upload-logs : Upload console log and json output]