2025-10-03 10:00:09.570059 | Job console starting...
2025-10-03 10:00:09.581143 | Updating repositories
2025-10-03 10:00:09.618381 | Preparing job workspace
2025-10-03 10:00:13.358698 | Running Ansible setup...
2025-10-03 10:00:18.766608 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 10:00:19.367095 | 
2025-10-03 10:00:19.367222 | PLAY [localhost]
2025-10-03 10:00:19.376503 | 
2025-10-03 10:00:19.376616 | TASK [Gathering Facts]
2025-10-03 10:00:20.430695 | localhost | ok
2025-10-03 10:00:20.459904 | 
2025-10-03 10:00:20.460060 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 10:00:21.067272 | localhost -> localhost | changed
2025-10-03 10:00:21.072840 | 
2025-10-03 10:00:21.072947 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 10:00:22.017328 | localhost -> localhost | changed
2025-10-03 10:00:22.027141 | 
2025-10-03 10:00:22.027252 | TASK [Setup log path fact]
2025-10-03 10:00:22.044581 | localhost | ok
2025-10-03 10:00:22.067976 | 
2025-10-03 10:00:22.068096 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 10:00:22.117383 | localhost | ok
2025-10-03 10:00:22.135887 | 
2025-10-03 10:00:22.136026 | TASK [emit-job-header : Print job information]
2025-10-03 10:00:22.187832 | # Job Information
2025-10-03 10:00:22.188005 | Ansible Version: 2.15.12
2025-10-03 10:00:22.188034 | Job: cifmw-molecule-recognize_ssh_keypair
2025-10-03 10:00:22.188055 | Pipeline: github-check
2025-10-03 10:00:22.188074 | Executor: ze03.softwarefactory-project.io
2025-10-03 10:00:22.188092 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-03 10:00:22.188111 | Log URL (when completed): https://logserver.rdoproject.org/910/rdoproject.org/910f8aa313cc4e47ac37e3956c9f781f/
2025-10-03 10:00:22.188130 | Event ID: 79314020-a03f-11f0-87f2-6df8ed647fba
2025-10-03 10:00:22.191993 | 
2025-10-03 10:00:22.192075 | LOOP [emit-job-header : Print node information]
2025-10-03 10:00:22.356433 | localhost | ok:
2025-10-03 10:00:22.356647 | localhost | # Node Information
2025-10-03 10:00:22.356675 | localhost | Inventory Hostname: controller
2025-10-03 10:00:22.356701 | localhost | Hostname: np0005468532
2025-10-03 10:00:22.356722 | localhost | Username: zuul
2025-10-03 10:00:22.356765 | localhost | Distro: CentOS 9
2025-10-03 10:00:22.356784 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-03 10:00:22.356802 | localhost | Region: RegionOne
2025-10-03 10:00:22.356818 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-03 10:00:22.356835 | localhost | Product Name: OpenStack Nova
2025-10-03 10:00:22.356857 | localhost | Interface IP: 38.102.83.22
2025-10-03 10:00:22.390248 | 
2025-10-03 10:00:22.390341 | PLAY [all]
2025-10-03 10:00:22.403558 | 
2025-10-03 10:00:22.403640 | TASK [Gather network facts]
2025-10-03 10:00:22.886538 | controller | ok
2025-10-03 10:00:22.913159 | 
2025-10-03 10:00:22.913272 | TASK [include_role : start-zuul-console]
2025-10-03 10:00:22.934404 | controller | ok
2025-10-03 10:00:22.949893 | 
2025-10-03 10:00:22.950014 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 10:00:23.397646 | controller | ok
2025-10-03 10:00:23.408151 | 
2025-10-03 10:00:23.408273 | TASK [include_role : add-build-sshkey]
2025-10-03 10:00:23.438075 | controller | ok
2025-10-03 10:00:23.456249 | 
2025-10-03 10:00:23.456357 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 10:00:23.708299 | controller -> localhost | ok
2025-10-03 10:00:23.721583 | 
2025-10-03 10:00:23.721695 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 10:00:23.761646 | controller | ok
2025-10-03 10:00:23.776146 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 10:00:23.783607 | 
2025-10-03 10:00:23.783708 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 10:00:24.525437 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 10:00:24.525702 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/910f8aa313cc4e47ac37e3956c9f781f_id_rsa.
2025-10-03 10:00:24.525781 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/910f8aa313cc4e47ac37e3956c9f781f_id_rsa.pub.
2025-10-03 10:00:24.525821 | controller -> localhost | The key fingerprint is:
2025-10-03 10:00:24.525856 | controller -> localhost | SHA256:Dowb7yq37yVRZunX6ciIILTQOdYtue37tDEqCrREFeo zuul-build-sshkey
2025-10-03 10:00:24.525891 | controller -> localhost | The key's randomart image is:
2025-10-03 10:00:24.525927 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 10:00:24.525962 | controller -> localhost | |   o.            |
2025-10-03 10:00:24.525998 | controller -> localhost | | .oo o   .       |
2025-10-03 10:00:24.526030 | controller -> localhost | |.o* + . =        |
2025-10-03 10:00:24.526061 | controller -> localhost | |o+ o * =   . .   |
2025-10-03 10:00:24.526094 | controller -> localhost | | Eo = = S . o    |
2025-10-03 10:00:24.526127 | controller -> localhost | |o .. * = + o     |
2025-10-03 10:00:24.526157 | controller -> localhost | |..  . = B o .    |
2025-10-03 10:00:24.526191 | controller -> localhost | | .. o. * +       |
2025-10-03 10:00:24.526223 | controller -> localhost | |  .+o**.o        |
2025-10-03 10:00:24.526254 | controller -> localhost | +----[SHA256]-----+
2025-10-03 10:00:24.526319 | controller -> localhost | ok: Runtime: 0:00:00.285522
2025-10-03 10:00:24.535852 | 
2025-10-03 10:00:24.535994 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 10:00:24.560438 | controller | ok
2025-10-03 10:00:24.576294 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 10:00:24.592203 | 
2025-10-03 10:00:24.592368 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 10:00:24.615744 | controller | skipping: Conditional result was False
2025-10-03 10:00:24.652014 | 
2025-10-03 10:00:24.652140 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 10:00:25.141220 | controller | changed
2025-10-03 10:00:25.146136 | 
2025-10-03 10:00:25.146199 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 10:00:25.400792 | controller | ok
2025-10-03 10:00:25.407244 | 
2025-10-03 10:00:25.407314 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 10:00:26.294501 | controller | changed
2025-10-03 10:00:26.303034 | 
2025-10-03 10:00:26.303160 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 10:00:27.077506 | controller | changed
2025-10-03 10:00:27.085053 | 
2025-10-03 10:00:27.085183 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 10:00:27.111424 | controller | skipping: Conditional result was False
2025-10-03 10:00:27.123156 | 
2025-10-03 10:00:27.123279 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 10:00:27.633570 | controller -> localhost | changed
2025-10-03 10:00:27.644915 | 
2025-10-03 10:00:27.645013 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 10:00:27.923601 | controller -> localhost | Identity added: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/910f8aa313cc4e47ac37e3956c9f781f_id_rsa (zuul-build-sshkey)
2025-10-03 10:00:27.923829 | controller -> localhost | ok: Runtime: 0:00:00.009404
2025-10-03 10:00:27.938029 | 
2025-10-03 10:00:27.938134 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 10:00:28.302888 | controller | ok
2025-10-03 10:00:28.308049 | 
2025-10-03 10:00:28.308312 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 10:00:28.332777 | controller | skipping: Conditional result was False
2025-10-03 10:00:28.343292 | 
2025-10-03 10:00:28.343403 | TASK [include_role : validate-host]
2025-10-03 10:00:28.383478 | controller | ok
2025-10-03 10:00:28.414898 | 
2025-10-03 10:00:28.415036 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 10:00:28.467931 | controller | ok
2025-10-03 10:00:28.473565 | 
2025-10-03 10:00:28.473657 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 10:00:28.890867 | controller -> localhost | ok
2025-10-03 10:00:28.902814 | 
2025-10-03 10:00:28.902978 | TASK [validate-host : Collect information about the host]
2025-10-03 10:00:29.799572 | controller | ok
2025-10-03 10:00:29.818191 | 
2025-10-03 10:00:29.818333 | TASK [validate-host : Sanitize hostname]
2025-10-03 10:00:29.884464 | controller | ok
2025-10-03 10:00:29.893922 | 
2025-10-03 10:00:29.894034 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 10:00:30.703041 | controller -> localhost | changed
2025-10-03 10:00:30.709361 | 
2025-10-03 10:00:30.709433 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 10:00:31.185482 | controller | ok
2025-10-03 10:00:31.195479 | 
2025-10-03 10:00:31.195588 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 10:00:31.921663 | controller -> localhost | changed
2025-10-03 10:00:31.934608 | 
2025-10-03 10:00:31.934781 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 10:00:31.949960 | controller | skipping: Conditional result was False
2025-10-03 10:00:31.956986 | 
2025-10-03 10:00:31.957079 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 10:00:31.984320 | controller | skipping: Conditional result was False
2025-10-03 10:00:31.989703 | 
2025-10-03 10:00:31.989828 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 10:00:32.230710 | controller | ok: "logs"
2025-10-03 10:00:32.230974 | controller | ok: All items complete
2025-10-03 10:00:32.231005 | 
2025-10-03 10:00:32.456489 | controller | ok: "artifacts"
2025-10-03 10:00:32.665371 | controller | ok: "docs"
2025-10-03 10:00:32.672638 | 
2025-10-03 10:00:32.672783 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 10:00:32.971946 | controller | changed: "logs"
2025-10-03 10:00:33.195954 | controller | changed: "artifacts"
2025-10-03 10:00:33.418001 | controller | changed: "docs"
2025-10-03 10:00:33.476256 | 
2025-10-03 10:00:33.476412 | PLAY RECAP
2025-10-03 10:00:33.476471 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 10:00:33.476507 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 10:00:33.476532 | 
2025-10-03 10:00:33.634452 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 10:00:33.635411 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 10:00:34.296661 | 
2025-10-03 10:00:34.296889 | PLAY [localhost]
2025-10-03 10:00:34.332748 | 
2025-10-03 10:00:34.332882 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-03 10:00:34.776884 | localhost | ok
2025-10-03 10:00:34.784842 | 
2025-10-03 10:00:34.785189 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-03 10:00:35.505109 | localhost | changed
2025-10-03 10:00:35.527631 | 
2025-10-03 10:00:35.527767 | PLAY [all]
2025-10-03 10:00:35.546159 | 
2025-10-03 10:00:35.546317 | TASK [include_role : prepare-workspace]
2025-10-03 10:00:35.567446 | controller | ok
2025-10-03 10:00:35.582520 | 
2025-10-03 10:00:35.582638 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 10:00:36.004703 | controller | ok
2025-10-03 10:00:36.017092 | 
2025-10-03 10:00:36.017203 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 10:00:38.026950 | controller | Output suppressed because no_log was given
2025-10-03 10:00:38.038164 | 
2025-10-03 10:00:38.038253 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 10:00:38.391544 | controller | changed: "logs"
2025-10-03 10:00:38.612974 | controller | changed: "artifacts"
2025-10-03 10:00:38.823924 | controller | changed: "docs"
2025-10-03 10:00:38.832908 | 
2025-10-03 10:00:38.833038 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 10:00:39.098523 | controller | changed: "logs"
2025-10-03 10:00:39.098786 | controller | changed: All items complete
2025-10-03 10:00:39.098822 | 
2025-10-03 10:00:39.309793 | controller | changed: "artifacts"
2025-10-03 10:00:39.533364 | controller | changed: "docs"
2025-10-03 10:00:39.557621 | 
2025-10-03 10:00:39.557766 | TASK [Check if worker can sudo]
2025-10-03 10:00:40.101625 | controller | ok: Runtime: 0:00:00.051727
2025-10-03 10:00:40.108184 | 
2025-10-03 10:00:40.108293 | TASK [configure-mirrors : Gather needed facts]
2025-10-03 10:00:40.165679 | controller | skipping: Conditional result was False
2025-10-03 10:00:40.171647 | 
2025-10-03 10:00:40.171744 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-03 10:00:40.246719 | controller | ok
2025-10-03 10:00:40.255245 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-03 10:00:40.262200 | 
2025-10-03 10:00:40.262310 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-03 10:00:40.579882 | controller | ok
2025-10-03 10:00:40.585990 | 
2025-10-03 10:00:40.586110 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-03 10:00:40.650559 | controller | ok: "/var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-03 10:00:40.668341 | 
2025-10-03 10:00:40.668461 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-03 10:00:41.468101 | controller | changed
2025-10-03 10:00:41.476860 | 
2025-10-03 10:00:41.477004 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-03 10:00:41.542839 | controller | ok: "/var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-03 10:00:41.543007 | controller | ok: All items complete
2025-10-03 10:00:41.543035 | 
2025-10-03 10:00:41.606692 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-03 10:00:41.614007 | 
2025-10-03 10:00:41.614085 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-03 10:00:42.493837 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-03 10:00:43.212953 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-03 10:00:43.233018 | 
2025-10-03 10:00:43.233167 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-03 10:00:43.712316 | controller | changed: section and option added
2025-10-03 10:00:43.748408 | 
2025-10-03 10:00:43.748535 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-03 10:00:44.567956 | controller | 29 files removed
2025-10-03 10:00:44.568162 | controller | ok: Item: dnf clean all Runtime: 0:00:00.506625
2025-10-03 10:00:44.568204 | controller | changed: All items complete
2025-10-03 10:00:44.568226 | 
2025-10-03 10:00:55.462068 | 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-03 10:00:55.462184 | controller | DNF version: 4.14.0
2025-10-03 10:00:55.462219 | controller | cachedir: /var/cache/dnf
2025-10-03 10:00:55.462248 | controller | Making cache files for all metadata files.
2025-10-03 10:00:55.462275 | controller | baseos: has expired and will be refreshed.
2025-10-03 10:00:55.462301 | controller | appstream: has expired and will be refreshed.
2025-10-03 10:00:55.462328 | controller | crb: has expired and will be refreshed.
2025-10-03 10:00:55.462365 | controller | extras-common: has expired and will be refreshed.
2025-10-03 10:00:55.462392 | controller | repo: downloading from remote: baseos
2025-10-03 10:00:55.462420 | controller | CentOS Stream 9 - BaseOS                         82 MB/s | 8.8 MB     00:00
2025-10-03 10:00:55.462448 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-03 10:00:55.462468 | controller | repo: downloading from remote: appstream
2025-10-03 10:00:55.462487 | controller | CentOS Stream 9 - AppStream                     120 MB/s |  25 MB     00:00
2025-10-03 10:00:55.462505 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-03 10:00:55.462523 | controller | repo: downloading from remote: crb
2025-10-03 10:00:55.462541 | controller | CentOS Stream 9 - CRB                            71 MB/s | 7.1 MB     00:00
2025-10-03 10:00:55.462559 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-03 10:00:55.462576 | controller | repo: downloading from remote: extras-common
2025-10-03 10:00:55.462593 | controller | CentOS Stream 9 - Extras packages               1.5 MB/s |  20 kB     00:00
2025-10-03 10:00:55.462611 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-03 10:00:55.462627 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-03 10:00:55.462645 | controller | Completion plugin: Generating completion cache...
2025-10-03 10:00:55.462661 | controller | Metadata cache created.
2025-10-03 10:00:55.462688 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.629814
2025-10-03 10:00:55.492464 | 
2025-10-03 10:00:55.492634 | PLAY RECAP
2025-10-03 10:00:55.492823 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 10:00:55.492922 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 10:00:55.492981 | 
2025-10-03 10:00:57.489919 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 10:00:57.490790 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 10:00:58.079230 | 
2025-10-03 10:00:58.079348 | PLAY [all]
2025-10-03 10:00:58.100817 | 
2025-10-03 10:00:58.100951 | TASK [Install binary dependencies]
2025-10-03 10:00:58.161190 | controller | ok
2025-10-03 10:00:58.183257 | 
2025-10-03 10:00:58.183398 | TASK [bindep : Include find tasks]
2025-10-03 10:00:58.212192 | controller | ok
2025-10-03 10:00:58.220311 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-03 10:00:58.226529 | 
2025-10-03 10:00:58.226598 | TASK [bindep : Look for bindep.txt]
2025-10-03 10:00:58.675822 | controller | ok
2025-10-03 10:00:58.682422 | 
2025-10-03 10:00:58.682491 | TASK [bindep : Define bindep_file fact]
2025-10-03 10:00:58.711926 | controller | ok
2025-10-03 10:00:58.717371 | 
2025-10-03 10:00:58.717446 | TASK [bindep : Look for other-requirements.txt]
2025-10-03 10:00:58.744324 | controller | skipping: Conditional result was False
2025-10-03 10:00:58.749914 | 
2025-10-03 10:00:58.749983 | TASK [bindep : Define bindep_file fact]
2025-10-03 10:00:58.783898 | controller | skipping: Conditional result was False
2025-10-03 10:00:58.789524 | 
2025-10-03 10:00:58.789592 | TASK [bindep : Look for bindep fallback file]
2025-10-03 10:00:58.813537 | controller | skipping: Conditional result was False
2025-10-03 10:00:58.819703 | 
2025-10-03 10:00:58.819789 | TASK [bindep : Define bindep_file fact]
2025-10-03 10:00:58.844030 | controller | skipping: Conditional result was False
2025-10-03 10:00:58.851313 | 
2025-10-03 10:00:58.851439 | TASK [bindep : Include bindep tasks]
2025-10-03 10:00:58.885190 | controller | ok
2025-10-03 10:00:58.895146 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-03 10:00:58.903823 | 
2025-10-03 10:00:58.903929 | TASK [bindep : Look for bindep command]
2025-10-03 10:00:58.928205 | controller | skipping: Conditional result was False
2025-10-03 10:00:58.935515 | 
2025-10-03 10:00:58.935603 | TASK [bindep : Check for system bindep]
2025-10-03 10:00:59.468694 | controller | ok: Runtime: 0:00:00.004247
2025-10-03 10:00:59.477062 | 
2025-10-03 10:00:59.477198 | TASK [bindep : Define bindep_command fact]
2025-10-03 10:00:59.504903 | controller | skipping: Conditional result was False
2025-10-03 10:00:59.522271 | 
2025-10-03 10:00:59.522447 | TASK [bindep : Include install tasks]
2025-10-03 10:00:59.556246 | controller | ok
2025-10-03 10:00:59.568446 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-03 10:00:59.583295 | 
2025-10-03 10:00:59.583446 | TASK [bindep : Create temp dir for bindep]
2025-10-03 10:00:59.978391 | controller | changed
2025-10-03 10:00:59.988375 | 
2025-10-03 10:00:59.988539 | TASK [Ensure we have pip dependencies]
2025-10-03 10:01:00.012517 | controller | ok
2025-10-03 10:01:00.052323 | 
2025-10-03 10:01:00.052450 | TASK [ensure-pip : Check if pip is installed]
2025-10-03 06:01:00.339896 | controller | /usr/bin/pip3
2025-10-03 06:01:00.370314 | controller | /usr/bin/python3: No module named wheel
2025-10-03 10:01:00.586985 | controller | ok: Runtime: 0:00:00.042098
2025-10-03 10:01:00.594108 | 
2025-10-03 10:01:00.594218 | LOOP [ensure-pip : Install pip from packages]
2025-10-03 10:01:00.647558 | controller | ok: "/var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-03 10:01:00.657458 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-03 10:01:00.669585 | 
2025-10-03 10:01:00.669707 | TASK [ensure-pip : Install Python 3 pip]
2025-10-03 10:01:03.123872 | controller | changed
2025-10-03 10:01:03.134169 | 
2025-10-03 10:01:03.134336 | TASK [ensure-pip : Check for EPEL repository]
2025-10-03 10:01:03.203208 | controller | skipping: Conditional result was False
2025-10-03 10:01:03.213419 | 
2025-10-03 10:01:03.213555 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-03 10:01:03.269583 | controller | skipping: Conditional result was False
2025-10-03 10:01:03.279508 | 
2025-10-03 10:01:03.279666 | TASK [ensure-pip : Install Python 2 pip]
2025-10-03 10:01:03.336331 | controller | skipping: Conditional result was False
2025-10-03 10:01:03.346792 | 
2025-10-03 10:01:03.346930 | TASK [ensure-pip : Ensure setuptools]
2025-10-03 10:01:03.362087 | controller | skipping: Conditional result was False
2025-10-03 10:01:03.371757 | 
2025-10-03 10:01:03.371870 | TASK [ensure-pip : Check for ensurepip module]
2025-10-03 10:01:03.914305 | controller | skipping: Conditional result was False
2025-10-03 10:01:03.928356 | 
2025-10-03 10:01:03.928516 | TASK [ensure-pip : Ensure python3-venv]
2025-10-03 10:01:03.956292 | controller | skipping: Conditional result was False
2025-10-03 10:01:03.969601 | 
2025-10-03 10:01:03.969785 | TASK [ensure-pip : Install pip from source]
2025-10-03 10:01:03.997245 | controller | skipping: Conditional result was False
2025-10-03 10:01:04.011842 | 
2025-10-03 10:01:04.012068 | TASK [ensure-pip : Probe for venv python full path]
2025-10-03 06:01:04.306487 | controller | /usr/bin/python3
2025-10-03 10:01:04.562428 | controller | ok: Runtime: 0:00:00.006701
2025-10-03 10:01:04.568434 | 
2025-10-03 10:01:04.568509 | TASK [ensure-pip : Set host default]
2025-10-03 10:01:04.607912 | controller | ok
2025-10-03 10:01:04.613848 | 
2025-10-03 10:01:04.613946 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-03 10:01:04.665686 | controller | ok
2025-10-03 10:01:04.678877 | 
2025-10-03 10:01:04.678981 | TASK [bindep : Install bindep into temporary venv]
2025-10-03 10:01:09.050043 | controller | changed
2025-10-03 10:01:09.063240 | 
2025-10-03 10:01:09.063384 | TASK [bindep : Define bindep_command]
2025-10-03 10:01:09.113261 | controller | ok
2025-10-03 10:01:09.122374 | 
2025-10-03 10:01:09.122478 | LOOP [bindep : Include package tasks]
2025-10-03 10:01:09.174992 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-03 10:01:09.175295 | controller | ok: All items complete
2025-10-03 10:01:09.175337 | 
2025-10-03 10:01:09.189895 | controller | included: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-03 10:01:09.203051 | 
2025-10-03 10:01:09.203163 | TASK [bindep : Define bindep_run fact]
2025-10-03 10:01:09.233944 | controller | ok
2025-10-03 10:01:09.239673 | 
2025-10-03 10:01:09.239762 | TASK [bindep : Get list of packages to install from bindep]
2025-10-03 06:01:10.604583 | controller | podman
2025-10-03 06:01:10.633831 | controller | python3-jmespath
2025-10-03 06:01:10.633996 | controller | python3-libvirt
2025-10-03 06:01:10.634006 | controller | python3-lxml
2025-10-03 06:01:10.634016 | controller | python3-netaddr
2025-10-03 10:01:10.776971 | controller | ok: Runtime: 0:00:01.132833
2025-10-03 10:01:10.786169 | 
2025-10-03 10:01:10.786304 | TASK [bindep : Install distro packages from bindep]
2025-10-03 10:02:19.855096 | controller | changed
2025-10-03 10:02:19.860553 | 
2025-10-03 10:02:19.860620 | TASK [bindep : Check that packages are installed]
2025-10-03 10:02:21.391816 | controller | ok: Runtime: 0:00:01.214236
2025-10-03 10:02:21.407189 | 
2025-10-03 10:02:21.407364 | TASK [bindep : Fail if we cannot install all packages]
2025-10-03 10:02:21.446990 | controller | skipping: Conditional result was False
2025-10-03 10:02:21.473458 | 
2025-10-03 10:02:21.473638 | TASK [Run test-setup role]
2025-10-03 10:02:21.500510 | controller | ok
2025-10-03 10:02:21.531231 | 
2025-10-03 10:02:21.531376 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-03 10:02:21.777688 | controller | ok
2025-10-03 10:02:21.799472 | 
2025-10-03 10:02:21.799673 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-03 10:02:22.346383 | controller | skipping: Conditional result was False
2025-10-03 10:02:22.403924 | 
2025-10-03 10:02:22.404091 | TASK [bindep : Remove bindep temp dir]
2025-10-03 10:02:22.810146 | controller | ok
2025-10-03 10:02:22.827366 | 
2025-10-03 10:02:22.827481 | PLAY RECAP
2025-10-03 10:02:22.827538 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-03 10:02:22.827569 | 
2025-10-03 10:02:22.964070 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 10:02:22.965355 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 10:02:23.548334 | 
2025-10-03 10:02:23.548457 | PLAY [all]
2025-10-03 10:02:23.569211 | 
2025-10-03 10:02:23.569318 | TASK [Abort when test_command variable is undefined]
2025-10-03 10:02:23.593993 | controller | skipping: Conditional result was False
2025-10-03 10:02:23.599755 | 
2025-10-03 10:02:23.599847 | TASK [Convert test_command to list]
2025-10-03 10:02:23.644214 | controller | skipping: Conditional result was False
2025-10-03 10:02:23.650855 | 
2025-10-03 10:02:23.650940 | TASK [Use test_command list]
2025-10-03 10:02:23.720480 | controller | ok
2025-10-03 10:02:23.726199 | 
2025-10-03 10:02:23.726298 | LOOP [Run test_command]
2025-10-03 10:02:24.132833 | controller | no check to run
2025-10-03 10:02:24.133170 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006497
2025-10-03 10:02:24.183312 | 
2025-10-03 10:02:24.183442 | PLAY RECAP
2025-10-03 10:02:24.183526 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 10:02:24.183570 | 
2025-10-03 10:02:24.300895 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 10:02:24.301819 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 10:02:24.970587 | 
2025-10-03 10:02:24.970718 | PLAY [all]
2025-10-03 10:02:24.992358 | 
2025-10-03 10:02:24.992481 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-03 10:02:25.358903 | controller | changed: non-zero return code
2025-10-03 10:02:25.364640 | 
2025-10-03 10:02:25.364756 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-03 10:02:25.379547 | controller | skipping: Conditional result was False
2025-10-03 10:02:25.385625 | 
2025-10-03 10:02:25.385710 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-03 10:02:25.406556 | 
2025-10-03 10:02:25.406742 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-03 10:02:25.430426 | 
2025-10-03 10:02:25.430663 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-03 10:02:25.446020 | controller | skipping: Conditional result was False
2025-10-03 10:02:25.455915 | 
2025-10-03 10:02:25.456022 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-03 10:02:25.479470 | 
2025-10-03 10:02:25.479860 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-03 10:02:25.505368 | controller | skipping: Conditional result was False
2025-10-03 10:02:25.514028 | 
2025-10-03 10:02:25.514169 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-03 10:02:25.529212 | controller | skipping: Conditional result was False
2025-10-03 10:02:25.536475 | 
2025-10-03 10:02:25.536598 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-03 10:02:25.551373 | controller | skipping: Conditional result was False
2025-10-03 10:02:25.580131 | 
2025-10-03 10:02:25.580245 | PLAY RECAP
2025-10-03 10:02:25.580339 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-03 10:02:25.580366 | 
2025-10-03 10:02:25.718501 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 10:02:25.720262 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 10:02:26.312436 | 
2025-10-03 10:02:26.312578 | PLAY [all]
2025-10-03 10:02:26.332460 | 
2025-10-03 10:02:26.332569 | TASK [include_role : fetch-output]
2025-10-03 10:02:26.361984 | controller | ok
2025-10-03 10:02:26.380035 | 
2025-10-03 10:02:26.380136 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 10:02:26.455493 | controller | skipping: Conditional result was False
2025-10-03 10:02:26.471082 | 
2025-10-03 10:02:26.471259 | TASK [fetch-output : Set log path for single node]
2025-10-03 10:02:26.523055 | controller | ok
2025-10-03 10:02:26.538439 | 
2025-10-03 10:02:26.538618 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 10:02:26.991596 | controller -> localhost | ok: "/var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/logs"
2025-10-03 10:02:27.221218 | controller -> localhost | changed: "/var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/artifacts"
2025-10-03 10:02:27.544666 | controller -> localhost | changed: "/var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/docs"
2025-10-03 10:02:27.561545 | 
2025-10-03 10:02:27.561653 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 10:02:28.278857 | controller | changed: .d..t...... ./
2025-10-03 10:02:28.279427 | controller | changed: All items complete
2025-10-03 10:02:28.279505 | 
2025-10-03 10:02:28.809303 | controller | changed: .d..t...... ./
2025-10-03 10:02:29.298211 | controller | changed: .d..t...... ./
2025-10-03 10:02:29.318901 | 
2025-10-03 10:02:29.319048 | TASK [include_role : fetch-output-openshift]
2025-10-03 10:02:29.333054 | controller | skipping: Conditional result was False
2025-10-03 10:02:29.342750 | 
2025-10-03 10:02:29.342853 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 10:02:29.803192 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013109
2025-10-03 10:02:30.061837 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006996
2025-10-03 10:02:30.089710 | 
2025-10-03 10:02:30.089840 | PLAY [all]
2025-10-03 10:02:30.105919 | 
2025-10-03 10:02:30.106008 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 10:02:30.570476 | controller | changed
2025-10-03 10:02:30.619440 | 
2025-10-03 10:02:30.619553 | PLAY RECAP
2025-10-03 10:02:30.619650 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 10:02:30.619681 | 
2025-10-03 10:02:30.743933 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 10:02:30.746842 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 10:02:31.449448 | 
2025-10-03 10:02:31.449673 | PLAY [localhost]
2025-10-03 10:02:31.477992 | 
2025-10-03 10:02:31.478167 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 10:02:31.948734 | localhost | changed
2025-10-03 10:02:31.956215 | 
2025-10-03 10:02:31.956338 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 10:02:31.987545 | localhost | ok
2025-10-03 10:02:31.999985 | 
2025-10-03 10:02:32.000106 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 10:02:32.388010 | localhost | changed
2025-10-03 10:02:32.395137 | 
2025-10-03 10:02:32.395271 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 10:02:33.074365 | localhost | changed
2025-10-03 10:02:33.079849 | 
2025-10-03 10:02:33.080188 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 10:02:33.566231 | localhost | Identity added: /var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/tmp/ansible.zjvvsr6j (/var/lib/zuul/builds/910f8aa313cc4e47ac37e3956c9f781f/work/tmp/ansible.zjvvsr6j)
2025-10-03 10:02:33.566599 | localhost | ok: Runtime: 0:00:00.010474
2025-10-03 10:02:33.576908 | 
2025-10-03 10:02:33.577151 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 10:02:33.893831 | localhost | ok: Runtime: 0:00:00.008704
2025-10-03 10:02:33.906036 | 
2025-10-03 10:02:33.906226 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 10:02:33.976822 | localhost | changed
2025-10-03 10:02:33.987695 | 
2025-10-03 10:02:33.987949 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 10:02:34.431197 | localhost | changed
2025-10-03 10:02:34.455680 | 
2025-10-03 10:02:34.455946 | PLAY [localhost]
2025-10-03 10:02:34.474503 | 
2025-10-03 10:02:34.474784 | TASK [Generate bulk log download script]
2025-10-03 10:02:34.494698 | localhost | ok
2025-10-03 10:02:34.507836 | 
2025-10-03 10:02:34.507959 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 10:02:34.546507 | localhost | ok: All assertions passed
2025-10-03 10:02:34.551473 | 
2025-10-03 10:02:34.551572 | TASK [local-log-download : Create download script]
2025-10-03 10:02:34.983459 | localhost -> localhost | changed
2025-10-03 10:02:34.992478 | 
2025-10-03 10:02:34.992555 | TASK [Register quick-download link]
2025-10-03 10:02:35.011256 | localhost | ok
2025-10-03 10:02:35.050685 | 
2025-10-03 10:02:35.050806 | PLAY [logserver.rdoproject.org]
2025-10-03 10:02:35.060925 | 
2025-10-03 10:02:35.061004 | TASK [Set zuul-log-path fact]
2025-10-03 10:02:35.077222 | logserver.rdoproject.org | ok
2025-10-03 10:02:35.087625 | 
2025-10-03 10:02:35.087807 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 10:02:35.115082 | logserver.rdoproject.org | ok
2025-10-03 10:02:35.120671 | 
2025-10-03 10:02:35.120798 | TASK [upload-logs : Create log directories]
2025-10-03 10:02:35.741658 | logserver.rdoproject.org | changed
2025-10-03 10:02:35.745453 | 
2025-10-03 10:02:35.745568 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 10:02:36.004861 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006061
2025-10-03 10:02:36.010065 | 
2025-10-03 10:02:36.010134 | TASK [upload-logs : Upload logs to log server]
2025-10-03 10:02:36.652452 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 10:02:36.659426 | 
2025-10-03 10:02:36.659578 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 10:02:36.705500 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:02:36.729877 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:02:36.746283 | 
2025-10-03 10:02:36.746465 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 10:02:36.798715 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:02:36.799168 | 
2025-10-03 10:02:36.807015 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:02:36.822655 | 
2025-10-03 10:02:36.822920 | LOOP [upload-logs : Upload console log and json output]