2025-10-03 12:44:33.188783 | Job console starting...
2025-10-03 12:44:33.206078 | Updating repositories
2025-10-03 12:44:33.244235 | Preparing job workspace
2025-10-03 12:44:36.852169 | Running Ansible setup...
2025-10-03 12:44:41.143084 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 12:44:41.814358 | 
2025-10-03 12:44:41.814523 | PLAY [localhost]
2025-10-03 12:44:41.824380 | 
2025-10-03 12:44:41.824457 | TASK [Gathering Facts]
2025-10-03 12:44:42.819587 | localhost | ok
2025-10-03 12:44:42.836590 | 
2025-10-03 12:44:42.836713 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 12:44:43.347797 | localhost -> localhost | changed
2025-10-03 12:44:43.354553 | 
2025-10-03 12:44:43.354623 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 12:44:44.310230 | localhost -> localhost | changed
2025-10-03 12:44:44.321075 | 
2025-10-03 12:44:44.321144 | TASK [Setup log path fact]
2025-10-03 12:44:44.346729 | localhost | ok
2025-10-03 12:44:44.366753 | 
2025-10-03 12:44:44.366853 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 12:44:44.396682 | localhost | ok
2025-10-03 12:44:44.405556 | 
2025-10-03 12:44:44.405625 | TASK [emit-job-header : Print job information]
2025-10-03 12:44:44.462142 | # Job Information
2025-10-03 12:44:44.462330 | Ansible Version: 2.15.12
2025-10-03 12:44:44.462355 | Job: cifmw-molecule-ci_dcn_site
2025-10-03 12:44:44.462375 | Pipeline: github-check
2025-10-03 12:44:44.462392 | Executor: ze02.softwarefactory-project.io
2025-10-03 12:44:44.462410 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366
2025-10-03 12:44:44.462429 | Log URL (when completed): https://logserver.rdoproject.org/9e4/rdoproject.org/9e4a9e04e67740919a6186a8b948e545/
2025-10-03 12:44:44.462447 | Event ID: 8a294f00-a056-11f0-8eee-1e8238c96249
2025-10-03 12:44:44.466944 | 
2025-10-03 12:44:44.467012 | LOOP [emit-job-header : Print node information]
2025-10-03 12:44:44.600577 | localhost | ok:
2025-10-03 12:44:44.600924 | localhost | # Node Information
2025-10-03 12:44:44.600958 | localhost | Inventory Hostname: controller
2025-10-03 12:44:44.600983 | localhost | Hostname: np0005468860
2025-10-03 12:44:44.601002 | localhost | Username: zuul
2025-10-03 12:44:44.601021 | localhost | Distro: CentOS 9
2025-10-03 12:44:44.601041 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-03 12:44:44.601065 | localhost | Region: RegionOne
2025-10-03 12:44:44.601093 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-03 12:44:44.601122 | localhost | Product Name: OpenStack Nova
2025-10-03 12:44:44.601144 | localhost | Interface IP: 38.102.83.163
2025-10-03 12:44:44.654718 | 
2025-10-03 12:44:44.654878 | PLAY [all]
2025-10-03 12:44:44.662759 | 
2025-10-03 12:44:44.662826 | TASK [Gather network facts]
2025-10-03 12:44:45.211066 | controller | ok
2025-10-03 12:44:45.246195 | 
2025-10-03 12:44:45.246361 | TASK [include_role : start-zuul-console]
2025-10-03 12:44:45.270407 | controller | ok
2025-10-03 12:44:45.288117 | 
2025-10-03 12:44:45.288250 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 12:44:45.705247 | controller | ok
2025-10-03 12:44:45.718841 | 
2025-10-03 12:44:45.719029 | TASK [include_role : add-build-sshkey]
2025-10-03 12:44:45.762737 | controller | ok
2025-10-03 12:44:45.787930 | 
2025-10-03 12:44:45.788026 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 12:44:46.028268 | controller -> localhost | ok
2025-10-03 12:44:46.036223 | 
2025-10-03 12:44:46.036291 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 12:44:46.067468 | controller | ok
2025-10-03 12:44:46.081147 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 12:44:46.087530 | 
2025-10-03 12:44:46.087617 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 12:44:46.775005 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 12:44:46.775214 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/9e4a9e04e67740919a6186a8b948e545_id_rsa.
2025-10-03 12:44:46.775266 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/9e4a9e04e67740919a6186a8b948e545_id_rsa.pub.
2025-10-03 12:44:46.775290 | controller -> localhost | The key fingerprint is:
2025-10-03 12:44:46.775310 | controller -> localhost | SHA256:1P+aT0bw43ch/o7mnD5oGoyvZEgHj3cTYtRF8fY9VUw zuul-build-sshkey
2025-10-03 12:44:46.775329 | controller -> localhost | The key's randomart image is:
2025-10-03 12:44:46.775347 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 12:44:46.775364 | controller -> localhost | |       .. o+.  oE|
2025-10-03 12:44:46.775381 | controller -> localhost | |      .  o  .   o|
2025-10-03 12:44:46.775399 | controller -> localhost | |     . o... .o  .|
2025-10-03 12:44:46.775416 | controller -> localhost | |      =.. ...o. o|
2025-10-03 12:44:46.775433 | controller -> localhost | |     o +So  ..++.|
2025-10-03 12:44:46.775450 | controller -> localhost | |    . + + . .+..o|
2025-10-03 12:44:46.775467 | controller -> localhost | |     . + o  ..= o|
2025-10-03 12:44:46.775486 | controller -> localhost | |      o . .o.B+..|
2025-10-03 12:44:46.775503 | controller -> localhost | |       ..oo *B+o |
2025-10-03 12:44:46.775520 | controller -> localhost | +----[SHA256]-----+
2025-10-03 12:44:46.775565 | controller -> localhost | ok: Runtime: 0:00:00.259977
2025-10-03 12:44:46.781574 | 
2025-10-03 12:44:46.781637 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 12:44:46.813192 | controller | ok
2025-10-03 12:44:46.824141 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 12:44:46.832601 | 
2025-10-03 12:44:46.832706 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 12:44:46.846930 | controller | skipping: Conditional result was False
2025-10-03 12:44:46.854798 | 
2025-10-03 12:44:46.854929 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 12:44:47.359437 | controller | changed
2025-10-03 12:44:47.364478 | 
2025-10-03 12:44:47.364541 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 12:44:47.661499 | controller | ok
2025-10-03 12:44:47.666791 | 
2025-10-03 12:44:47.666875 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 12:44:48.466345 | controller | changed
2025-10-03 12:44:48.471383 | 
2025-10-03 12:44:48.471446 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 12:44:49.202163 | controller | changed
2025-10-03 12:44:49.207422 | 
2025-10-03 12:44:49.207488 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 12:44:49.233008 | controller | skipping: Conditional result was False
2025-10-03 12:44:49.239813 | 
2025-10-03 12:44:49.239883 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 12:44:49.686891 | controller -> localhost | changed
2025-10-03 12:44:49.700443 | 
2025-10-03 12:44:49.700516 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 12:44:50.034141 | controller -> localhost | Identity added: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/9e4a9e04e67740919a6186a8b948e545_id_rsa (zuul-build-sshkey)
2025-10-03 12:44:50.034467 | controller -> localhost | ok: Runtime: 0:00:00.012264
2025-10-03 12:44:50.041114 | 
2025-10-03 12:44:50.041175 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 12:44:50.474397 | controller | ok
2025-10-03 12:44:50.484778 | 
2025-10-03 12:44:50.484846 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 12:44:50.508656 | controller | skipping: Conditional result was False
2025-10-03 12:44:50.519580 | 
2025-10-03 12:44:50.519660 | TASK [include_role : validate-host]
2025-10-03 12:44:50.539783 | controller | ok
2025-10-03 12:44:50.560077 | 
2025-10-03 12:44:50.560144 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 12:44:50.599854 | controller | ok
2025-10-03 12:44:50.604717 | 
2025-10-03 12:44:50.604778 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 12:44:50.960244 | controller -> localhost | ok
2025-10-03 12:44:50.966574 | 
2025-10-03 12:44:50.966637 | TASK [validate-host : Collect information about the host]
2025-10-03 12:44:52.018170 | controller | ok
2025-10-03 12:44:52.032892 | 
2025-10-03 12:44:52.033180 | TASK [validate-host : Sanitize hostname]
2025-10-03 12:44:52.084102 | controller | ok
2025-10-03 12:44:52.090910 | 
2025-10-03 12:44:52.090975 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 12:44:52.717186 | controller -> localhost | changed
2025-10-03 12:44:52.727402 | 
2025-10-03 12:44:52.727483 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 12:44:53.180137 | controller | ok
2025-10-03 12:44:53.193966 | 
2025-10-03 12:44:53.194040 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 12:44:53.868868 | controller -> localhost | changed
2025-10-03 12:44:53.882038 | 
2025-10-03 12:44:53.882119 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 12:44:53.929209 | controller | skipping: Conditional result was False
2025-10-03 12:44:53.937742 | 
2025-10-03 12:44:53.937805 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 12:44:53.991875 | controller | skipping: Conditional result was False
2025-10-03 12:44:53.997738 | 
2025-10-03 12:44:53.997808 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 12:44:54.287847 | controller | ok: "logs"
2025-10-03 12:44:54.288132 | controller | ok: All items complete
2025-10-03 12:44:54.288160 | 
2025-10-03 12:44:54.492428 | controller | ok: "artifacts"
2025-10-03 12:44:54.679687 | controller | ok: "docs"
2025-10-03 12:44:54.688937 | 
2025-10-03 12:44:54.689100 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 12:44:55.009196 | controller | changed: "logs"
2025-10-03 12:44:55.252551 | controller | changed: "artifacts"
2025-10-03 12:44:55.513391 | controller | changed: "docs"
2025-10-03 12:44:55.553013 | 
2025-10-03 12:44:55.553100 | PLAY RECAP
2025-10-03 12:44:55.553143 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 12:44:55.553168 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 12:44:55.553185 | 
2025-10-03 12:44:55.716218 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 12:44:55.717222 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 12:44:56.621828 | 
2025-10-03 12:44:56.621993 | PLAY [localhost]
2025-10-03 12:44:56.642682 | 
2025-10-03 12:44:56.642775 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-03 12:44:57.365766 | localhost | ok
2025-10-03 12:44:57.372993 | 
2025-10-03 12:44:57.373076 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-03 12:44:58.683160 | localhost | changed
2025-10-03 12:44:58.762206 | 
2025-10-03 12:44:58.762381 | PLAY [all]
2025-10-03 12:44:58.798747 | 
2025-10-03 12:44:58.798844 | TASK [include_role : prepare-workspace]
2025-10-03 12:44:58.862806 | controller | ok
2025-10-03 12:44:58.920909 | 
2025-10-03 12:44:58.921060 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 12:44:59.370806 | controller | ok
2025-10-03 12:44:59.384755 | 
2025-10-03 12:44:59.385434 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 12:45:01.418938 | controller | Output suppressed because no_log was given
2025-10-03 12:45:01.437383 | 
2025-10-03 12:45:01.437573 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 12:45:01.772395 | controller | changed: "logs"
2025-10-03 12:45:02.010007 | controller | changed: "artifacts"
2025-10-03 12:45:02.232054 | controller | changed: "docs"
2025-10-03 12:45:02.249415 | 
2025-10-03 12:45:02.249515 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 12:45:02.595534 | controller | changed: "logs"
2025-10-03 12:45:02.595838 | controller | changed: All items complete
2025-10-03 12:45:02.595865 | 
2025-10-03 12:45:02.840280 | controller | changed: "artifacts"
2025-10-03 12:45:03.050260 | controller | changed: "docs"
2025-10-03 12:45:03.069074 | 
2025-10-03 12:45:03.069220 | TASK [Check if worker can sudo]
2025-10-03 12:45:03.606584 | controller | ok: Runtime: 0:00:00.062710
2025-10-03 12:45:03.616481 | 
2025-10-03 12:45:03.616694 | TASK [configure-mirrors : Gather needed facts]
2025-10-03 12:45:03.738355 | controller | skipping: Conditional result was False
2025-10-03 12:45:03.745358 | 
2025-10-03 12:45:03.745427 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-03 12:45:03.893318 | controller | ok
2025-10-03 12:45:03.903660 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-03 12:45:03.910522 | 
2025-10-03 12:45:03.910584 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-03 12:45:04.206408 | controller | ok
2025-10-03 12:45:04.215386 | 
2025-10-03 12:45:04.215455 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-03 12:45:04.351018 | controller | ok: "/var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-03 12:45:04.368709 | 
2025-10-03 12:45:04.368853 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-03 12:45:05.271115 | controller | changed
2025-10-03 12:45:05.276867 | 
2025-10-03 12:45:05.276934 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-03 12:45:05.344896 | controller | ok: "/var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-03 12:45:05.345076 | controller | ok: All items complete
2025-10-03 12:45:05.345102 | 
2025-10-03 12:45:05.389080 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-03 12:45:05.395751 | 
2025-10-03 12:45:05.395820 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-03 12:45:06.343207 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-03 12:45:07.168127 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-03 12:45:07.185763 | 
2025-10-03 12:45:07.185865 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-03 12:45:07.634068 | controller | changed: section and option added
2025-10-03 12:45:07.700813 | 
2025-10-03 12:45:07.700995 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-03 12:45:08.582063 | controller | 29 files removed
2025-10-03 12:45:08.582417 | controller | ok: Item: dnf clean all Runtime: 0:00:00.500163
2025-10-03 12:45:08.582475 | controller | changed: All items complete
2025-10-03 12:45:08.582503 | 
2025-10-03 12:45:19.658934 | 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 12:45:19.659035 | controller | DNF version: 4.14.0
2025-10-03 12:45:19.659059 | controller | cachedir: /var/cache/dnf
2025-10-03 12:45:19.659079 | controller | Making cache files for all metadata files.
2025-10-03 12:45:19.659097 | controller | baseos: has expired and will be refreshed.
2025-10-03 12:45:19.659114 | controller | appstream: has expired and will be refreshed.
2025-10-03 12:45:19.659131 | controller | crb: has expired and will be refreshed.
2025-10-03 12:45:19.659157 | controller | extras-common: has expired and will be refreshed.
2025-10-03 12:45:19.659173 | controller | repo: downloading from remote: baseos
2025-10-03 12:45:19.659190 | controller | CentOS Stream 9 - BaseOS                         65 MB/s | 8.8 MB     00:00
2025-10-03 12:45:19.659206 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-03 12:45:19.659223 | controller | repo: downloading from remote: appstream
2025-10-03 12:45:19.659239 | controller | CentOS Stream 9 - AppStream                      65 MB/s |  25 MB     00:00
2025-10-03 12:45:19.659254 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-03 12:45:19.659270 | controller | repo: downloading from remote: crb
2025-10-03 12:45:19.659286 | controller | CentOS Stream 9 - CRB                            57 MB/s | 7.1 MB     00:00
2025-10-03 12:45:19.659302 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-03 12:45:19.659318 | controller | repo: downloading from remote: extras-common
2025-10-03 12:45:19.659335 | controller | CentOS Stream 9 - Extras packages               740 kB/s |  20 kB     00:00
2025-10-03 12:45:19.659351 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-03 12:45:19.659367 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-03 12:45:19.659383 | controller | Completion plugin: Generating completion cache...
2025-10-03 12:45:19.659399 | controller | Metadata cache created.
2025-10-03 12:45:19.659425 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.818948
2025-10-03 12:45:19.713656 | 
2025-10-03 12:45:19.713810 | PLAY RECAP
2025-10-03 12:45:19.713897 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 12:45:19.713925 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 12:45:19.713943 | 
2025-10-03 12:45:19.887307 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 12:45:19.888266 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 12:45:20.490330 | 
2025-10-03 12:45:20.490484 | PLAY [all]
2025-10-03 12:45:20.515025 | 
2025-10-03 12:45:20.515169 | TASK [Install binary dependencies]
2025-10-03 12:45:20.566022 | controller | ok
2025-10-03 12:45:20.586822 | 
2025-10-03 12:45:20.586905 | TASK [bindep : Include find tasks]
2025-10-03 12:45:20.616494 | controller | ok
2025-10-03 12:45:20.624746 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-03 12:45:20.631168 | 
2025-10-03 12:45:20.631237 | TASK [bindep : Look for bindep.txt]
2025-10-03 12:45:21.059118 | controller | ok
2025-10-03 12:45:21.066917 | 
2025-10-03 12:45:21.067004 | TASK [bindep : Define bindep_file fact]
2025-10-03 12:45:21.098390 | controller | ok
2025-10-03 12:45:21.105757 | 
2025-10-03 12:45:21.105845 | TASK [bindep : Look for other-requirements.txt]
2025-10-03 12:45:21.132417 | controller | skipping: Conditional result was False
2025-10-03 12:45:21.141013 | 
2025-10-03 12:45:21.141126 | TASK [bindep : Define bindep_file fact]
2025-10-03 12:45:21.167699 | controller | skipping: Conditional result was False
2025-10-03 12:45:21.174252 | 
2025-10-03 12:45:21.174335 | TASK [bindep : Look for bindep fallback file]
2025-10-03 12:45:21.219549 | controller | skipping: Conditional result was False
2025-10-03 12:45:21.226226 | 
2025-10-03 12:45:21.226305 | TASK [bindep : Define bindep_file fact]
2025-10-03 12:45:21.251658 | controller | skipping: Conditional result was False
2025-10-03 12:45:21.258273 | 
2025-10-03 12:45:21.258358 | TASK [bindep : Include bindep tasks]
2025-10-03 12:45:21.290296 | controller | ok
2025-10-03 12:45:21.297567 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-03 12:45:21.305464 | 
2025-10-03 12:45:21.305548 | TASK [bindep : Look for bindep command]
2025-10-03 12:45:21.341016 | controller | skipping: Conditional result was False
2025-10-03 12:45:21.348295 | 
2025-10-03 12:45:21.348383 | TASK [bindep : Check for system bindep]
2025-10-03 12:45:21.882834 | controller | ok: Runtime: 0:00:00.006053
2025-10-03 12:45:21.904276 | 
2025-10-03 12:45:21.904436 | TASK [bindep : Define bindep_command fact]
2025-10-03 12:45:21.938443 | controller | skipping: Conditional result was False
2025-10-03 12:45:21.944834 | 
2025-10-03 12:45:21.944909 | TASK [bindep : Include install tasks]
2025-10-03 12:45:21.974792 | controller | ok
2025-10-03 12:45:21.987808 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-03 12:45:21.999959 | 
2025-10-03 12:45:22.000132 | TASK [bindep : Create temp dir for bindep]
2025-10-03 12:45:22.438724 | controller | changed
2025-10-03 12:45:22.460649 | 
2025-10-03 12:45:22.461004 | TASK [Ensure we have pip dependencies]
2025-10-03 12:45:22.523698 | controller | ok
2025-10-03 12:45:22.584852 | 
2025-10-03 12:45:22.584986 | TASK [ensure-pip : Check if pip is installed]
2025-10-03 08:45:22.921017 | controller | /usr/bin/pip3
2025-10-03 08:45:22.950584 | controller | /usr/bin/python3: No module named wheel
2025-10-03 12:45:23.132491 | controller | ok: Runtime: 0:00:00.041105
2025-10-03 12:45:23.146993 | 
2025-10-03 12:45:23.147139 | LOOP [ensure-pip : Install pip from packages]
2025-10-03 12:45:23.196211 | controller | ok: "/var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-03 12:45:23.208620 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-03 12:45:23.222982 | 
2025-10-03 12:45:23.223068 | TASK [ensure-pip : Install Python 3 pip]
2025-10-03 12:45:26.460836 | controller | changed
2025-10-03 12:45:26.471744 | 
2025-10-03 12:45:26.471834 | TASK [ensure-pip : Check for EPEL repository]
2025-10-03 12:45:26.540973 | controller | skipping: Conditional result was False
2025-10-03 12:45:26.547367 | 
2025-10-03 12:45:26.547433 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-03 12:45:26.622037 | controller | skipping: Conditional result was False
2025-10-03 12:45:26.628924 | 
2025-10-03 12:45:26.628992 | TASK [ensure-pip : Install Python 2 pip]
2025-10-03 12:45:26.697649 | controller | skipping: Conditional result was False
2025-10-03 12:45:26.704284 | 
2025-10-03 12:45:26.704377 | TASK [ensure-pip : Ensure setuptools]
2025-10-03 12:45:26.728616 | controller | skipping: Conditional result was False
2025-10-03 12:45:26.742564 | 
2025-10-03 12:45:26.744262 | TASK [ensure-pip : Check for ensurepip module]
2025-10-03 12:45:27.297407 | controller | skipping: Conditional result was False
2025-10-03 12:45:27.306644 | 
2025-10-03 12:45:27.306779 | TASK [ensure-pip : Ensure python3-venv]
2025-10-03 12:45:27.333691 | controller | skipping: Conditional result was False
2025-10-03 12:45:27.358771 | 
2025-10-03 12:45:27.358949 | TASK [ensure-pip : Install pip from source]
2025-10-03 12:45:27.383585 | controller | skipping: Conditional result was False
2025-10-03 12:45:27.390339 | 
2025-10-03 12:45:27.390419 | TASK [ensure-pip : Probe for venv python full path]
2025-10-03 08:45:27.735891 | controller | /usr/bin/python3
2025-10-03 12:45:27.952935 | controller | ok: Runtime: 0:00:00.010411
2025-10-03 12:45:27.958700 | 
2025-10-03 12:45:27.958764 | TASK [ensure-pip : Set host default]
2025-10-03 12:45:28.008779 | controller | ok
2025-10-03 12:45:28.016190 | 
2025-10-03 12:45:28.016328 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-03 12:45:28.107618 | controller | ok
2025-10-03 12:45:28.132103 | 
2025-10-03 12:45:28.132216 | TASK [bindep : Install bindep into temporary venv]
2025-10-03 12:45:32.958322 | controller | changed
2025-10-03 12:45:32.973861 | 
2025-10-03 12:45:32.973928 | TASK [bindep : Define bindep_command]
2025-10-03 12:45:33.023881 | controller | ok
2025-10-03 12:45:33.029596 | 
2025-10-03 12:45:33.029660 | LOOP [bindep : Include package tasks]
2025-10-03 12:45:33.118239 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-03 12:45:33.118521 | controller | ok: All items complete
2025-10-03 12:45:33.118552 | 
2025-10-03 12:45:33.128988 | controller | included: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-03 12:45:33.145953 | 
2025-10-03 12:45:33.146095 | TASK [bindep : Define bindep_run fact]
2025-10-03 12:45:33.175974 | controller | ok
2025-10-03 12:45:33.181501 | 
2025-10-03 12:45:33.181577 | TASK [bindep : Get list of packages to install from bindep]
2025-10-03 08:45:34.592406 | controller | podman
2025-10-03 08:45:34.625714 | controller | python3-jmespath
2025-10-03 08:45:34.625792 | controller | python3-libvirt
2025-10-03 08:45:34.625799 | controller | python3-lxml
2025-10-03 08:45:34.625809 | controller | python3-netaddr
2025-10-03 12:45:34.717460 | controller | ok: Runtime: 0:00:01.214441
2025-10-03 12:45:34.729489 | 
2025-10-03 12:45:34.729799 | TASK [bindep : Install distro packages from bindep]
2025-10-03 12:46:45.062122 | controller | changed
2025-10-03 12:46:45.069751 | 
2025-10-03 12:46:45.069839 | TASK [bindep : Check that packages are installed]
2025-10-03 12:46:46.610764 | controller | ok: Runtime: 0:00:01.102431
2025-10-03 12:46:46.626377 | 
2025-10-03 12:46:46.626531 | TASK [bindep : Fail if we cannot install all packages]
2025-10-03 12:46:46.666258 | controller | skipping: Conditional result was False
2025-10-03 12:46:46.682836 | 
2025-10-03 12:46:46.682939 | TASK [Run test-setup role]
2025-10-03 12:46:46.720399 | controller | ok
2025-10-03 12:46:46.752507 | 
2025-10-03 12:46:46.752709 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-03 12:46:47.021327 | controller | ok
2025-10-03 12:46:47.027064 | 
2025-10-03 12:46:47.027150 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-03 12:46:47.559629 | controller | skipping: Conditional result was False
2025-10-03 12:46:47.588229 | 
2025-10-03 12:46:47.588332 | TASK [bindep : Remove bindep temp dir]
2025-10-03 12:46:48.003760 | controller | ok
2025-10-03 12:46:48.028783 | 
2025-10-03 12:46:48.028892 | PLAY RECAP
2025-10-03 12:46:48.028955 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-03 12:46:48.028984 | 
2025-10-03 12:46:48.166216 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 12:46:48.167262 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 12:46:48.779052 | 
2025-10-03 12:46:48.779187 | PLAY [all]
2025-10-03 12:46:48.799097 | 
2025-10-03 12:46:48.799176 | TASK [Abort when test_command variable is undefined]
2025-10-03 12:46:48.834977 | controller | skipping: Conditional result was False
2025-10-03 12:46:48.841597 | 
2025-10-03 12:46:48.841693 | TASK [Convert test_command to list]
2025-10-03 12:46:48.890162 | controller | skipping: Conditional result was False
2025-10-03 12:46:48.898474 | 
2025-10-03 12:46:48.898545 | TASK [Use test_command list]
2025-10-03 12:46:48.960785 | controller | ok
2025-10-03 12:46:48.966586 | 
2025-10-03 12:46:48.966652 | LOOP [Run test_command]
2025-10-03 12:46:49.389265 | controller | no check to run
2025-10-03 12:46:49.389774 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006471
2025-10-03 12:46:49.444042 | 
2025-10-03 12:46:49.444243 | PLAY RECAP
2025-10-03 12:46:49.444331 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 12:46:49.444375 | 
2025-10-03 12:46:49.620113 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 12:46:49.622195 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 12:46:50.256467 | 
2025-10-03 12:46:50.256606 | PLAY [all]
2025-10-03 12:46:50.278996 | 
2025-10-03 12:46:50.279175 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-03 12:46:50.636053 | controller | changed: non-zero return code
2025-10-03 12:46:50.641643 | 
2025-10-03 12:46:50.641736 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-03 12:46:50.668055 | controller | skipping: Conditional result was False
2025-10-03 12:46:50.674437 | 
2025-10-03 12:46:50.674511 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-03 12:46:50.705255 | 
2025-10-03 12:46:50.705412 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-03 12:46:50.735499 | 
2025-10-03 12:46:50.735659 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-03 12:46:50.769988 | controller | skipping: Conditional result was False
2025-10-03 12:46:50.779765 | 
2025-10-03 12:46:50.779941 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-03 12:46:50.819978 | 
2025-10-03 12:46:50.820182 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-03 12:46:50.846281 | controller | skipping: Conditional result was False
2025-10-03 12:46:50.851992 | 
2025-10-03 12:46:50.852063 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-03 12:46:50.866640 | controller | skipping: Conditional result was False
2025-10-03 12:46:50.874304 | 
2025-10-03 12:46:50.874388 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-03 12:46:50.891793 | controller | skipping: Conditional result was False
2025-10-03 12:46:50.919623 | 
2025-10-03 12:46:50.919731 | PLAY RECAP
2025-10-03 12:46:50.919783 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-03 12:46:50.919803 | 
2025-10-03 12:46:51.048885 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 12:46:51.049905 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 12:46:51.648438 | 
2025-10-03 12:46:51.648608 | PLAY [all]
2025-10-03 12:46:51.668383 | 
2025-10-03 12:46:51.668528 | TASK [include_role : fetch-output]
2025-10-03 12:46:51.719247 | controller | ok
2025-10-03 12:46:51.737614 | 
2025-10-03 12:46:51.737725 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 12:46:51.805251 | controller | skipping: Conditional result was False
2025-10-03 12:46:51.815029 | 
2025-10-03 12:46:51.815130 | TASK [fetch-output : Set log path for single node]
2025-10-03 12:46:51.860932 | controller | ok
2025-10-03 12:46:51.878034 | 
2025-10-03 12:46:51.878157 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 12:46:52.297711 | controller -> localhost | ok: "/var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/logs"
2025-10-03 12:46:52.541459 | controller -> localhost | changed: "/var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/artifacts"
2025-10-03 12:46:52.789954 | controller -> localhost | changed: "/var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/docs"
2025-10-03 12:46:52.804619 | 
2025-10-03 12:46:52.804800 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 12:46:53.442195 | controller | changed: .d..t...... ./
2025-10-03 12:46:53.442431 | controller | changed: All items complete
2025-10-03 12:46:53.442458 | 
2025-10-03 12:46:53.940643 | controller | changed: .d..t...... ./
2025-10-03 12:46:54.422782 | controller | changed: .d..t...... ./
2025-10-03 12:46:54.440988 | 
2025-10-03 12:46:54.441144 | TASK [include_role : fetch-output-openshift]
2025-10-03 12:46:54.468134 | controller | skipping: Conditional result was False
2025-10-03 12:46:54.479612 | 
2025-10-03 12:46:54.479815 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 12:46:54.920377 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013394
2025-10-03 12:46:55.160073 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015159
2025-10-03 12:46:55.190207 | 
2025-10-03 12:46:55.190348 | PLAY [all]
2025-10-03 12:46:55.205328 | 
2025-10-03 12:46:55.205392 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 12:46:55.747566 | controller | changed
2025-10-03 12:46:55.772921 | 
2025-10-03 12:46:55.772982 | PLAY RECAP
2025-10-03 12:46:55.773025 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 12:46:55.773045 | 
2025-10-03 12:46:55.951396 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 12:46:55.952437 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 12:46:56.605384 | 
2025-10-03 12:46:56.605553 | PLAY [localhost]
2025-10-03 12:46:56.625044 | 
2025-10-03 12:46:56.625157 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 12:46:57.127096 | localhost | changed
2025-10-03 12:46:57.138369 | 
2025-10-03 12:46:57.138778 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 12:46:57.168384 | localhost | ok
2025-10-03 12:46:57.177054 | 
2025-10-03 12:46:57.177155 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 12:46:57.678156 | localhost | changed
2025-10-03 12:46:57.684205 | 
2025-10-03 12:46:57.684286 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 12:46:58.496141 | localhost | changed
2025-10-03 12:46:58.507042 | 
2025-10-03 12:46:58.507179 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 12:46:59.054794 | localhost | Identity added: /var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/tmp/ansible.vt1mwaqc (/var/lib/zuul/builds/9e4a9e04e67740919a6186a8b948e545/work/tmp/ansible.vt1mwaqc)
2025-10-03 12:46:59.055154 | localhost | ok: Runtime: 0:00:00.011817
2025-10-03 12:46:59.065572 | 
2025-10-03 12:46:59.065756 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 12:46:59.387559 | localhost | ok: Runtime: 0:00:00.011214
2025-10-03 12:46:59.395979 | 
2025-10-03 12:46:59.396096 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 12:46:59.459091 | localhost | changed
2025-10-03 12:46:59.463891 | 
2025-10-03 12:46:59.463959 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 12:46:59.917019 | localhost | changed
2025-10-03 12:46:59.954520 | 
2025-10-03 12:46:59.954601 | PLAY [localhost]
2025-10-03 12:46:59.971655 | 
2025-10-03 12:46:59.971775 | TASK [Generate bulk log download script]
2025-10-03 12:46:59.993372 | localhost | ok
2025-10-03 12:47:00.028858 | 
2025-10-03 12:47:00.029080 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 12:47:00.070420 | localhost | ok: All assertions passed
2025-10-03 12:47:00.075402 | 
2025-10-03 12:47:00.075466 | TASK [local-log-download : Create download script]
2025-10-03 12:47:00.477639 | localhost -> localhost | changed
2025-10-03 12:47:00.491949 | 
2025-10-03 12:47:00.492116 | TASK [Register quick-download link]
2025-10-03 12:47:00.521091 | localhost | ok
2025-10-03 12:47:00.610628 | 
2025-10-03 12:47:00.610832 | PLAY [logserver.rdoproject.org]
2025-10-03 12:47:00.631022 | 
2025-10-03 12:47:00.631162 | TASK [Set zuul-log-path fact]
2025-10-03 12:47:00.650345 | logserver.rdoproject.org | ok
2025-10-03 12:47:00.660658 | 
2025-10-03 12:47:00.660776 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 12:47:00.689031 | logserver.rdoproject.org | ok
2025-10-03 12:47:00.694476 | 
2025-10-03 12:47:00.694541 | TASK [upload-logs : Create log directories]
2025-10-03 12:47:01.380231 | logserver.rdoproject.org | changed
2025-10-03 12:47:01.389499 | 
2025-10-03 12:47:01.389762 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 12:47:01.692164 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007376
2025-10-03 12:47:01.699066 | 
2025-10-03 12:47:01.699186 | TASK [upload-logs : Upload logs to log server]
2025-10-03 12:47:02.398033 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 12:47:02.404837 | 
2025-10-03 12:47:02.404906 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 12:47:02.450575 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 12:47:02.459346 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 12:47:02.472835 | 
2025-10-03 12:47:02.472910 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 12:47:02.517092 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 12:47:02.517326 | 
2025-10-03 12:47:02.521087 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 12:47:02.532432 | 
2025-10-03 12:47:02.532504 | LOOP [upload-logs : Upload console log and json output]