2025-12-05 15:18:35.140042 | Job console starting...
2025-12-05 15:18:35.151209 | Updating repositories
2025-12-05 15:18:35.170657 | Preparing job workspace
2025-12-05 15:18:39.070272 | Running Ansible setup...
2025-12-05 15:18:43.004255 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:18:43.724471 | 
2025-12-05 15:18:43.724591 | PLAY [localhost]
2025-12-05 15:18:43.745104 | 
2025-12-05 15:18:43.745191 | TASK [Gathering Facts]
2025-12-05 15:18:45.042110 | localhost | ok
2025-12-05 15:18:45.057566 | 
2025-12-05 15:18:45.057645 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-05 15:18:45.667026 | localhost -> localhost | changed
2025-12-05 15:18:45.673279 | 
2025-12-05 15:18:45.673347 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-05 15:18:46.648251 | localhost -> localhost | changed
2025-12-05 15:18:46.660357 | 
2025-12-05 15:18:46.660420 | TASK [Setup log path fact]
2025-12-05 15:18:46.702799 | localhost | ok
2025-12-05 15:18:46.726444 | 
2025-12-05 15:18:46.726517 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:18:46.760279 | localhost | ok
2025-12-05 15:18:46.770968 | 
2025-12-05 15:18:46.771033 | TASK [emit-job-header : Print job information]
2025-12-05 15:18:46.823273 | # Job Information
2025-12-05 15:18:46.823437 | Ansible Version: 2.15.12
2025-12-05 15:18:46.823462 | Job: cifmw-molecule-cifmw_external_dns
2025-12-05 15:18:46.823485 | Pipeline: github-check
2025-12-05 15:18:46.823504 | Executor: ze02.softwarefactory-project.io
2025-12-05 15:18:46.823522 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539
2025-12-05 15:18:46.823541 | Log URL (when completed): https://logserver.rdoproject.org/28a/rdoproject.org/28aabb70a1d84ecfb2e8039ed3674ce9/
2025-12-05 15:18:46.823560 | Event ID: 748a4b40-d1ed-11f0-8510-c0ded0ca5b3b
2025-12-05 15:18:46.828478 | 
2025-12-05 15:18:46.828545 | LOOP [emit-job-header : Print node information]
2025-12-05 15:18:46.925842 | localhost | ok:
2025-12-05 15:18:46.926053 | localhost | # Node Information
2025-12-05 15:18:46.926081 | localhost | Inventory Hostname: controller
2025-12-05 15:18:46.926104 | localhost | Hostname: np0005547214
2025-12-05 15:18:46.926123 | localhost | Username: zuul
2025-12-05 15:18:46.926143 | localhost | Distro: CentOS 9
2025-12-05 15:18:46.926161 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-05 15:18:46.926178 | localhost | Region: RegionOne
2025-12-05 15:18:46.926195 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-05 15:18:46.926210 | localhost | Product Name: OpenStack Nova
2025-12-05 15:18:46.926227 | localhost | Interface IP: 38.102.83.154
2025-12-05 15:18:46.970162 | 
2025-12-05 15:18:46.970316 | PLAY [all]
2025-12-05 15:18:46.984927 | 
2025-12-05 15:18:46.984995 | TASK [Gather network facts]
2025-12-05 15:18:47.550593 | controller | ok
2025-12-05 15:18:47.575926 | 
2025-12-05 15:18:47.575999 | TASK [include_role : start-zuul-console]
2025-12-05 15:18:47.617465 | controller | ok
2025-12-05 15:18:47.629372 | 
2025-12-05 15:18:47.629441 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-05 15:18:48.085086 | controller | ok
2025-12-05 15:18:48.093688 | 
2025-12-05 15:18:48.093751 | TASK [include_role : add-build-sshkey]
2025-12-05 15:18:48.124885 | controller | ok
2025-12-05 15:18:48.150649 | 
2025-12-05 15:18:48.151149 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 15:18:48.394713 | controller -> localhost | ok
2025-12-05 15:18:48.401025 | 
2025-12-05 15:18:48.401087 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 15:18:48.421282 | controller | ok
2025-12-05 15:18:48.440288 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 15:18:48.446216 | 
2025-12-05 15:18:48.446274 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 15:18:49.139967 | controller -> localhost | Generating public/private rsa key pair.
2025-12-05 15:18:49.140176 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/28aabb70a1d84ecfb2e8039ed3674ce9_id_rsa.
2025-12-05 15:18:49.140208 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/28aabb70a1d84ecfb2e8039ed3674ce9_id_rsa.pub.
2025-12-05 15:18:49.140230 | controller -> localhost | The key fingerprint is:
2025-12-05 15:18:49.140249 | controller -> localhost | SHA256:7KIqvcqbJuf1MAbeNUk96u8fHP8L6dwV6bss3tsxhoI zuul-build-sshkey
2025-12-05 15:18:49.140270 | controller -> localhost | The key's randomart image is:
2025-12-05 15:18:49.140288 | controller -> localhost | +---[RSA 3072]----+
2025-12-05 15:18:49.140306 | controller -> localhost | |                 |
2025-12-05 15:18:49.140324 | controller -> localhost | |       .         |
2025-12-05 15:18:49.140341 | controller -> localhost | |      . o        |
2025-12-05 15:18:49.140359 | controller -> localhost | |     . + .      .|
2025-12-05 15:18:49.140377 | controller -> localhost | |  .   = S .    o |
2025-12-05 15:18:49.140394 | controller -> localhost | | . o o o ..o .o .|
2025-12-05 15:18:49.140410 | controller -> localhost | | .. * o .Eo.+. =.|
2025-12-05 15:18:49.140427 | controller -> localhost | |+.+o = o   +.=+.=|
2025-12-05 15:18:49.140445 | controller -> localhost | |+O=o. ..o.. +.=B+|
2025-12-05 15:18:49.140461 | controller -> localhost | +----[SHA256]-----+
2025-12-05 15:18:49.140510 | controller -> localhost | ok: Runtime: 0:00:00.200717
2025-12-05 15:18:49.146350 | 
2025-12-05 15:18:49.146410 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 15:18:49.171818 | controller | ok
2025-12-05 15:18:49.191403 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 15:18:49.206504 | 
2025-12-05 15:18:49.206693 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 15:18:49.231802 | controller | skipping: Conditional result was False
2025-12-05 15:18:49.238125 | 
2025-12-05 15:18:49.238189 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 15:18:49.718682 | controller | changed
2025-12-05 15:18:49.724306 | 
2025-12-05 15:18:49.724372 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 15:18:50.002379 | controller | ok
2025-12-05 15:18:50.018864 | 
2025-12-05 15:18:50.019006 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 15:18:50.926154 | controller | changed
2025-12-05 15:18:50.936073 | 
2025-12-05 15:18:50.936135 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 15:18:51.813829 | controller | changed
2025-12-05 15:18:51.818767 | 
2025-12-05 15:18:51.818828 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 15:18:51.866767 | controller | skipping: Conditional result was False
2025-12-05 15:18:51.872384 | 
2025-12-05 15:18:51.872447 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 15:18:52.290464 | controller -> localhost | changed
2025-12-05 15:18:52.301133 | 
2025-12-05 15:18:52.301203 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 15:18:52.613227 | controller -> localhost | Identity added: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/28aabb70a1d84ecfb2e8039ed3674ce9_id_rsa (zuul-build-sshkey)
2025-12-05 15:18:52.613434 | controller -> localhost | ok: Runtime: 0:00:00.008966
2025-12-05 15:18:52.620071 | 
2025-12-05 15:18:52.620133 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 15:18:53.101937 | controller | ok
2025-12-05 15:18:53.106556 | 
2025-12-05 15:18:53.106617 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 15:18:53.144414 | controller | skipping: Conditional result was False
2025-12-05 15:18:53.155207 | 
2025-12-05 15:18:53.155273 | TASK [include_role : validate-host]
2025-12-05 15:18:53.184583 | controller | ok
2025-12-05 15:18:53.204354 | 
2025-12-05 15:18:53.204428 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-05 15:18:53.244876 | controller | ok
2025-12-05 15:18:53.254264 | 
2025-12-05 15:18:53.254327 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-05 15:18:53.502871 | controller -> localhost | ok
2025-12-05 15:18:53.538303 | 
2025-12-05 15:18:53.538428 | TASK [validate-host : Collect information about the host]
2025-12-05 15:18:54.360527 | controller | ok
2025-12-05 15:18:54.373244 | 
2025-12-05 15:18:54.373328 | TASK [validate-host : Sanitize hostname]
2025-12-05 15:18:54.457351 | controller | ok
2025-12-05 15:18:54.466047 | 
2025-12-05 15:18:54.466188 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-05 15:18:54.917556 | controller -> localhost | changed
2025-12-05 15:18:54.923280 | 
2025-12-05 15:18:54.923344 | TASK [validate-host : Collect information about zuul worker]
2025-12-05 15:18:55.354736 | controller | ok
2025-12-05 15:18:55.367323 | 
2025-12-05 15:18:55.367454 | TASK [validate-host : Write out all zuul information for each host]
2025-12-05 15:18:55.903569 | controller -> localhost | changed
2025-12-05 15:18:55.913283 | 
2025-12-05 15:18:55.913342 | TASK [include_role : prepare-workspace-openshift]
2025-12-05 15:18:55.926802 | controller | skipping: Conditional result was False
2025-12-05 15:18:55.933051 | 
2025-12-05 15:18:55.933127 | TASK [include_role : remove-zuul-sshkey]
2025-12-05 15:18:55.948433 | controller | skipping: Conditional result was False
2025-12-05 15:18:55.956929 | 
2025-12-05 15:18:55.957132 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:18:56.268197 | controller | ok: "logs"
2025-12-05 15:18:56.269416 | controller | ok: All items complete
2025-12-05 15:18:56.269573 | 
2025-12-05 15:18:56.512812 | controller | ok: "artifacts"
2025-12-05 15:18:56.715765 | controller | ok: "docs"
2025-12-05 15:18:56.730875 | 
2025-12-05 15:18:56.731008 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:18:57.016922 | controller | changed: "logs"
2025-12-05 15:18:57.275492 | controller | changed: "artifacts"
2025-12-05 15:18:57.489393 | controller | changed: "docs"
2025-12-05 15:18:57.537501 | 
2025-12-05 15:18:57.537611 | PLAY RECAP
2025-12-05 15:18:57.537655 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-05 15:18:57.537710 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:18:57.537729 | 
2025-12-05 15:18:57.709298 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:18:57.710145 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:18:58.466112 | 
2025-12-05 15:18:58.466308 | PLAY [localhost]
2025-12-05 15:18:58.487567 | 
2025-12-05 15:18:58.487654 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-05 15:18:58.973563 | localhost | ok
2025-12-05 15:18:58.979745 | 
2025-12-05 15:18:58.979842 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-05 15:18:59.750406 | localhost | changed
2025-12-05 15:18:59.774913 | 
2025-12-05 15:18:59.774980 | PLAY [all]
2025-12-05 15:18:59.794499 | 
2025-12-05 15:18:59.794575 | TASK [include_role : prepare-workspace]
2025-12-05 15:18:59.837508 | controller | ok
2025-12-05 15:18:59.855530 | 
2025-12-05 15:18:59.855703 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-05 15:19:00.310140 | controller | ok
2025-12-05 15:19:00.319592 | 
2025-12-05 15:19:00.319837 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-05 15:19:02.272867 | controller | Output suppressed because no_log was given
2025-12-05 15:19:02.295333 | 
2025-12-05 15:19:02.295492 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:19:02.653182 | controller | changed: "logs"
2025-12-05 15:19:02.865892 | controller | changed: "artifacts"
2025-12-05 15:19:03.082680 | controller | changed: "docs"
2025-12-05 15:19:03.098963 | 
2025-12-05 15:19:03.099041 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:19:03.459000 | controller | changed: "logs"
2025-12-05 15:19:03.459301 | controller | changed: All items complete
2025-12-05 15:19:03.459330 | 
2025-12-05 15:19:03.671573 | controller | changed: "artifacts"
2025-12-05 15:19:03.892532 | controller | changed: "docs"
2025-12-05 15:19:03.907060 | 
2025-12-05 15:19:03.907156 | TASK [Check if worker can sudo]
2025-12-05 15:19:04.957212 | controller | ok: Runtime: 0:00:00.035040
2025-12-05 15:19:04.964145 | 
2025-12-05 15:19:04.964245 | TASK [configure-mirrors : Gather needed facts]
2025-12-05 15:19:05.055071 | controller | skipping: Conditional result was False
2025-12-05 15:19:05.062322 | 
2025-12-05 15:19:05.062398 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-05 15:19:05.184161 | controller | ok
2025-12-05 15:19:05.263553 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-05 15:19:05.270141 | 
2025-12-05 15:19:05.270209 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-05 15:19:05.574059 | controller | ok
2025-12-05 15:19:05.590317 | 
2025-12-05 15:19:05.590455 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-05 15:19:05.685461 | controller | ok: "/var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-05 15:19:05.703702 | 
2025-12-05 15:19:05.703902 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-05 15:19:06.628581 | controller | changed
2025-12-05 15:19:06.634955 | 
2025-12-05 15:19:06.635027 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-05 15:19:06.729926 | controller | ok: "/var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-05 15:19:06.730136 | controller | ok: All items complete
2025-12-05 15:19:06.730162 | 
2025-12-05 15:19:06.778219 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-05 15:19:06.785027 | 
2025-12-05 15:19:06.785105 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-05 15:19:07.717093 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-05 15:19:08.670543 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-05 15:19:08.691201 | 
2025-12-05 15:19:08.691350 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-05 15:19:09.242691 | controller | changed: section and option added
2025-12-05 15:19:09.283562 | 
2025-12-05 15:19:09.283651 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-05 15:19:09.976019 | controller | 29 files removed
2025-12-05 15:19:09.976448 | controller | ok: Item: dnf clean all Runtime: 0:00:00.328924
2025-12-05 15:19:09.976534 | controller | changed: All items complete
2025-12-05 15:19:09.976581 | 
2025-12-05 15:19:20.793490 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-12-05 15:19:20.793707 | controller | DNF version: 4.14.0
2025-12-05 15:19:20.793785 | controller | cachedir: /var/cache/dnf
2025-12-05 15:19:20.793842 | controller | Making cache files for all metadata files.
2025-12-05 15:19:20.793894 | controller | baseos: has expired and will be refreshed.
2025-12-05 15:19:20.793942 | controller | appstream: has expired and will be refreshed.
2025-12-05 15:19:20.793988 | controller | crb: has expired and will be refreshed.
2025-12-05 15:19:20.794082 | controller | extras-common: has expired and will be refreshed.
2025-12-05 15:19:20.794128 | controller | repo: downloading from remote: baseos
2025-12-05 15:19:20.794179 | controller | CentOS Stream 9 - BaseOS                         63 MB/s | 8.8 MB     00:00
2025-12-05 15:19:20.794228 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-05 15:19:20.794274 | controller | repo: downloading from remote: appstream
2025-12-05 15:19:20.794320 | controller | CentOS Stream 9 - AppStream                     104 MB/s |  25 MB     00:00
2025-12-05 15:19:20.794365 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-05 15:19:20.794410 | controller | repo: downloading from remote: crb
2025-12-05 15:19:20.794455 | controller | CentOS Stream 9 - CRB                            85 MB/s | 7.3 MB     00:00
2025-12-05 15:19:20.794503 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-05 15:19:20.794547 | controller | repo: downloading from remote: extras-common
2025-12-05 15:19:20.794594 | controller | CentOS Stream 9 - Extras packages               1.7 MB/s |  20 kB     00:00
2025-12-05 15:19:20.794640 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-05 15:19:20.794734 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-05 15:19:20.794785 | controller | Completion plugin: Generating completion cache...
2025-12-05 15:19:20.794831 | controller | Metadata cache created.
2025-12-05 15:19:20.794897 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.528750
2025-12-05 15:19:20.824959 | 
2025-12-05 15:19:20.825171 | PLAY RECAP
2025-12-05 15:19:20.825269 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-05 15:19:20.825331 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:19:20.825374 | 
2025-12-05 15:19:21.029981 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:19:21.030854 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:19:21.647643 | 
2025-12-05 15:19:21.647791 | PLAY [all]
2025-12-05 15:19:21.670773 | 
2025-12-05 15:19:21.670851 | TASK [Install binary dependencies]
2025-12-05 15:19:21.753949 | controller | ok
2025-12-05 15:19:21.774642 | 
2025-12-05 15:19:21.774763 | TASK [bindep : Include find tasks]
2025-12-05 15:19:21.805337 | controller | ok
2025-12-05 15:19:21.813189 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-05 15:19:21.819328 | 
2025-12-05 15:19:21.819392 | TASK [bindep : Look for bindep.txt]
2025-12-05 15:19:22.268460 | controller | ok
2025-12-05 15:19:22.275435 | 
2025-12-05 15:19:22.275506 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:19:22.319460 | controller | ok
2025-12-05 15:19:22.327405 | 
2025-12-05 15:19:22.327494 | TASK [bindep : Look for other-requirements.txt]
2025-12-05 15:19:22.354149 | controller | skipping: Conditional result was False
2025-12-05 15:19:22.362726 | 
2025-12-05 15:19:22.362824 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:19:22.422510 | controller | skipping: Conditional result was False
2025-12-05 15:19:22.431604 | 
2025-12-05 15:19:22.431725 | TASK [bindep : Look for bindep fallback file]
2025-12-05 15:19:22.467149 | controller | skipping: Conditional result was False
2025-12-05 15:19:22.475383 | 
2025-12-05 15:19:22.475476 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:19:22.502014 | controller | skipping: Conditional result was False
2025-12-05 15:19:22.510846 | 
2025-12-05 15:19:22.510937 | TASK [bindep : Include bindep tasks]
2025-12-05 15:19:22.556908 | controller | ok
2025-12-05 15:19:22.569778 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-05 15:19:22.580457 | 
2025-12-05 15:19:22.580541 | TASK [bindep : Look for bindep command]
2025-12-05 15:19:22.606326 | controller | skipping: Conditional result was False
2025-12-05 15:19:22.614017 | 
2025-12-05 15:19:22.614080 | TASK [bindep : Check for system bindep]
2025-12-05 15:19:23.158386 | controller | ok: Runtime: 0:00:00.007625
2025-12-05 15:19:23.170836 | 
2025-12-05 15:19:23.170964 | TASK [bindep : Define bindep_command fact]
2025-12-05 15:19:23.209540 | controller | skipping: Conditional result was False
2025-12-05 15:19:23.219472 | 
2025-12-05 15:19:23.223433 | TASK [bindep : Include install tasks]
2025-12-05 15:19:23.263913 | controller | ok
2025-12-05 15:19:23.280862 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-05 15:19:23.289602 | 
2025-12-05 15:19:23.289667 | TASK [bindep : Create temp dir for bindep]
2025-12-05 15:19:23.686250 | controller | changed
2025-12-05 15:19:23.692300 | 
2025-12-05 15:19:23.692362 | TASK [Ensure we have pip dependencies]
2025-12-05 15:19:23.723762 | controller | ok
2025-12-05 15:19:23.748080 | 
2025-12-05 15:19:23.748145 | TASK [ensure-pip : Check if pip is installed]
2025-12-05 10:19:24.059285 | controller | /usr/bin/pip3
2025-12-05 10:19:24.090632 | controller | /usr/bin/python3: No module named wheel
2025-12-05 15:19:24.280228 | controller | ok: Runtime: 0:00:00.044292
2025-12-05 15:19:24.286234 | 
2025-12-05 15:19:24.286306 | LOOP [ensure-pip : Install pip from packages]
2025-12-05 15:19:24.341243 | controller | ok: "/var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-05 15:19:24.351965 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-05 15:19:24.361915 | 
2025-12-05 15:19:24.361977 | TASK [ensure-pip : Install Python 3 pip]
2025-12-05 15:19:26.141086 | controller | changed
2025-12-05 15:19:26.152732 | 
2025-12-05 15:19:26.152800 | TASK [ensure-pip : Check for EPEL repository]
2025-12-05 15:19:26.211491 | controller | skipping: Conditional result was False
2025-12-05 15:19:26.218794 | 
2025-12-05 15:19:26.218863 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-05 15:19:26.265744 | controller | skipping: Conditional result was False
2025-12-05 15:19:26.275298 | 
2025-12-05 15:19:26.275411 | TASK [ensure-pip : Install Python 2 pip]
2025-12-05 15:19:26.321878 | controller | skipping: Conditional result was False
2025-12-05 15:19:26.336342 | 
2025-12-05 15:19:26.336476 | TASK [ensure-pip : Ensure setuptools]
2025-12-05 15:19:26.355283 | controller | skipping: Conditional result was False
2025-12-05 15:19:26.368772 | 
2025-12-05 15:19:26.368906 | TASK [ensure-pip : Check for ensurepip module]
2025-12-05 15:19:26.911836 | controller | skipping: Conditional result was False
2025-12-05 15:19:26.919573 | 
2025-12-05 15:19:26.919660 | TASK [ensure-pip : Ensure python3-venv]
2025-12-05 15:19:26.945881 | controller | skipping: Conditional result was False
2025-12-05 15:19:26.953008 | 
2025-12-05 15:19:26.953072 | TASK [ensure-pip : Install pip from source]
2025-12-05 15:19:26.968809 | controller | skipping: Conditional result was False
2025-12-05 15:19:26.976256 | 
2025-12-05 15:19:26.976351 | TASK [ensure-pip : Probe for venv python full path]
2025-12-05 10:19:27.256185 | controller | /usr/bin/python3
2025-12-05 15:19:27.509614 | controller | ok: Runtime: 0:00:00.008820
2025-12-05 15:19:27.523526 | 
2025-12-05 15:19:27.523863 | TASK [ensure-pip : Set host default]
2025-12-05 15:19:27.605495 | controller | ok
2025-12-05 15:19:27.616783 | 
2025-12-05 15:19:27.616919 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-05 15:19:27.701027 | controller | ok
2025-12-05 15:19:27.724875 | 
2025-12-05 15:19:27.725008 | TASK [bindep : Install bindep into temporary venv]
2025-12-05 15:19:31.952086 | controller | changed
2025-12-05 15:19:31.965527 | 
2025-12-05 15:19:31.965715 | TASK [bindep : Define bindep_command]
2025-12-05 15:19:32.006139 | controller | ok
2025-12-05 15:19:32.017774 | 
2025-12-05 15:19:32.017929 | LOOP [bindep : Include package tasks]
2025-12-05 15:19:32.081469 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-05 15:19:32.081793 | controller | ok: All items complete
2025-12-05 15:19:32.081831 | 
2025-12-05 15:19:32.098226 | controller | included: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-05 15:19:32.112816 | 
2025-12-05 15:19:32.112906 | TASK [bindep : Define bindep_run fact]
2025-12-05 15:19:32.149929 | controller | ok
2025-12-05 15:19:32.158174 | 
2025-12-05 15:19:32.158289 | TASK [bindep : Get list of packages to install from bindep]
2025-12-05 10:19:33.658107 | controller | podman
2025-12-05 10:19:33.692595 | controller | python3-jmespath
2025-12-05 10:19:33.692825 | controller | python3-libvirt
2025-12-05 10:19:33.692837 | controller | python3-lxml
2025-12-05 10:19:33.692848 | controller | python3-netaddr
2025-12-05 15:19:33.735527 | controller | ok: Runtime: 0:00:01.278941
2025-12-05 15:19:33.747584 | 
2025-12-05 15:19:33.747768 | TASK [bindep : Install distro packages from bindep]
2025-12-05 15:20:36.418013 | controller | changed
2025-12-05 15:20:36.429247 | 
2025-12-05 15:20:36.429370 | TASK [bindep : Check that packages are installed]
2025-12-05 15:20:37.978012 | controller | ok: Runtime: 0:00:01.097301
2025-12-05 15:20:37.991116 | 
2025-12-05 15:20:37.991257 | TASK [bindep : Fail if we cannot install all packages]
2025-12-05 15:20:38.019483 | controller | skipping: Conditional result was False
2025-12-05 15:20:38.044417 | 
2025-12-05 15:20:38.044525 | TASK [Run test-setup role]
2025-12-05 15:20:38.066883 | controller | ok
2025-12-05 15:20:38.090101 | 
2025-12-05 15:20:38.090206 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-05 15:20:38.324658 | controller | ok
2025-12-05 15:20:38.348600 | 
2025-12-05 15:20:38.348717 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-05 15:20:38.885969 | controller | skipping: Conditional result was False
2025-12-05 15:20:38.918313 | 
2025-12-05 15:20:38.918411 | TASK [bindep : Remove bindep temp dir]
2025-12-05 15:20:39.272941 | controller | ok
2025-12-05 15:20:39.284143 | 
2025-12-05 15:20:39.284194 | PLAY RECAP
2025-12-05 15:20:39.284236 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-05 15:20:39.284259 | 
2025-12-05 15:20:39.383780 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:20:39.384624 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:20:39.968195 | 
2025-12-05 15:20:39.968310 | PLAY [all]
2025-12-05 15:20:39.987322 | 
2025-12-05 15:20:39.987394 | TASK [Abort when test_command variable is undefined]
2025-12-05 15:20:40.022227 | controller | skipping: Conditional result was False
2025-12-05 15:20:40.028075 | 
2025-12-05 15:20:40.028146 | TASK [Convert test_command to list]
2025-12-05 15:20:40.067470 | controller | skipping: Conditional result was False
2025-12-05 15:20:40.074381 | 
2025-12-05 15:20:40.074480 | TASK [Use test_command list]
2025-12-05 15:20:40.125834 | controller | ok
2025-12-05 15:20:40.131114 | 
2025-12-05 15:20:40.131178 | LOOP [Run test_command]
2025-12-05 15:20:40.536501 | controller | no check to run
2025-12-05 15:20:40.536691 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005184
2025-12-05 15:20:40.575739 | 
2025-12-05 15:20:40.575841 | PLAY RECAP
2025-12-05 15:20:40.575894 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:20:40.575915 | 
2025-12-05 15:20:40.665881 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:20:40.668105 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:20:41.214752 | 
2025-12-05 15:20:41.214865 | PLAY [all]
2025-12-05 15:20:41.235556 | 
2025-12-05 15:20:41.235638 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-05 15:20:41.580539 | controller | changed: non-zero return code
2025-12-05 15:20:41.586327 | 
2025-12-05 15:20:41.586406 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-05 15:20:41.610797 | controller | skipping: Conditional result was False
2025-12-05 15:20:41.619221 | 
2025-12-05 15:20:41.619313 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-05 15:20:41.651855 | 
2025-12-05 15:20:41.652001 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-05 15:20:41.672370 | 
2025-12-05 15:20:41.672612 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-05 15:20:41.690241 | controller | skipping: Conditional result was False
2025-12-05 15:20:41.697324 | 
2025-12-05 15:20:41.697407 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-05 15:20:41.729234 | 
2025-12-05 15:20:41.729362 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-05 15:20:41.755471 | controller | skipping: Conditional result was False
2025-12-05 15:20:41.761088 | 
2025-12-05 15:20:41.761155 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-05 15:20:41.784351 | controller | skipping: Conditional result was False
2025-12-05 15:20:41.789838 | 
2025-12-05 15:20:41.789903 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-05 15:20:41.814084 | controller | skipping: Conditional result was False
2025-12-05 15:20:41.837602 | 
2025-12-05 15:20:41.837656 | PLAY RECAP
2025-12-05 15:20:41.837723 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-05 15:20:41.837745 | 
2025-12-05 15:20:41.940282 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:20:41.941228 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:20:42.525511 | 
2025-12-05 15:20:42.525628 | PLAY [all]
2025-12-05 15:20:42.545074 | 
2025-12-05 15:20:42.545155 | TASK [include_role : fetch-output]
2025-12-05 15:20:42.605278 | controller | ok
2025-12-05 15:20:42.622153 | 
2025-12-05 15:20:42.622243 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 15:20:42.666879 | controller | skipping: Conditional result was False
2025-12-05 15:20:42.673483 | 
2025-12-05 15:20:42.673557 | TASK [fetch-output : Set log path for single node]
2025-12-05 15:20:42.706909 | controller | ok
2025-12-05 15:20:42.712339 | 
2025-12-05 15:20:42.712426 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 15:20:43.141178 | controller -> localhost | ok: "/var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/logs"
2025-12-05 15:20:43.391968 | controller -> localhost | changed: "/var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/artifacts"
2025-12-05 15:20:43.624724 | controller -> localhost | changed: "/var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/docs"
2025-12-05 15:20:43.640948 | 
2025-12-05 15:20:43.641194 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 15:20:44.304473 | controller | changed: .d..t...... ./
2025-12-05 15:20:44.304700 | controller | changed: All items complete
2025-12-05 15:20:44.304732 | 
2025-12-05 15:20:44.800996 | controller | changed: .d..t...... ./
2025-12-05 15:20:45.297695 | controller | changed: .d..t...... ./
2025-12-05 15:20:45.320404 | 
2025-12-05 15:20:45.320588 | TASK [include_role : fetch-output-openshift]
2025-12-05 15:20:45.348680 | controller | skipping: Conditional result was False
2025-12-05 15:20:45.358346 | 
2025-12-05 15:20:45.358455 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-05 15:20:45.875503 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.018445
2025-12-05 15:20:46.137101 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.033488
2025-12-05 15:20:46.172815 | 
2025-12-05 15:20:46.172950 | PLAY [all]
2025-12-05 15:20:46.187783 | 
2025-12-05 15:20:46.187855 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-05 15:20:46.675086 | controller | changed
2025-12-05 15:20:46.713144 | 
2025-12-05 15:20:46.713212 | PLAY RECAP
2025-12-05 15:20:46.713271 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:20:46.713300 | 
2025-12-05 15:20:46.855894 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:20:46.857043 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-05 15:20:47.509906 | 
2025-12-05 15:20:47.510027 | PLAY [localhost]
2025-12-05 15:20:47.542067 | 
2025-12-05 15:20:47.542195 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-05 15:20:47.947822 | localhost | changed
2025-12-05 15:20:47.953293 | 
2025-12-05 15:20:47.953370 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-05 15:20:47.982370 | localhost | ok
2025-12-05 15:20:47.991433 | 
2025-12-05 15:20:47.991501 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-05 15:20:48.482634 | localhost | changed
2025-12-05 15:20:48.497893 | 
2025-12-05 15:20:48.498006 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-05 15:20:49.412092 | localhost | changed
2025-12-05 15:20:49.419861 | 
2025-12-05 15:20:49.419928 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-05 15:20:49.809323 | localhost | Identity added: /var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/tmp/ansible.owijzdwk (/var/lib/zuul/builds/28aabb70a1d84ecfb2e8039ed3674ce9/work/tmp/ansible.owijzdwk)
2025-12-05 15:20:49.809630 | localhost | ok: Runtime: 0:00:00.008450
2025-12-05 15:20:49.820043 | 
2025-12-05 15:20:49.820117 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-05 15:20:50.144975 | localhost | ok: Runtime: 0:00:00.007393
2025-12-05 15:20:50.151612 | 
2025-12-05 15:20:50.151707 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-05 15:20:50.203817 | localhost | changed
2025-12-05 15:20:50.208437 | 
2025-12-05 15:20:50.208505 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-05 15:20:50.605938 | localhost | changed
2025-12-05 15:20:50.637396 | 
2025-12-05 15:20:50.637463 | PLAY [localhost]
2025-12-05 15:20:50.658425 | 
2025-12-05 15:20:50.658562 | TASK [Generate bulk log download script]
2025-12-05 15:20:50.688224 | localhost | ok
2025-12-05 15:20:50.700562 | 
2025-12-05 15:20:50.700683 | TASK [local-log-download : Check API endpoint is defined]
2025-12-05 15:20:50.728510 | localhost | ok: All assertions passed
2025-12-05 15:20:50.733127 | 
2025-12-05 15:20:50.733190 | TASK [local-log-download : Create download script]
2025-12-05 15:20:51.121432 | localhost -> localhost | changed
2025-12-05 15:20:51.130763 | 
2025-12-05 15:20:51.130829 | TASK [Register quick-download link]
2025-12-05 15:20:51.151963 | localhost | ok
2025-12-05 15:20:51.195868 | 
2025-12-05 15:20:51.195969 | PLAY [logserver.rdoproject.org]
2025-12-05 15:20:51.205465 | 
2025-12-05 15:20:51.205521 | TASK [Set zuul-log-path fact]
2025-12-05 15:20:51.221397 | logserver.rdoproject.org | ok
2025-12-05 15:20:51.230290 | 
2025-12-05 15:20:51.230353 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:20:51.256507 | logserver.rdoproject.org | ok
2025-12-05 15:20:51.261753 | 
2025-12-05 15:20:51.261814 | TASK [upload-logs : Create log directories]
2025-12-05 15:20:51.891561 | logserver.rdoproject.org | changed
2025-12-05 15:20:51.896183 | 
2025-12-05 15:20:51.896267 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-05 15:20:52.151356 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005699
2025-12-05 15:20:52.156719 | 
2025-12-05 15:20:52.156787 | TASK [upload-logs : Upload logs to log server]
2025-12-05 15:20:52.819192 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-05 15:20:52.822399 | 
2025-12-05 15:20:52.822460 | LOOP [upload-logs : Compress console log and json output]
2025-12-05 15:20:52.873370 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:20:52.881948 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:20:52.891302 | 
2025-12-05 15:20:52.891495 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-05 15:20:52.951431 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:20:52.951792 | 
2025-12-05 15:20:52.956942 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:20:52.961813 | 
2025-12-05 15:20:52.961959 | LOOP [upload-logs : Upload console log and json output]