2025-10-03 04:00:00.329701 | Job console starting...
2025-10-03 04:00:00.353333 | Updating repositories
2025-10-03 04:00:00.379064 | Preparing job workspace
2025-10-03 04:00:03.826427 | Running Ansible setup...
2025-10-03 04:00:07.889140 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 04:00:08.433293 | 
2025-10-03 04:00:08.433410 | PLAY [localhost]
2025-10-03 04:00:08.441908 | 
2025-10-03 04:00:08.441977 | TASK [Gathering Facts]
2025-10-03 04:00:09.414103 | localhost | ok
2025-10-03 04:00:09.435522 | 
2025-10-03 04:00:09.435761 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 04:00:09.868765 | localhost -> localhost | changed
2025-10-03 04:00:09.874573 | 
2025-10-03 04:00:09.874640 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 04:00:10.664614 | localhost -> localhost | changed
2025-10-03 04:00:10.673945 | 
2025-10-03 04:00:10.674082 | TASK [Setup log path fact]
2025-10-03 04:00:10.695516 | localhost | ok
2025-10-03 04:00:10.709536 | 
2025-10-03 04:00:10.709606 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 04:00:10.737045 | localhost | ok
2025-10-03 04:00:10.745313 | 
2025-10-03 04:00:10.745380 | TASK [emit-job-header : Print job information]
2025-10-03 04:00:10.796207 | # Job Information
2025-10-03 04:00:10.796378 | Ansible Version: 2.15.12
2025-10-03 04:00:10.796404 | Job: cifmw-molecule-ci_dcn_site
2025-10-03 04:00:10.796423 | Pipeline: github-check
2025-10-03 04:00:10.796441 | Executor: ze02.softwarefactory-project.io
2025-10-03 04:00:10.796458 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-03 04:00:10.796477 | Log URL (when completed): https://logserver.rdoproject.org/320/rdoproject.org/320702ba72dd468f9bb241c3d03db52b/
2025-10-03 04:00:10.796496 | Event ID: 3daecbd0-a00d-11f0-93f4-31ce34c57105
2025-10-03 04:00:10.801650 | 
2025-10-03 04:00:10.801749 | LOOP [emit-job-header : Print node information]
2025-10-03 04:00:10.928107 | localhost | ok:
2025-10-03 04:00:10.928457 | localhost | # Node Information
2025-10-03 04:00:10.928488 | localhost | Inventory Hostname: controller
2025-10-03 04:00:10.928511 | localhost | Hostname: np0005467681
2025-10-03 04:00:10.928530 | localhost | Username: zuul
2025-10-03 04:00:10.928551 | localhost | Distro: CentOS 9
2025-10-03 04:00:10.928568 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-03 04:00:10.928585 | localhost | Region: RegionOne
2025-10-03 04:00:10.928601 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-03 04:00:10.928617 | localhost | Product Name: OpenStack Nova
2025-10-03 04:00:10.928633 | localhost | Interface IP: 38.102.83.12
2025-10-03 04:00:10.957285 | 
2025-10-03 04:00:10.957366 | PLAY [all]
2025-10-03 04:00:10.965764 | 
2025-10-03 04:00:10.965828 | TASK [Gather network facts]
2025-10-03 04:00:11.477105 | controller | ok
2025-10-03 04:00:11.520793 | 
2025-10-03 04:00:11.521054 | TASK [include_role : start-zuul-console]
2025-10-03 04:00:11.565204 | controller | ok
2025-10-03 04:00:11.579236 | 
2025-10-03 04:00:11.579300 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 04:00:12.076851 | controller | ok
2025-10-03 04:00:12.095437 | 
2025-10-03 04:00:12.095645 | TASK [include_role : add-build-sshkey]
2025-10-03 04:00:12.127064 | controller | ok
2025-10-03 04:00:12.140537 | 
2025-10-03 04:00:12.140606 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 04:00:12.506274 | controller -> localhost | ok
2025-10-03 04:00:12.514007 | 
2025-10-03 04:00:12.514072 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 04:00:12.548096 | controller | ok
2025-10-03 04:00:12.562181 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 04:00:12.568024 | 
2025-10-03 04:00:12.568098 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 04:00:13.831389 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 04:00:13.831590 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/320702ba72dd468f9bb241c3d03db52b_id_rsa.
2025-10-03 04:00:13.831623 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/320702ba72dd468f9bb241c3d03db52b_id_rsa.pub.
2025-10-03 04:00:13.831645 | controller -> localhost | The key fingerprint is:
2025-10-03 04:00:13.831686 | controller -> localhost | SHA256:AAwmRrkdSlnRw749/nl61v/9khO/icWh1Biy87dUxfU zuul-build-sshkey
2025-10-03 04:00:13.831730 | controller -> localhost | The key's randomart image is:
2025-10-03 04:00:13.831750 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 04:00:13.831768 | controller -> localhost | |oo*==           .|
2025-10-03 04:00:13.831786 | controller -> localhost | |.* ..=         .o|
2025-10-03 04:00:13.831804 | controller -> localhost | |. + o o    . .  E|
2025-10-03 04:00:13.831821 | controller -> localhost | | o . . .    o + .|
2025-10-03 04:00:13.831838 | controller -> localhost | |      o S  o o o.|
2025-10-03 04:00:13.831855 | controller -> localhost | |     . o    + + o|
2025-10-03 04:00:13.831872 | controller -> localhost | |      . .   .o O |
2025-10-03 04:00:13.831891 | controller -> localhost | |       .  .+ .O =|
2025-10-03 04:00:13.831909 | controller -> localhost | |        .+=  ..BB|
2025-10-03 04:00:13.831926 | controller -> localhost | +----[SHA256]-----+
2025-10-03 04:00:13.831971 | controller -> localhost | ok: Runtime: 0:00:00.384155
2025-10-03 04:00:13.838292 | 
2025-10-03 04:00:13.838354 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 04:00:13.870577 | controller | ok
2025-10-03 04:00:13.884807 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 04:00:13.895382 | 
2025-10-03 04:00:13.895450 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 04:00:13.924042 | controller | skipping: Conditional result was False
2025-10-03 04:00:13.932066 | 
2025-10-03 04:00:13.932136 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 04:00:14.529594 | controller | changed
2025-10-03 04:00:14.537058 | 
2025-10-03 04:00:14.537151 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 04:00:14.814322 | controller | ok
2025-10-03 04:00:14.825103 | 
2025-10-03 04:00:14.825194 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 04:00:15.687637 | controller | changed
2025-10-03 04:00:15.694582 | 
2025-10-03 04:00:15.694736 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 04:00:16.642966 | controller | changed
2025-10-03 04:00:16.649938 | 
2025-10-03 04:00:16.650004 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 04:00:16.674079 | controller | skipping: Conditional result was False
2025-10-03 04:00:16.680611 | 
2025-10-03 04:00:16.680694 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 04:00:17.113487 | controller -> localhost | changed
2025-10-03 04:00:17.124917 | 
2025-10-03 04:00:17.124999 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 04:00:17.414106 | controller -> localhost | Identity added: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/320702ba72dd468f9bb241c3d03db52b_id_rsa (zuul-build-sshkey)
2025-10-03 04:00:17.414369 | controller -> localhost | ok: Runtime: 0:00:00.016918
2025-10-03 04:00:17.422079 | 
2025-10-03 04:00:17.422143 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 04:00:17.866162 | controller | ok
2025-10-03 04:00:17.878515 | 
2025-10-03 04:00:17.878592 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 04:00:17.942099 | controller | skipping: Conditional result was False
2025-10-03 04:00:17.956697 | 
2025-10-03 04:00:17.956763 | TASK [include_role : validate-host]
2025-10-03 04:00:17.989444 | controller | ok
2025-10-03 04:00:18.016054 | 
2025-10-03 04:00:18.016142 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 04:00:18.046470 | controller | ok
2025-10-03 04:00:18.053418 | 
2025-10-03 04:00:18.053481 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 04:00:18.328240 | controller -> localhost | ok
2025-10-03 04:00:18.334346 | 
2025-10-03 04:00:18.334412 | TASK [validate-host : Collect information about the host]
2025-10-03 04:00:19.142816 | controller | ok
2025-10-03 04:00:19.155721 | 
2025-10-03 04:00:19.155810 | TASK [validate-host : Sanitize hostname]
2025-10-03 04:00:19.221771 | controller | ok
2025-10-03 04:00:19.229381 | 
2025-10-03 04:00:19.229471 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 04:00:19.742034 | controller -> localhost | changed
2025-10-03 04:00:19.748902 | 
2025-10-03 04:00:19.748971 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 04:00:20.205681 | controller | ok
2025-10-03 04:00:20.211364 | 
2025-10-03 04:00:20.211431 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 04:00:20.754096 | controller -> localhost | changed
2025-10-03 04:00:20.773653 | 
2025-10-03 04:00:20.773991 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 04:00:20.812974 | controller | skipping: Conditional result was False
2025-10-03 04:00:20.819405 | 
2025-10-03 04:00:20.819474 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 04:00:20.873759 | controller | skipping: Conditional result was False
2025-10-03 04:00:20.880630 | 
2025-10-03 04:00:20.880731 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 04:00:21.196526 | controller | ok: "logs"
2025-10-03 04:00:21.197287 | controller | ok: All items complete
2025-10-03 04:00:21.197316 | 
2025-10-03 04:00:21.481283 | controller | ok: "artifacts"
2025-10-03 04:00:21.708087 | controller | ok: "docs"
2025-10-03 04:00:21.723290 | 
2025-10-03 04:00:21.723447 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 04:00:22.071059 | controller | changed: "logs"
2025-10-03 04:00:22.284370 | controller | changed: "artifacts"
2025-10-03 04:00:22.541591 | controller | changed: "docs"
2025-10-03 04:00:22.573428 | 
2025-10-03 04:00:22.573640 | PLAY RECAP
2025-10-03 04:00:22.573715 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 04:00:22.573745 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 04:00:22.573763 | 
2025-10-03 04:00:22.749743 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 04:00:22.750789 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 04:00:23.737362 | 
2025-10-03 04:00:23.737507 | PLAY [localhost]
2025-10-03 04:00:23.759236 | 
2025-10-03 04:00:23.759353 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-03 04:00:24.482909 | localhost | ok
2025-10-03 04:00:24.492075 | 
2025-10-03 04:00:24.492166 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-03 04:00:25.732199 | localhost | changed
2025-10-03 04:00:25.757005 | 
2025-10-03 04:00:25.757215 | PLAY [all]
2025-10-03 04:00:25.778027 | 
2025-10-03 04:00:25.778099 | TASK [include_role : prepare-workspace]
2025-10-03 04:00:25.808312 | controller | ok
2025-10-03 04:00:25.823105 | 
2025-10-03 04:00:25.823174 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 04:00:26.301390 | controller | ok
2025-10-03 04:00:26.308010 | 
2025-10-03 04:00:26.308076 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 04:00:28.407999 | controller | Output suppressed because no_log was given
2025-10-03 04:00:28.418574 | 
2025-10-03 04:00:28.418642 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 04:00:28.731731 | controller | changed: "logs"
2025-10-03 04:00:28.944538 | controller | changed: "artifacts"
2025-10-03 04:00:29.165412 | controller | changed: "docs"
2025-10-03 04:00:29.176414 | 
2025-10-03 04:00:29.176575 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 04:00:29.452944 | controller | changed: "logs"
2025-10-03 04:00:29.453434 | controller | changed: All items complete
2025-10-03 04:00:29.453496 | 
2025-10-03 04:00:29.739026 | controller | changed: "artifacts"
2025-10-03 04:00:29.999270 | controller | changed: "docs"
2025-10-03 04:00:30.019355 | 
2025-10-03 04:00:30.019488 | TASK [Check if worker can sudo]
2025-10-03 04:00:31.076431 | controller | ok: Runtime: 0:00:00.114340
2025-10-03 04:00:31.090584 | 
2025-10-03 04:00:31.090763 | TASK [configure-mirrors : Gather needed facts]
2025-10-03 04:00:31.210882 | controller | skipping: Conditional result was False
2025-10-03 04:00:31.224352 | 
2025-10-03 04:00:31.224492 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-03 04:00:31.408247 | controller | ok
2025-10-03 04:00:31.424987 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-03 04:00:31.434819 | 
2025-10-03 04:00:31.434909 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-03 04:00:31.721837 | controller | ok
2025-10-03 04:00:31.732047 | 
2025-10-03 04:00:31.732132 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-03 04:00:31.793588 | controller | ok: "/var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-03 04:00:31.820050 | 
2025-10-03 04:00:31.820271 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-03 04:00:32.776457 | controller | changed
2025-10-03 04:00:32.789685 | 
2025-10-03 04:00:32.789783 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-03 04:00:32.863213 | controller | ok: "/var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-03 04:00:32.863474 | controller | ok: All items complete
2025-10-03 04:00:32.863501 | 
2025-10-03 04:00:32.937920 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-03 04:00:32.945654 | 
2025-10-03 04:00:32.945752 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-03 04:00:34.262966 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-03 04:00:35.312142 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-03 04:00:35.323023 | 
2025-10-03 04:00:35.323134 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-03 04:00:35.832098 | controller | changed: section and option added
2025-10-03 04:00:35.868516 | 
2025-10-03 04:00:35.868656 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-03 04:00:36.911963 | controller | 29 files removed
2025-10-03 04:00:36.912212 | controller | ok: Item: dnf clean all Runtime: 0:00:00.696121
2025-10-03 04:00:36.912253 | controller | changed: All items complete
2025-10-03 04:00:36.912274 | 
2025-10-03 04:00:47.915365 | 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 04:00:47.915500 | controller | DNF version: 4.14.0
2025-10-03 04:00:47.915524 | controller | cachedir: /var/cache/dnf
2025-10-03 04:00:47.915544 | controller | Making cache files for all metadata files.
2025-10-03 04:00:47.915563 | controller | baseos: has expired and will be refreshed.
2025-10-03 04:00:47.915580 | controller | appstream: has expired and will be refreshed.
2025-10-03 04:00:47.915597 | controller | crb: has expired and will be refreshed.
2025-10-03 04:00:47.915625 | controller | extras-common: has expired and will be refreshed.
2025-10-03 04:00:47.915642 | controller | repo: downloading from remote: baseos
2025-10-03 04:00:47.915659 | controller | CentOS Stream 9 - BaseOS                         68 MB/s | 8.8 MB     00:00
2025-10-03 04:00:47.915699 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-03 04:00:47.915721 | controller | repo: downloading from remote: appstream
2025-10-03 04:00:47.915739 | controller | CentOS Stream 9 - AppStream                      80 MB/s |  25 MB     00:00
2025-10-03 04:00:47.915755 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-03 04:00:47.915771 | controller | repo: downloading from remote: crb
2025-10-03 04:00:47.915787 | controller | CentOS Stream 9 - CRB                            70 MB/s | 7.1 MB     00:00
2025-10-03 04:00:47.915804 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-03 04:00:47.915820 | controller | repo: downloading from remote: extras-common
2025-10-03 04:00:47.915836 | controller | CentOS Stream 9 - Extras packages               1.5 MB/s |  20 kB     00:00
2025-10-03 04:00:47.915852 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-03 04:00:47.915869 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-03 04:00:47.915885 | controller | Completion plugin: Generating completion cache...
2025-10-03 04:00:47.915901 | controller | Metadata cache created.
2025-10-03 04:00:47.915927 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.738012
2025-10-03 04:00:47.934192 | 
2025-10-03 04:00:47.934328 | PLAY RECAP
2025-10-03 04:00:47.934385 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 04:00:47.934419 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 04:00:47.934444 | 
2025-10-03 04:00:48.121072 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 04:00:48.121932 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 04:00:48.690031 | 
2025-10-03 04:00:48.690213 | PLAY [all]
2025-10-03 04:00:48.710931 | 
2025-10-03 04:00:48.711007 | TASK [Install binary dependencies]
2025-10-03 04:00:48.751248 | controller | ok
2025-10-03 04:00:48.770103 | 
2025-10-03 04:00:48.770182 | TASK [bindep : Include find tasks]
2025-10-03 04:00:48.821840 | controller | ok
2025-10-03 04:00:48.832165 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-03 04:00:48.840227 | 
2025-10-03 04:00:48.840313 | TASK [bindep : Look for bindep.txt]
2025-10-03 04:00:49.242061 | controller | ok
2025-10-03 04:00:49.266410 | 
2025-10-03 04:00:49.266560 | TASK [bindep : Define bindep_file fact]
2025-10-03 04:00:49.321535 | controller | ok
2025-10-03 04:00:49.329113 | 
2025-10-03 04:00:49.329202 | TASK [bindep : Look for other-requirements.txt]
2025-10-03 04:00:49.353687 | controller | skipping: Conditional result was False
2025-10-03 04:00:49.360146 | 
2025-10-03 04:00:49.360220 | TASK [bindep : Define bindep_file fact]
2025-10-03 04:00:49.383812 | controller | skipping: Conditional result was False
2025-10-03 04:00:49.390215 | 
2025-10-03 04:00:49.390287 | TASK [bindep : Look for bindep fallback file]
2025-10-03 04:00:49.423886 | controller | skipping: Conditional result was False
2025-10-03 04:00:49.430047 | 
2025-10-03 04:00:49.430121 | TASK [bindep : Define bindep_file fact]
2025-10-03 04:00:49.454312 | controller | skipping: Conditional result was False
2025-10-03 04:00:49.460271 | 
2025-10-03 04:00:49.460336 | TASK [bindep : Include bindep tasks]
2025-10-03 04:00:49.505441 | controller | ok
2025-10-03 04:00:49.512516 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-03 04:00:49.520546 | 
2025-10-03 04:00:49.520608 | TASK [bindep : Look for bindep command]
2025-10-03 04:00:49.545911 | controller | skipping: Conditional result was False
2025-10-03 04:00:49.553030 | 
2025-10-03 04:00:49.553095 | TASK [bindep : Check for system bindep]
2025-10-03 04:00:50.084209 | controller | ok: Runtime: 0:00:00.005699
2025-10-03 04:00:50.090646 | 
2025-10-03 04:00:50.090734 | TASK [bindep : Define bindep_command fact]
2025-10-03 04:00:50.135910 | controller | skipping: Conditional result was False
2025-10-03 04:00:50.142560 | 
2025-10-03 04:00:50.142624 | TASK [bindep : Include install tasks]
2025-10-03 04:00:50.192577 | controller | ok
2025-10-03 04:00:50.200260 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-03 04:00:50.209369 | 
2025-10-03 04:00:50.209437 | TASK [bindep : Create temp dir for bindep]
2025-10-03 04:00:50.637366 | controller | changed
2025-10-03 04:00:50.649534 | 
2025-10-03 04:00:50.649708 | TASK [Ensure we have pip dependencies]
2025-10-03 04:00:50.678102 | controller | ok
2025-10-03 04:00:50.717233 | 
2025-10-03 04:00:50.717389 | TASK [ensure-pip : Check if pip is installed]
2025-10-03 00:00:51.015956 | controller | /usr/bin/pip3
2025-10-03 00:00:51.044621 | controller | /usr/bin/python3: No module named wheel
2025-10-03 04:00:51.253148 | controller | ok: Runtime: 0:00:00.041108
2025-10-03 04:00:51.266087 | 
2025-10-03 04:00:51.266226 | LOOP [ensure-pip : Install pip from packages]
2025-10-03 04:00:51.328905 | controller | ok: "/var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-03 04:00:51.359544 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-03 04:00:51.373992 | 
2025-10-03 04:00:51.374081 | TASK [ensure-pip : Install Python 3 pip]
2025-10-03 04:00:55.424553 | controller | changed
2025-10-03 04:00:55.433077 | 
2025-10-03 04:00:55.433171 | TASK [ensure-pip : Check for EPEL repository]
2025-10-03 04:00:55.489235 | controller | skipping: Conditional result was False
2025-10-03 04:00:55.498931 | 
2025-10-03 04:00:55.499031 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-03 04:00:55.545877 | controller | skipping: Conditional result was False
2025-10-03 04:00:55.560521 | 
2025-10-03 04:00:55.560820 | TASK [ensure-pip : Install Python 2 pip]
2025-10-03 04:00:55.609163 | controller | skipping: Conditional result was False
2025-10-03 04:00:55.622186 | 
2025-10-03 04:00:55.622330 | TASK [ensure-pip : Ensure setuptools]
2025-10-03 04:00:55.649764 | controller | skipping: Conditional result was False
2025-10-03 04:00:55.663716 | 
2025-10-03 04:00:55.663854 | TASK [ensure-pip : Check for ensurepip module]
2025-10-03 04:00:56.214203 | controller | skipping: Conditional result was False
2025-10-03 04:00:56.227715 | 
2025-10-03 04:00:56.227856 | TASK [ensure-pip : Ensure python3-venv]
2025-10-03 04:00:56.255265 | controller | skipping: Conditional result was False
2025-10-03 04:00:56.264797 | 
2025-10-03 04:00:56.264900 | TASK [ensure-pip : Install pip from source]
2025-10-03 04:00:56.299355 | controller | skipping: Conditional result was False
2025-10-03 04:00:56.315314 | 
2025-10-03 04:00:56.315419 | TASK [ensure-pip : Probe for venv python full path]
2025-10-03 00:00:56.613980 | controller | /usr/bin/python3
2025-10-03 04:00:56.861316 | controller | ok: Runtime: 0:00:00.008780
2025-10-03 04:00:56.874748 | 
2025-10-03 04:00:56.874931 | TASK [ensure-pip : Set host default]
2025-10-03 04:00:56.955295 | controller | ok
2025-10-03 04:00:56.966456 | 
2025-10-03 04:00:56.966630 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-03 04:00:57.042418 | controller | ok
2025-10-03 04:00:57.066306 | 
2025-10-03 04:00:57.066447 | TASK [bindep : Install bindep into temporary venv]
2025-10-03 04:01:01.316848 | controller | changed
2025-10-03 04:01:01.322566 | 
2025-10-03 04:01:01.322633 | TASK [bindep : Define bindep_command]
2025-10-03 04:01:01.370971 | controller | ok
2025-10-03 04:01:01.382254 | 
2025-10-03 04:01:01.382393 | LOOP [bindep : Include package tasks]
2025-10-03 04:01:01.460064 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-03 04:01:01.460613 | controller | ok: All items complete
2025-10-03 04:01:01.460764 | 
2025-10-03 04:01:01.487812 | controller | included: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-03 04:01:01.510777 | 
2025-10-03 04:01:01.510928 | TASK [bindep : Define bindep_run fact]
2025-10-03 04:01:01.554383 | controller | ok
2025-10-03 04:01:01.567216 | 
2025-10-03 04:01:01.567356 | TASK [bindep : Get list of packages to install from bindep]
2025-10-03 00:01:03.370628 | controller | podman
2025-10-03 00:01:03.432080 | controller | python3-jmespath
2025-10-03 00:01:03.432315 | controller | python3-libvirt
2025-10-03 00:01:03.432329 | controller | python3-lxml
2025-10-03 00:01:03.432338 | controller | python3-netaddr
2025-10-03 04:01:03.618227 | controller | ok: Runtime: 0:00:01.545883
2025-10-03 04:01:03.624132 | 
2025-10-03 04:01:03.624199 | TASK [bindep : Install distro packages from bindep]
2025-10-03 04:02:07.406496 | controller | changed
2025-10-03 04:02:07.418466 | 
2025-10-03 04:02:07.418601 | TASK [bindep : Check that packages are installed]
2025-10-03 04:02:09.470460 | controller | ok: Runtime: 0:00:01.427309
2025-10-03 04:02:09.482941 | 
2025-10-03 04:02:09.483082 | TASK [bindep : Fail if we cannot install all packages]
2025-10-03 04:02:09.520790 | controller | skipping: Conditional result was False
2025-10-03 04:02:09.544122 | 
2025-10-03 04:02:09.544257 | TASK [Run test-setup role]
2025-10-03 04:02:09.573234 | controller | ok
2025-10-03 04:02:09.602422 | 
2025-10-03 04:02:09.602550 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-03 04:02:09.892238 | controller | ok
2025-10-03 04:02:09.903982 | 
2025-10-03 04:02:09.904116 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-03 04:02:10.453580 | controller | skipping: Conditional result was False
2025-10-03 04:02:10.498489 | 
2025-10-03 04:02:10.498776 | TASK [bindep : Remove bindep temp dir]
2025-10-03 04:02:10.891917 | controller | ok
2025-10-03 04:02:10.912229 | 
2025-10-03 04:02:10.912331 | PLAY RECAP
2025-10-03 04:02:10.912387 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-03 04:02:10.912416 | 
2025-10-03 04:02:11.053162 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 04:02:11.054085 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 04:02:11.608075 | 
2025-10-03 04:02:11.608195 | PLAY [all]
2025-10-03 04:02:11.627743 | 
2025-10-03 04:02:11.627817 | TASK [Abort when test_command variable is undefined]
2025-10-03 04:02:11.662611 | controller | skipping: Conditional result was False
2025-10-03 04:02:11.668971 | 
2025-10-03 04:02:11.669050 | TASK [Convert test_command to list]
2025-10-03 04:02:11.723679 | controller | skipping: Conditional result was False
2025-10-03 04:02:11.731038 | 
2025-10-03 04:02:11.731119 | TASK [Use test_command list]
2025-10-03 04:02:11.790875 | controller | ok
2025-10-03 04:02:11.796217 | 
2025-10-03 04:02:11.796279 | LOOP [Run test_command]
2025-10-03 04:02:12.183147 | controller | no check to run
2025-10-03 04:02:12.183442 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005569
2025-10-03 04:02:12.205474 | 
2025-10-03 04:02:12.205594 | PLAY RECAP
2025-10-03 04:02:12.205637 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 04:02:12.205657 | 
2025-10-03 04:02:12.322613 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 04:02:12.324427 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 04:02:12.927077 | 
2025-10-03 04:02:12.927211 | PLAY [all]
2025-10-03 04:02:12.948164 | 
2025-10-03 04:02:12.948259 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-03 04:02:13.410755 | controller | changed: non-zero return code
2025-10-03 04:02:13.419413 | 
2025-10-03 04:02:13.419568 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-03 04:02:13.445152 | controller | skipping: Conditional result was False
2025-10-03 04:02:13.454968 | 
2025-10-03 04:02:13.455125 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-03 04:02:13.490547 | 
2025-10-03 04:02:13.490763 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-03 04:02:13.523247 | 
2025-10-03 04:02:13.523418 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-03 04:02:13.550238 | controller | skipping: Conditional result was False
2025-10-03 04:02:13.564047 | 
2025-10-03 04:02:13.564202 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-03 04:02:13.604920 | 
2025-10-03 04:02:13.605168 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-03 04:02:13.631596 | controller | skipping: Conditional result was False
2025-10-03 04:02:13.643544 | 
2025-10-03 04:02:13.643715 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-03 04:02:13.682653 | controller | skipping: Conditional result was False
2025-10-03 04:02:13.696088 | 
2025-10-03 04:02:13.696239 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-03 04:02:13.725935 | controller | skipping: Conditional result was False
2025-10-03 04:02:13.755852 | 
2025-10-03 04:02:13.755920 | PLAY RECAP
2025-10-03 04:02:13.755963 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-03 04:02:13.755983 | 
2025-10-03 04:02:13.863135 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 04:02:13.868093 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 04:02:14.458193 | 
2025-10-03 04:02:14.458322 | PLAY [all]
2025-10-03 04:02:14.477550 | 
2025-10-03 04:02:14.477644 | TASK [include_role : fetch-output]
2025-10-03 04:02:14.528647 | controller | ok
2025-10-03 04:02:14.551814 | 
2025-10-03 04:02:14.551930 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 04:02:14.639241 | controller | skipping: Conditional result was False
2025-10-03 04:02:14.655531 | 
2025-10-03 04:02:14.655717 | TASK [fetch-output : Set log path for single node]
2025-10-03 04:02:14.710028 | controller | ok
2025-10-03 04:02:14.717335 | 
2025-10-03 04:02:14.717432 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 04:02:15.154655 | controller -> localhost | ok: "/var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/logs"
2025-10-03 04:02:15.365084 | controller -> localhost | changed: "/var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/artifacts"
2025-10-03 04:02:15.591168 | controller -> localhost | changed: "/var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/docs"
2025-10-03 04:02:15.603602 | 
2025-10-03 04:02:15.603753 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 04:02:16.277395 | controller | changed: .d..t...... ./
2025-10-03 04:02:16.277806 | controller | changed: All items complete
2025-10-03 04:02:16.277881 | 
2025-10-03 04:02:16.863025 | controller | changed: .d..t...... ./
2025-10-03 04:02:17.419246 | controller | changed: .d..t...... ./
2025-10-03 04:02:17.447227 | 
2025-10-03 04:02:17.447447 | TASK [include_role : fetch-output-openshift]
2025-10-03 04:02:17.476419 | controller | skipping: Conditional result was False
2025-10-03 04:02:17.490113 | 
2025-10-03 04:02:17.490259 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 04:02:17.933977 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008817
2025-10-03 04:02:18.166198 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009736
2025-10-03 04:02:18.204817 | 
2025-10-03 04:02:18.204913 | PLAY [all]
2025-10-03 04:02:18.224969 | 
2025-10-03 04:02:18.225057 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 04:02:18.670477 | controller | changed
2025-10-03 04:02:18.693462 | 
2025-10-03 04:02:18.693512 | PLAY RECAP
2025-10-03 04:02:18.693552 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 04:02:18.693571 | 
2025-10-03 04:02:18.799112 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 04:02:18.799967 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 04:02:19.407372 | 
2025-10-03 04:02:19.407504 | PLAY [localhost]
2025-10-03 04:02:19.427035 | 
2025-10-03 04:02:19.427141 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 04:02:19.795880 | localhost | changed
2025-10-03 04:02:19.800873 | 
2025-10-03 04:02:19.800967 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 04:02:19.831816 | localhost | ok
2025-10-03 04:02:19.843059 | 
2025-10-03 04:02:19.843146 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 04:02:20.221149 | localhost | changed
2025-10-03 04:02:20.229566 | 
2025-10-03 04:02:20.229720 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 04:02:20.951620 | localhost | changed
2025-10-03 04:02:20.957679 | 
2025-10-03 04:02:20.957753 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 04:02:21.474021 | localhost | Identity added: /var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/tmp/ansible.2eioyebd (/var/lib/zuul/builds/320702ba72dd468f9bb241c3d03db52b/work/tmp/ansible.2eioyebd)
2025-10-03 04:02:21.474287 | localhost | ok: Runtime: 0:00:00.015249
2025-10-03 04:02:21.480069 | 
2025-10-03 04:02:21.480137 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 04:02:21.754313 | localhost | ok: Runtime: 0:00:00.006132
2025-10-03 04:02:21.759555 | 
2025-10-03 04:02:21.759621 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 04:02:21.810307 | localhost | changed
2025-10-03 04:02:21.814698 | 
2025-10-03 04:02:21.814763 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 04:02:22.225877 | localhost | changed
2025-10-03 04:02:22.249567 | 
2025-10-03 04:02:22.249640 | PLAY [localhost]
2025-10-03 04:02:22.263101 | 
2025-10-03 04:02:22.263165 | TASK [Generate bulk log download script]
2025-10-03 04:02:22.281561 | localhost | ok
2025-10-03 04:02:22.294291 | 
2025-10-03 04:02:22.294355 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 04:02:22.323176 | localhost | ok: All assertions passed
2025-10-03 04:02:22.328180 | 
2025-10-03 04:02:22.328243 | TASK [local-log-download : Create download script]
2025-10-03 04:02:22.779895 | localhost -> localhost | changed
2025-10-03 04:02:22.790129 | 
2025-10-03 04:02:22.790197 | TASK [Register quick-download link]
2025-10-03 04:02:22.822166 | localhost | ok
2025-10-03 04:02:22.879250 | 
2025-10-03 04:02:22.879376 | PLAY [logserver.rdoproject.org]
2025-10-03 04:02:22.889079 | 
2025-10-03 04:02:22.889139 | TASK [Set zuul-log-path fact]
2025-10-03 04:02:22.905951 | logserver.rdoproject.org | ok
2025-10-03 04:02:22.915366 | 
2025-10-03 04:02:22.915429 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 04:02:22.952058 | logserver.rdoproject.org | ok
2025-10-03 04:02:22.958601 | 
2025-10-03 04:02:22.958684 | TASK [upload-logs : Create log directories]
2025-10-03 04:02:23.615597 | logserver.rdoproject.org | changed
2025-10-03 04:02:23.628635 | 
2025-10-03 04:02:23.628810 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 04:02:23.983473 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008503
2025-10-03 04:02:23.994264 | 
2025-10-03 04:02:23.994404 | TASK [upload-logs : Upload logs to log server]
2025-10-03 04:02:24.708637 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 04:02:24.715696 | 
2025-10-03 04:02:24.715853 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 04:02:24.787138 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 04:02:24.801157 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 04:02:24.813220 | 
2025-10-03 04:02:24.813595 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 04:02:24.877294 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 04:02:24.877684 | 
2025-10-03 04:02:24.888070 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 04:02:24.900535 | 
2025-10-03 04:02:24.900788 | LOOP [upload-logs : Upload console log and json output]