2025-10-13 11:50:09.985464 | Job console starting...
2025-10-13 11:50:09.998182 | Updating repositories
2025-10-13 11:50:10.029916 | Preparing job workspace
2025-10-13 11:50:13.904976 | Running Ansible setup...
2025-10-13 11:50:18.773871 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 11:50:19.317405 | 
2025-10-13 11:50:19.317556 | PLAY [localhost]
2025-10-13 11:50:19.326339 | 
2025-10-13 11:50:19.326420 | TASK [Gathering Facts]
2025-10-13 11:50:20.317450 | localhost | ok
2025-10-13 11:50:20.339823 | 
2025-10-13 11:50:20.339916 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 11:50:20.777855 | localhost -> localhost | changed
2025-10-13 11:50:20.783164 | 
2025-10-13 11:50:20.783233 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 11:50:21.618380 | localhost -> localhost | changed
2025-10-13 11:50:21.626834 | 
2025-10-13 11:50:21.626911 | TASK [Setup log path fact]
2025-10-13 11:50:21.643839 | localhost | ok
2025-10-13 11:50:21.666653 | 
2025-10-13 11:50:21.666747 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 11:50:21.715814 | localhost | ok
2025-10-13 11:50:21.723801 | 
2025-10-13 11:50:21.723862 | TASK [emit-job-header : Print job information]
2025-10-13 11:50:21.750953 | # Job Information
2025-10-13 11:50:21.751299 | Ansible Version: 2.15.12
2025-10-13 11:50:21.751330 | Job: cifmw-molecule-cifmw_external_dns
2025-10-13 11:50:21.751350 | Pipeline: github-check
2025-10-13 11:50:21.751368 | Executor: ze01.softwarefactory-project.io
2025-10-13 11:50:21.751385 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402
2025-10-13 11:50:21.751403 | Log URL (when completed): https://logserver.rdoproject.org/77f/rdoproject.org/77fbf22bf8af4be5b4de4df91f143b30/
2025-10-13 11:50:21.751420 | Event ID: 8b074e50-a82a-11f0-8a85-6f43315ec64f
2025-10-13 11:50:21.755186 | 
2025-10-13 11:50:21.755261 | LOOP [emit-job-header : Print node information]
2025-10-13 11:50:21.867802 | localhost | ok:
2025-10-13 11:50:21.867992 | localhost | # Node Information
2025-10-13 11:50:21.868040 | localhost | Inventory Hostname: controller
2025-10-13 11:50:21.868066 | localhost | Hostname: np0005484036
2025-10-13 11:50:21.868085 | localhost | Username: zuul
2025-10-13 11:50:21.868105 | localhost | Distro: CentOS 9
2025-10-13 11:50:21.868123 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 11:50:21.868141 | localhost | Region: RegionOne
2025-10-13 11:50:21.868157 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 11:50:21.868174 | localhost | Product Name: OpenStack Nova
2025-10-13 11:50:21.868191 | localhost | Interface IP: 38.102.83.219
2025-10-13 11:50:21.894597 | 
2025-10-13 11:50:21.894683 | PLAY [all]
2025-10-13 11:50:21.907895 | 
2025-10-13 11:50:21.907958 | TASK [Gather network facts]
2025-10-13 11:50:22.515512 | controller | ok
2025-10-13 11:50:22.529872 | 
2025-10-13 11:50:22.529938 | TASK [include_role : start-zuul-console]
2025-10-13 11:50:22.548715 | controller | ok
2025-10-13 11:50:22.559667 | 
2025-10-13 11:50:22.559731 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 11:50:22.923996 | controller | ok
2025-10-13 11:50:22.935424 | 
2025-10-13 11:50:22.935486 | TASK [include_role : add-build-sshkey]
2025-10-13 11:50:22.964457 | controller | ok
2025-10-13 11:50:22.977399 | 
2025-10-13 11:50:22.977463 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 11:50:23.255160 | controller -> localhost | ok
2025-10-13 11:50:23.268540 | 
2025-10-13 11:50:23.268820 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 11:50:23.303959 | controller | ok
2025-10-13 11:50:23.319793 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 11:50:23.328833 | 
2025-10-13 11:50:23.329061 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 11:50:24.472556 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 11:50:24.472761 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/77fbf22bf8af4be5b4de4df91f143b30_id_rsa.
2025-10-13 11:50:24.472792 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/77fbf22bf8af4be5b4de4df91f143b30_id_rsa.pub.
2025-10-13 11:50:24.472814 | controller -> localhost | The key fingerprint is:
2025-10-13 11:50:24.472833 | controller -> localhost | SHA256:wpKiDNHtbKokqm5/JOHBI2Lok/W/hGTTBBoASORI2O4 zuul-build-sshkey
2025-10-13 11:50:24.472851 | controller -> localhost | The key's randomart image is:
2025-10-13 11:50:24.472869 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 11:50:24.472886 | controller -> localhost | |B*.. .           |
2025-10-13 11:50:24.472904 | controller -> localhost | |*...o .          |
2025-10-13 11:50:24.472922 | controller -> localhost | |+oo..  .         |
2025-10-13 11:50:24.472939 | controller -> localhost | |o+.O oo          |
2025-10-13 11:50:24.472957 | controller -> localhost | |=.* @+o.S        |
2025-10-13 11:50:24.472974 | controller -> localhost | |o=E*o+o.         |
2025-10-13 11:50:24.472991 | controller -> localhost | |ooo o...         |
2025-10-13 11:50:24.473010 | controller -> localhost | |+o   ...         |
2025-10-13 11:50:24.473053 | controller -> localhost | |B....  ..        |
2025-10-13 11:50:24.473072 | controller -> localhost | +----[SHA256]-----+
2025-10-13 11:50:24.473132 | controller -> localhost | ok: Runtime: 0:00:00.602620
2025-10-13 11:50:24.479113 | 
2025-10-13 11:50:24.479176 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 11:50:24.510533 | controller | ok
2025-10-13 11:50:24.520048 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 11:50:24.528507 | 
2025-10-13 11:50:24.528573 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 11:50:24.552833 | controller | skipping: Conditional result was False
2025-10-13 11:50:24.558298 | 
2025-10-13 11:50:24.558380 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 11:50:25.077500 | controller | changed
2025-10-13 11:50:25.091963 | 
2025-10-13 11:50:25.092128 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 11:50:25.421612 | controller | ok
2025-10-13 11:50:25.426436 | 
2025-10-13 11:50:25.426496 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 11:50:26.403522 | controller | changed
2025-10-13 11:50:26.412970 | 
2025-10-13 11:50:26.413087 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 11:50:27.334852 | controller | changed
2025-10-13 11:50:27.346807 | 
2025-10-13 11:50:27.346940 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 11:50:27.392441 | controller | skipping: Conditional result was False
2025-10-13 11:50:27.398054 | 
2025-10-13 11:50:27.398118 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 11:50:27.806874 | controller -> localhost | changed
2025-10-13 11:50:27.817691 | 
2025-10-13 11:50:27.817769 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 11:50:28.074661 | controller -> localhost | Identity added: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/77fbf22bf8af4be5b4de4df91f143b30_id_rsa (zuul-build-sshkey)
2025-10-13 11:50:28.074856 | controller -> localhost | ok: Runtime: 0:00:00.009479
2025-10-13 11:50:28.080628 | 
2025-10-13 11:50:28.080689 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 11:50:28.454859 | controller | ok
2025-10-13 11:50:28.459429 | 
2025-10-13 11:50:28.459489 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 11:50:28.482871 | controller | skipping: Conditional result was False
2025-10-13 11:50:28.492373 | 
2025-10-13 11:50:28.492440 | TASK [include_role : validate-host]
2025-10-13 11:50:28.520199 | controller | ok
2025-10-13 11:50:28.540343 | 
2025-10-13 11:50:28.540462 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 11:50:28.568756 | controller | ok
2025-10-13 11:50:28.573647 | 
2025-10-13 11:50:28.573721 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 11:50:28.834407 | controller -> localhost | ok
2025-10-13 11:50:28.841390 | 
2025-10-13 11:50:28.841468 | TASK [validate-host : Collect information about the host]
2025-10-13 11:50:29.664273 | controller | ok
2025-10-13 11:50:29.673632 | 
2025-10-13 11:50:29.673749 | TASK [validate-host : Sanitize hostname]
2025-10-13 11:50:29.743224 | controller | ok
2025-10-13 11:50:29.748218 | 
2025-10-13 11:50:29.748286 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 11:50:30.194072 | controller -> localhost | changed
2025-10-13 11:50:30.200169 | 
2025-10-13 11:50:30.200246 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 11:50:30.661903 | controller | ok
2025-10-13 11:50:30.672184 | 
2025-10-13 11:50:30.672313 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 11:50:31.179170 | controller -> localhost | changed
2025-10-13 11:50:31.195373 | 
2025-10-13 11:50:31.195519 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 11:50:31.210558 | controller | skipping: Conditional result was False
2025-10-13 11:50:31.218355 | 
2025-10-13 11:50:31.218449 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 11:50:31.233609 | controller | skipping: Conditional result was False
2025-10-13 11:50:31.242385 | 
2025-10-13 11:50:31.242481 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 11:50:31.542177 | controller | ok: "logs"
2025-10-13 11:50:31.542558 | controller | ok: All items complete
2025-10-13 11:50:31.542592 | 
2025-10-13 11:50:31.797114 | controller | ok: "artifacts"
2025-10-13 11:50:32.090758 | controller | ok: "docs"
2025-10-13 11:50:32.097554 | 
2025-10-13 11:50:32.097667 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 11:50:32.403590 | controller | changed: "logs"
2025-10-13 11:50:32.660417 | controller | changed: "artifacts"
2025-10-13 11:50:32.905326 | controller | changed: "docs"
2025-10-13 11:50:32.936737 | 
2025-10-13 11:50:32.936850 | PLAY RECAP
2025-10-13 11:50:32.936904 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 11:50:32.936940 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 11:50:32.936964 | 
2025-10-13 11:50:33.040714 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 11:50:33.041524 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 11:50:33.620890 | 
2025-10-13 11:50:33.621008 | PLAY [localhost]
2025-10-13 11:50:33.646162 | 
2025-10-13 11:50:33.646234 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 11:50:34.008096 | localhost | ok
2025-10-13 11:50:34.013330 | 
2025-10-13 11:50:34.013409 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 11:50:34.700332 | localhost | changed
2025-10-13 11:50:34.724942 | 
2025-10-13 11:50:34.725077 | PLAY [all]
2025-10-13 11:50:34.740691 | 
2025-10-13 11:50:34.740783 | TASK [include_role : prepare-workspace]
2025-10-13 11:50:34.760173 | controller | ok
2025-10-13 11:50:34.779343 | 
2025-10-13 11:50:34.779702 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 11:50:35.249290 | controller | ok
2025-10-13 11:50:35.255390 | 
2025-10-13 11:50:35.255494 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 11:50:37.199447 | controller | Output suppressed because no_log was given
2025-10-13 11:50:37.219099 | 
2025-10-13 11:50:37.219196 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 11:50:37.543080 | controller | changed: "logs"
2025-10-13 11:50:37.809858 | controller | changed: "artifacts"
2025-10-13 11:50:38.064886 | controller | changed: "docs"
2025-10-13 11:50:38.080889 | 
2025-10-13 11:50:38.080997 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 11:50:38.378775 | controller | changed: "logs"
2025-10-13 11:50:38.379102 | controller | changed: All items complete
2025-10-13 11:50:38.379145 | 
2025-10-13 11:50:38.604729 | controller | changed: "artifacts"
2025-10-13 11:50:38.884671 | controller | changed: "docs"
2025-10-13 11:50:38.897966 | 
2025-10-13 11:50:38.898110 | TASK [Check if worker can sudo]
2025-10-13 11:50:39.458133 | controller | ok: Runtime: 0:00:00.049226
2025-10-13 11:50:39.463952 | 
2025-10-13 11:50:39.464079 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 11:50:39.508753 | controller | skipping: Conditional result was False
2025-10-13 11:50:39.514938 | 
2025-10-13 11:50:39.515002 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 11:50:39.563928 | controller | ok
2025-10-13 11:50:39.571316 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 11:50:39.577114 | 
2025-10-13 11:50:39.577173 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 11:50:39.891989 | controller | ok
2025-10-13 11:50:39.904464 | 
2025-10-13 11:50:39.904612 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 11:50:39.987244 | controller | ok: "/var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 11:50:40.006897 | 
2025-10-13 11:50:40.007082 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 11:50:40.963266 | controller | changed
2025-10-13 11:50:40.972929 | 
2025-10-13 11:50:40.973126 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 11:50:41.046558 | controller | ok: "/var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 11:50:41.046726 | controller | ok: All items complete
2025-10-13 11:50:41.046752 | 
2025-10-13 11:50:41.094607 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 11:50:41.100859 | 
2025-10-13 11:50:41.100926 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 11:50:42.174220 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 11:50:43.009569 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 11:50:43.030260 | 
2025-10-13 11:50:43.030407 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 11:50:43.537824 | controller | changed: section and option added
2025-10-13 11:50:43.557368 | 
2025-10-13 11:50:43.557433 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 11:50:44.447294 | controller | 29 files removed
2025-10-13 11:50:44.447579 | controller | ok: Item: dnf clean all Runtime: 0:00:00.545757
2025-10-13 11:50:44.447632 | controller | changed: All items complete
2025-10-13 11:50:44.447663 | 
2025-10-13 11:50:55.213823 | 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 11:50:55.213940 | controller | DNF version: 4.14.0
2025-10-13 11:50:55.213971 | controller | cachedir: /var/cache/dnf
2025-10-13 11:50:55.213996 | controller | Making cache files for all metadata files.
2025-10-13 11:50:55.214043 | controller | baseos: has expired and will be refreshed.
2025-10-13 11:50:55.214072 | controller | appstream: has expired and will be refreshed.
2025-10-13 11:50:55.214093 | controller | crb: has expired and will be refreshed.
2025-10-13 11:50:55.214125 | controller | extras-common: has expired and will be refreshed.
2025-10-13 11:50:55.214151 | controller | repo: downloading from remote: baseos
2025-10-13 11:50:55.214172 | controller | CentOS Stream 9 - BaseOS                         81 MB/s | 8.8 MB     00:00
2025-10-13 11:50:55.214193 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 11:50:55.214214 | controller | repo: downloading from remote: appstream
2025-10-13 11:50:55.214237 | controller | CentOS Stream 9 - AppStream                      88 MB/s |  25 MB     00:00
2025-10-13 11:50:55.214258 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 11:50:55.214278 | controller | repo: downloading from remote: crb
2025-10-13 11:50:55.214299 | controller | CentOS Stream 9 - CRB                            94 MB/s | 7.2 MB     00:00
2025-10-13 11:50:55.214322 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 11:50:55.214343 | controller | repo: downloading from remote: extras-common
2025-10-13 11:50:55.214363 | controller | CentOS Stream 9 - Extras packages               136 kB/s |  20 kB     00:00
2025-10-13 11:50:55.214384 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 11:50:55.214407 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 11:50:55.214428 | controller | Completion plugin: Generating completion cache...
2025-10-13 11:50:55.214449 | controller | Metadata cache created.
2025-10-13 11:50:55.214482 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.461793
2025-10-13 11:50:55.242788 | 
2025-10-13 11:50:55.242940 | PLAY RECAP
2025-10-13 11:50:55.243000 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 11:50:55.243067 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 11:50:55.243094 | 
2025-10-13 11:50:55.354382 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 11:50:55.355221 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 11:50:55.899000 | 
2025-10-13 11:50:55.899118 | PLAY [all]
2025-10-13 11:50:55.920923 | 
2025-10-13 11:50:55.921009 | TASK [Install binary dependencies]
2025-10-13 11:50:55.960617 | controller | ok
2025-10-13 11:50:55.979852 | 
2025-10-13 11:50:55.979944 | TASK [bindep : Include find tasks]
2025-10-13 11:50:56.008973 | controller | ok
2025-10-13 11:50:56.016762 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 11:50:56.022931 | 
2025-10-13 11:50:56.022993 | TASK [bindep : Look for bindep.txt]
2025-10-13 11:50:56.416681 | controller | ok
2025-10-13 11:50:56.423462 | 
2025-10-13 11:50:56.423532 | TASK [bindep : Define bindep_file fact]
2025-10-13 11:50:56.451990 | controller | ok
2025-10-13 11:50:56.457211 | 
2025-10-13 11:50:56.457289 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 11:50:56.471076 | controller | skipping: Conditional result was False
2025-10-13 11:50:56.477426 | 
2025-10-13 11:50:56.477507 | TASK [bindep : Define bindep_file fact]
2025-10-13 11:50:56.501164 | controller | skipping: Conditional result was False
2025-10-13 11:50:56.507145 | 
2025-10-13 11:50:56.507223 | TASK [bindep : Look for bindep fallback file]
2025-10-13 11:50:56.531146 | controller | skipping: Conditional result was False
2025-10-13 11:50:56.537335 | 
2025-10-13 11:50:56.537415 | TASK [bindep : Define bindep_file fact]
2025-10-13 11:50:56.561246 | controller | skipping: Conditional result was False
2025-10-13 11:50:56.567105 | 
2025-10-13 11:50:56.567172 | TASK [bindep : Include bindep tasks]
2025-10-13 11:50:56.596977 | controller | ok
2025-10-13 11:50:56.603471 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 11:50:56.611332 | 
2025-10-13 11:50:56.611401 | TASK [bindep : Look for bindep command]
2025-10-13 11:50:56.635220 | controller | skipping: Conditional result was False
2025-10-13 11:50:56.641622 | 
2025-10-13 11:50:56.641702 | TASK [bindep : Check for system bindep]
2025-10-13 11:50:57.174603 | controller | ok: Runtime: 0:00:00.006961
2025-10-13 11:50:57.180609 | 
2025-10-13 11:50:57.180684 | TASK [bindep : Define bindep_command fact]
2025-10-13 11:50:57.219630 | controller | skipping: Conditional result was False
2025-10-13 11:50:57.226664 | 
2025-10-13 11:50:57.226752 | TASK [bindep : Include install tasks]
2025-10-13 11:50:57.267254 | controller | ok
2025-10-13 11:50:57.275090 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 11:50:57.285231 | 
2025-10-13 11:50:57.285339 | TASK [bindep : Create temp dir for bindep]
2025-10-13 11:50:57.652286 | controller | changed
2025-10-13 11:50:57.663796 | 
2025-10-13 11:50:57.663918 | TASK [Ensure we have pip dependencies]
2025-10-13 11:50:57.691699 | controller | ok
2025-10-13 11:50:57.731553 | 
2025-10-13 11:50:57.731641 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 07:50:58.035654 | controller | /usr/bin/pip3
2025-10-13 07:50:58.074492 | controller | /usr/bin/python3: No module named wheel
2025-10-13 11:50:58.265411 | controller | ok: Runtime: 0:00:00.054120
2025-10-13 11:50:58.271368 | 
2025-10-13 11:50:58.271434 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 11:50:58.319612 | controller | ok: "/var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 11:50:58.346255 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 11:50:58.366641 | 
2025-10-13 11:50:58.366835 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 11:51:00.801468 | controller | changed
2025-10-13 11:51:00.812694 | 
2025-10-13 11:51:00.812818 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 11:51:00.849651 | controller | skipping: Conditional result was False
2025-10-13 11:51:00.858751 | 
2025-10-13 11:51:00.858837 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 11:51:00.915041 | controller | skipping: Conditional result was False
2025-10-13 11:51:00.924475 | 
2025-10-13 11:51:00.924564 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 11:51:00.969194 | controller | skipping: Conditional result was False
2025-10-13 11:51:00.975662 | 
2025-10-13 11:51:00.975736 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 11:51:00.999567 | controller | skipping: Conditional result was False
2025-10-13 11:51:01.008166 | 
2025-10-13 11:51:01.008325 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 11:51:01.545670 | controller | skipping: Conditional result was False
2025-10-13 11:51:01.559612 | 
2025-10-13 11:51:01.559778 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 11:51:01.587442 | controller | skipping: Conditional result was False
2025-10-13 11:51:01.602409 | 
2025-10-13 11:51:01.602586 | TASK [ensure-pip : Install pip from source]
2025-10-13 11:51:01.630074 | controller | skipping: Conditional result was False
2025-10-13 11:51:01.646198 | 
2025-10-13 11:51:01.646352 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 07:51:01.974620 | controller | /usr/bin/python3
2025-10-13 11:51:02.192933 | controller | ok: Runtime: 0:00:00.007460
2025-10-13 11:51:02.204544 | 
2025-10-13 11:51:02.204682 | TASK [ensure-pip : Set host default]
2025-10-13 11:51:02.262236 | controller | ok
2025-10-13 11:51:02.273396 | 
2025-10-13 11:51:02.273538 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 11:51:02.324239 | controller | ok
2025-10-13 11:51:02.346579 | 
2025-10-13 11:51:02.346723 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 11:51:07.073767 | controller | changed
2025-10-13 11:51:07.086058 | 
2025-10-13 11:51:07.086196 | TASK [bindep : Define bindep_command]
2025-10-13 11:51:07.115120 | controller | ok
2025-10-13 11:51:07.126800 | 
2025-10-13 11:51:07.126937 | LOOP [bindep : Include package tasks]
2025-10-13 11:51:07.173930 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 11:51:07.174146 | controller | ok: All items complete
2025-10-13 11:51:07.174182 | 
2025-10-13 11:51:07.191729 | controller | included: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 11:51:07.210656 | 
2025-10-13 11:51:07.210889 | TASK [bindep : Define bindep_run fact]
2025-10-13 11:51:07.246004 | controller | ok
2025-10-13 11:51:07.254210 | 
2025-10-13 11:51:07.254384 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 07:51:08.565092 | controller | podman
2025-10-13 07:51:08.615888 | controller | python3-jmespath
2025-10-13 07:51:08.615937 | controller | python3-libvirt
2025-10-13 07:51:08.615952 | controller | python3-lxml
2025-10-13 07:51:08.616098 | controller | python3-netaddr
2025-10-13 11:51:08.792901 | controller | ok: Runtime: 0:00:01.072761
2025-10-13 11:51:08.805813 | 
2025-10-13 11:51:08.805989 | TASK [bindep : Install distro packages from bindep]
2025-10-13 11:52:09.374441 | controller | changed
2025-10-13 11:52:09.423345 | 
2025-10-13 11:52:09.423503 | TASK [bindep : Check that packages are installed]
2025-10-13 11:52:10.960249 | controller | ok: Runtime: 0:00:01.097497
2025-10-13 11:52:10.966120 | 
2025-10-13 11:52:10.966195 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 11:52:11.000937 | controller | skipping: Conditional result was False
2025-10-13 11:52:11.025944 | 
2025-10-13 11:52:11.026157 | TASK [Run test-setup role]
2025-10-13 11:52:11.059187 | controller | ok
2025-10-13 11:52:11.090973 | 
2025-10-13 11:52:11.091097 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 11:52:11.374755 | controller | ok
2025-10-13 11:52:11.386809 | 
2025-10-13 11:52:11.386920 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 11:52:11.929191 | controller | skipping: Conditional result was False
2025-10-13 11:52:11.969998 | 
2025-10-13 11:52:11.970195 | TASK [bindep : Remove bindep temp dir]
2025-10-13 11:52:12.336460 | controller | ok
2025-10-13 11:52:12.347422 | 
2025-10-13 11:52:12.347474 | PLAY RECAP
2025-10-13 11:52:12.347515 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 11:52:12.347535 | 
2025-10-13 11:52:12.443626 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 11:52:12.444544 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 11:52:13.018265 | 
2025-10-13 11:52:13.018392 | PLAY [all]
2025-10-13 11:52:13.038559 | 
2025-10-13 11:52:13.038650 | TASK [Abort when test_command variable is undefined]
2025-10-13 11:52:13.071001 | controller | skipping: Conditional result was False
2025-10-13 11:52:13.076816 | 
2025-10-13 11:52:13.076896 | TASK [Convert test_command to list]
2025-10-13 11:52:13.111821 | controller | skipping: Conditional result was False
2025-10-13 11:52:13.118090 | 
2025-10-13 11:52:13.118153 | TASK [Use test_command list]
2025-10-13 11:52:13.187040 | controller | ok
2025-10-13 11:52:13.193032 | 
2025-10-13 11:52:13.193091 | LOOP [Run test_command]
2025-10-13 11:52:13.604127 | controller | no check to run
2025-10-13 11:52:13.604459 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006230
2025-10-13 11:52:13.650278 | 
2025-10-13 11:52:13.650399 | PLAY RECAP
2025-10-13 11:52:13.650454 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 11:52:13.650484 | 
2025-10-13 11:52:13.768912 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 11:52:13.770604 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 11:52:14.332005 | 
2025-10-13 11:52:14.332125 | PLAY [all]
2025-10-13 11:52:14.352256 | 
2025-10-13 11:52:14.352342 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 11:52:14.707641 | controller | changed: non-zero return code
2025-10-13 11:52:14.712989 | 
2025-10-13 11:52:14.713078 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 11:52:14.736533 | controller | skipping: Conditional result was False
2025-10-13 11:52:14.741965 | 
2025-10-13 11:52:14.742082 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 11:52:14.771753 | 
2025-10-13 11:52:14.771866 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 11:52:14.801042 | 
2025-10-13 11:52:14.801171 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 11:52:14.815517 | controller | skipping: Conditional result was False
2025-10-13 11:52:14.821920 | 
2025-10-13 11:52:14.821986 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 11:52:14.851027 | 
2025-10-13 11:52:14.851145 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 11:52:14.878415 | controller | skipping: Conditional result was False
2025-10-13 11:52:14.889382 | 
2025-10-13 11:52:14.889522 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 11:52:14.917557 | controller | skipping: Conditional result was False
2025-10-13 11:52:14.931359 | 
2025-10-13 11:52:14.931590 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 11:52:14.960584 | controller | skipping: Conditional result was False
2025-10-13 11:52:15.003202 | 
2025-10-13 11:52:15.003379 | PLAY RECAP
2025-10-13 11:52:15.003450 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 11:52:15.003480 | 
2025-10-13 11:52:15.178739 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 11:52:15.179575 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 11:52:15.750646 | 
2025-10-13 11:52:15.750774 | PLAY [all]
2025-10-13 11:52:15.769780 | 
2025-10-13 11:52:15.769916 | TASK [include_role : fetch-output]
2025-10-13 11:52:15.809984 | controller | ok
2025-10-13 11:52:15.827094 | 
2025-10-13 11:52:15.827177 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 11:52:15.882765 | controller | skipping: Conditional result was False
2025-10-13 11:52:15.888728 | 
2025-10-13 11:52:15.888796 | TASK [fetch-output : Set log path for single node]
2025-10-13 11:52:15.938421 | controller | ok
2025-10-13 11:52:15.943454 | 
2025-10-13 11:52:15.943520 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 11:52:16.340355 | controller -> localhost | ok: "/var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/logs"
2025-10-13 11:52:16.577616 | controller -> localhost | changed: "/var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/artifacts"
2025-10-13 11:52:16.789264 | controller -> localhost | changed: "/var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/docs"
2025-10-13 11:52:16.801194 | 
2025-10-13 11:52:16.801320 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 11:52:17.472522 | controller | changed: .d..t...... ./
2025-10-13 11:52:17.472850 | controller | changed: All items complete
2025-10-13 11:52:17.472882 | 
2025-10-13 11:52:17.997002 | controller | changed: .d..t...... ./
2025-10-13 11:52:18.505385 | controller | changed: .d..t...... ./
2025-10-13 11:52:18.533960 | 
2025-10-13 11:52:18.534103 | TASK [include_role : fetch-output-openshift]
2025-10-13 11:52:18.563539 | controller | skipping: Conditional result was False
2025-10-13 11:52:18.569565 | 
2025-10-13 11:52:18.569628 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 11:52:18.996517 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008008
2025-10-13 11:52:19.207687 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007532
2025-10-13 11:52:19.242953 | 
2025-10-13 11:52:19.243055 | PLAY [all]
2025-10-13 11:52:19.257147 | 
2025-10-13 11:52:19.257209 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 11:52:19.687561 | controller | changed
2025-10-13 11:52:19.716736 | 
2025-10-13 11:52:19.716823 | PLAY RECAP
2025-10-13 11:52:19.716863 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 11:52:19.716883 | 
2025-10-13 11:52:19.921118 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 11:52:19.921998 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 11:52:20.526129 | 
2025-10-13 11:52:20.526237 | PLAY [localhost]
2025-10-13 11:52:20.546316 | 
2025-10-13 11:52:20.546429 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 11:52:21.192689 | localhost | changed
2025-10-13 11:52:21.197514 | 
2025-10-13 11:52:21.197585 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 11:52:21.226565 | localhost | ok
2025-10-13 11:52:21.234395 | 
2025-10-13 11:52:21.234458 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 11:52:21.628458 | localhost | changed
2025-10-13 11:52:21.633851 | 
2025-10-13 11:52:21.633920 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 11:52:22.317605 | localhost | changed
2025-10-13 11:52:22.323921 | 
2025-10-13 11:52:22.323984 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 11:52:22.799513 | localhost | Identity added: /var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/tmp/ansible.ds8peu50 (/var/lib/zuul/builds/77fbf22bf8af4be5b4de4df91f143b30/work/tmp/ansible.ds8peu50)
2025-10-13 11:52:22.799674 | localhost | ok: Runtime: 0:00:00.012753
2025-10-13 11:52:22.804119 | 
2025-10-13 11:52:22.804182 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 11:52:23.044616 | localhost | ok: Runtime: 0:00:00.004862
2025-10-13 11:52:23.049823 | 
2025-10-13 11:52:23.049883 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 11:52:23.105938 | localhost | changed
2025-10-13 11:52:23.110204 | 
2025-10-13 11:52:23.110268 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 11:52:23.736902 | localhost | changed
2025-10-13 11:52:23.772070 | 
2025-10-13 11:52:23.772211 | PLAY [localhost]
2025-10-13 11:52:23.796065 | 
2025-10-13 11:52:23.796149 | TASK [Generate bulk log download script]
2025-10-13 11:52:23.819444 | localhost | ok
2025-10-13 11:52:23.836879 | 
2025-10-13 11:52:23.836953 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 11:52:23.900967 | localhost | ok: All assertions passed
2025-10-13 11:52:23.905390 | 
2025-10-13 11:52:23.905449 | TASK [local-log-download : Create download script]
2025-10-13 11:52:24.564849 | localhost -> localhost | changed
2025-10-13 11:52:24.578302 | 
2025-10-13 11:52:24.578403 | TASK [Register quick-download link]
2025-10-13 11:52:24.671983 | localhost | ok
2025-10-13 11:52:24.700272 | 
2025-10-13 11:52:24.700370 | PLAY [logserver.rdoproject.org]
2025-10-13 11:52:24.727301 | 
2025-10-13 11:52:24.727389 | TASK [Set zuul-log-path fact]
2025-10-13 11:52:24.744939 | logserver.rdoproject.org | ok
2025-10-13 11:52:24.753786 | 
2025-10-13 11:52:24.753865 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 11:52:24.805356 | logserver.rdoproject.org | ok
2025-10-13 11:52:24.811224 | 
2025-10-13 11:52:24.811285 | TASK [upload-logs : Create log directories]
2025-10-13 11:52:25.632664 | logserver.rdoproject.org | changed
2025-10-13 11:52:25.635768 | 
2025-10-13 11:52:25.635833 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 11:52:25.969451 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005079
2025-10-13 11:52:25.973948 | 
2025-10-13 11:52:25.974006 | TASK [upload-logs : Upload logs to log server]
2025-10-13 11:52:26.651718 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 11:52:26.654920 | 
2025-10-13 11:52:26.654986 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 11:52:26.696535 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 11:52:26.706254 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 11:52:26.713071 | 
2025-10-13 11:52:26.713142 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 11:52:26.755332 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 11:52:26.755558 | 
2025-10-13 11:52:26.756273 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 11:52:26.764287 | 
2025-10-13 11:52:26.764366 | LOOP [upload-logs : Upload console log and json output]