2025-10-13 06:53:46.372165 | Job console starting...
2025-10-13 06:53:46.390318 | Updating repositories
2025-10-13 06:53:46.447784 | Preparing job workspace
2025-10-13 06:53:52.231755 | Running Ansible setup...
2025-10-13 06:53:56.981776 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:53:57.901131 | 
2025-10-13 06:53:57.901290 | PLAY [localhost]
2025-10-13 06:53:57.923459 | 
2025-10-13 06:53:57.923567 | TASK [Gathering Facts]
2025-10-13 06:53:59.364255 | localhost | ok
2025-10-13 06:53:59.397606 | 
2025-10-13 06:53:59.397766 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 06:54:00.347181 | localhost -> localhost | changed
2025-10-13 06:54:00.357485 | 
2025-10-13 06:54:00.357625 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 06:54:01.820239 | localhost -> localhost | changed
2025-10-13 06:54:01.830561 | 
2025-10-13 06:54:01.830637 | TASK [Setup log path fact]
2025-10-13 06:54:01.880605 | localhost | ok
2025-10-13 06:54:01.935975 | 
2025-10-13 06:54:01.936155 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:54:02.039322 | localhost | ok
2025-10-13 06:54:02.066130 | 
2025-10-13 06:54:02.066264 | TASK [emit-job-header : Print job information]
2025-10-13 06:54:02.256126 | # Job Information
2025-10-13 06:54:02.256288 | Ansible Version: 2.15.12
2025-10-13 06:54:02.256314 | Job: cifmw-molecule-recognize_ssh_keypair
2025-10-13 06:54:02.256334 | Pipeline: github-check
2025-10-13 06:54:02.256352 | Executor: ze02.softwarefactory-project.io
2025-10-13 06:54:02.256370 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-13 06:54:02.256388 | Log URL (when completed): https://logserver.rdoproject.org/c4d/rdoproject.org/c4d4846d6c37475bab01a318a3ba828a/
2025-10-13 06:54:02.256406 | Event ID: 0a621880-a801-11f0-8fd5-3020d4b2b2c2
2025-10-13 06:54:02.260590 | 
2025-10-13 06:54:02.260658 | LOOP [emit-job-header : Print node information]
2025-10-13 06:54:02.619372 | localhost | ok:
2025-10-13 06:54:02.619547 | localhost | # Node Information
2025-10-13 06:54:02.619573 | localhost | Inventory Hostname: controller
2025-10-13 06:54:02.619600 | localhost | Hostname: np0005482624
2025-10-13 06:54:02.619619 | localhost | Username: zuul
2025-10-13 06:54:02.619639 | localhost | Distro: CentOS 9
2025-10-13 06:54:02.619657 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 06:54:02.619713 | localhost | Region: RegionOne
2025-10-13 06:54:02.619731 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 06:54:02.619748 | localhost | Product Name: OpenStack Nova
2025-10-13 06:54:02.619764 | localhost | Interface IP: 38.129.56.230
2025-10-13 06:54:02.665686 | 
2025-10-13 06:54:02.665789 | PLAY [all]
2025-10-13 06:54:02.685351 | 
2025-10-13 06:54:02.685500 | TASK [Gather network facts]
2025-10-13 06:54:03.233290 | controller | ok
2025-10-13 06:54:03.270657 | 
2025-10-13 06:54:03.270818 | TASK [include_role : start-zuul-console]
2025-10-13 06:54:03.322970 | controller | ok
2025-10-13 06:54:03.347083 | 
2025-10-13 06:54:03.347184 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 06:54:03.850185 | controller | ok
2025-10-13 06:54:03.867273 | 
2025-10-13 06:54:03.867377 | TASK [include_role : add-build-sshkey]
2025-10-13 06:54:03.913742 | controller | ok
2025-10-13 06:54:03.937697 | 
2025-10-13 06:54:03.939564 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 06:54:04.227714 | controller -> localhost | ok
2025-10-13 06:54:04.233417 | 
2025-10-13 06:54:04.233482 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 06:54:04.273612 | controller | ok
2025-10-13 06:54:04.295922 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 06:54:04.304034 | 
2025-10-13 06:54:04.304094 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 06:54:05.663059 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 06:54:05.663294 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/c4d4846d6c37475bab01a318a3ba828a_id_rsa.
2025-10-13 06:54:05.663340 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/c4d4846d6c37475bab01a318a3ba828a_id_rsa.pub.
2025-10-13 06:54:05.663364 | controller -> localhost | The key fingerprint is:
2025-10-13 06:54:05.663384 | controller -> localhost | SHA256:AK1xMzCXJnnl1i0HkrOvf8MOr9+lkigmaGW/y3GoIbM zuul-build-sshkey
2025-10-13 06:54:05.663403 | controller -> localhost | The key's randomart image is:
2025-10-13 06:54:05.663421 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 06:54:05.663439 | controller -> localhost | |    ++.oo..      |
2025-10-13 06:54:05.663458 | controller -> localhost | |    ++O.oo o     |
2025-10-13 06:54:05.663476 | controller -> localhost | |     B.oooo o    |
2025-10-13 06:54:05.663494 | controller -> localhost | |    .  o.  o     |
2025-10-13 06:54:05.663512 | controller -> localhost | |        S.       |
2025-10-13 06:54:05.663529 | controller -> localhost | |      o  ..      |
2025-10-13 06:54:05.663547 | controller -> localhost | |    o+..o.oo .  .|
2025-10-13 06:54:05.663566 | controller -> localhost | |    o+.+=o.o*. o |
2025-10-13 06:54:05.663583 | controller -> localhost | |   .E .o+=o=+oo  |
2025-10-13 06:54:05.663600 | controller -> localhost | +----[SHA256]-----+
2025-10-13 06:54:05.663684 | controller -> localhost | ok: Runtime: 0:00:00.387821
2025-10-13 06:54:05.669971 | 
2025-10-13 06:54:05.670037 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 06:54:05.720176 | controller | ok
2025-10-13 06:54:05.736541 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 06:54:05.757052 | 
2025-10-13 06:54:05.757201 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 06:54:05.813632 | controller | skipping: Conditional result was False
2025-10-13 06:54:05.819499 | 
2025-10-13 06:54:05.819569 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 06:54:06.544103 | controller | changed
2025-10-13 06:54:06.550176 | 
2025-10-13 06:54:06.550240 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 06:54:06.926726 | controller | ok
2025-10-13 06:54:06.931809 | 
2025-10-13 06:54:06.931872 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 06:54:07.942202 | controller | changed
2025-10-13 06:54:07.948024 | 
2025-10-13 06:54:07.948091 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 06:54:09.043237 | controller | changed
2025-10-13 06:54:09.049142 | 
2025-10-13 06:54:09.049227 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 06:54:09.117397 | controller | skipping: Conditional result was False
2025-10-13 06:54:09.123219 | 
2025-10-13 06:54:09.123285 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 06:54:09.666496 | controller -> localhost | changed
2025-10-13 06:54:09.678299 | 
2025-10-13 06:54:09.678370 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 06:54:10.257465 | controller -> localhost | Identity added: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/c4d4846d6c37475bab01a318a3ba828a_id_rsa (zuul-build-sshkey)
2025-10-13 06:54:10.258049 | controller -> localhost | ok: Runtime: 0:00:00.040852
2025-10-13 06:54:10.263930 | 
2025-10-13 06:54:10.263993 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 06:54:10.692301 | controller | ok
2025-10-13 06:54:10.701056 | 
2025-10-13 06:54:10.701131 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 06:54:10.750938 | controller | skipping: Conditional result was False
2025-10-13 06:54:10.794427 | 
2025-10-13 06:54:10.794543 | TASK [include_role : validate-host]
2025-10-13 06:54:10.824692 | controller | ok
2025-10-13 06:54:10.847381 | 
2025-10-13 06:54:10.847467 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 06:54:10.876288 | controller | ok
2025-10-13 06:54:10.880817 | 
2025-10-13 06:54:10.880876 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 06:54:11.220811 | controller -> localhost | ok
2025-10-13 06:54:11.227714 | 
2025-10-13 06:54:11.227791 | TASK [validate-host : Collect information about the host]
2025-10-13 06:54:12.059238 | controller | ok
2025-10-13 06:54:12.067945 | 
2025-10-13 06:54:12.068036 | TASK [validate-host : Sanitize hostname]
2025-10-13 06:54:12.118777 | controller | ok
2025-10-13 06:54:12.125592 | 
2025-10-13 06:54:12.125701 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 06:54:12.622926 | controller -> localhost | changed
2025-10-13 06:54:12.633947 | 
2025-10-13 06:54:12.634086 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 06:54:13.092401 | controller | ok
2025-10-13 06:54:13.100747 | 
2025-10-13 06:54:13.100839 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 06:54:13.502091 | controller -> localhost | changed
2025-10-13 06:54:13.511695 | 
2025-10-13 06:54:13.511758 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 06:54:13.535873 | controller | skipping: Conditional result was False
2025-10-13 06:54:13.541568 | 
2025-10-13 06:54:13.541634 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 06:54:13.555255 | controller | skipping: Conditional result was False
2025-10-13 06:54:13.565410 | 
2025-10-13 06:54:13.565485 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:54:13.869011 | controller | ok: "logs"
2025-10-13 06:54:13.869239 | controller | ok: All items complete
2025-10-13 06:54:13.869267 | 
2025-10-13 06:54:14.144146 | controller | ok: "artifacts"
2025-10-13 06:54:14.409302 | controller | ok: "docs"
2025-10-13 06:54:14.415619 | 
2025-10-13 06:54:14.415714 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:54:14.720823 | controller | changed: "logs"
2025-10-13 06:54:14.976575 | controller | changed: "artifacts"
2025-10-13 06:54:15.236600 | controller | changed: "docs"
2025-10-13 06:54:15.279501 | 
2025-10-13 06:54:15.279581 | PLAY RECAP
2025-10-13 06:54:15.279625 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 06:54:15.279652 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:54:15.279695 | 
2025-10-13 06:54:15.404860 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:54:15.405656 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:54:16.013965 | 
2025-10-13 06:54:16.014087 | PLAY [localhost]
2025-10-13 06:54:16.033331 | 
2025-10-13 06:54:16.033416 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 06:54:16.403423 | localhost | ok
2025-10-13 06:54:16.409345 | 
2025-10-13 06:54:16.409500 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 06:54:17.152216 | localhost | changed
2025-10-13 06:54:17.177046 | 
2025-10-13 06:54:17.177141 | PLAY [all]
2025-10-13 06:54:17.197187 | 
2025-10-13 06:54:17.197290 | TASK [include_role : prepare-workspace]
2025-10-13 06:54:17.229881 | controller | ok
2025-10-13 06:54:17.265636 | 
2025-10-13 06:54:17.265782 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 06:54:17.725774 | controller | ok
2025-10-13 06:54:17.761781 | 
2025-10-13 06:54:17.761928 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 06:54:19.620868 | controller | Output suppressed because no_log was given
2025-10-13 06:54:19.633737 | 
2025-10-13 06:54:19.633807 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:54:19.920554 | controller | changed: "logs"
2025-10-13 06:54:20.166039 | controller | changed: "artifacts"
2025-10-13 06:54:20.388731 | controller | changed: "docs"
2025-10-13 06:54:20.403657 | 
2025-10-13 06:54:20.403848 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:54:20.687072 | controller | changed: "logs"
2025-10-13 06:54:20.687310 | controller | changed: All items complete
2025-10-13 06:54:20.687337 | 
2025-10-13 06:54:20.941405 | controller | changed: "artifacts"
2025-10-13 06:54:21.169297 | controller | changed: "docs"
2025-10-13 06:54:21.191370 | 
2025-10-13 06:54:21.191524 | TASK [Check if worker can sudo]
2025-10-13 06:54:21.747973 | controller | ok: Runtime: 0:00:00.051082
2025-10-13 06:54:21.753943 | 
2025-10-13 06:54:21.754009 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 06:54:21.798555 | controller | skipping: Conditional result was False
2025-10-13 06:54:21.805558 | 
2025-10-13 06:54:21.805632 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 06:54:21.856547 | controller | ok
2025-10-13 06:54:21.865109 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 06:54:21.873845 | 
2025-10-13 06:54:21.873968 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 06:54:22.245153 | controller | ok
2025-10-13 06:54:22.250878 | 
2025-10-13 06:54:22.250939 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 06:54:22.324283 | controller | ok: "/var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 06:54:22.333857 | 
2025-10-13 06:54:22.333973 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 06:54:23.338034 | controller | changed
2025-10-13 06:54:23.355000 | 
2025-10-13 06:54:23.355115 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 06:54:23.441595 | controller | ok: "/var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 06:54:23.441769 | controller | ok: All items complete
2025-10-13 06:54:23.441795 | 
2025-10-13 06:54:23.487202 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 06:54:23.494138 | 
2025-10-13 06:54:23.494202 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 06:54:24.453570 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 06:54:25.369228 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 06:54:25.389170 | 
2025-10-13 06:54:25.389368 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 06:54:25.897882 | controller | changed: section and option added
2025-10-13 06:54:25.929879 | 
2025-10-13 06:54:25.930043 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 06:54:26.721628 | controller | 29 files removed
2025-10-13 06:54:26.721879 | controller | ok: Item: dnf clean all Runtime: 0:00:00.499768
2025-10-13 06:54:26.721928 | controller | changed: All items complete
2025-10-13 06:54:26.721949 | 
2025-10-13 06:54:37.369131 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-10-13 06:54:37.369706 | controller | DNF version: 4.14.0
2025-10-13 06:54:37.369750 | controller | cachedir: /var/cache/dnf
2025-10-13 06:54:37.369773 | controller | Making cache files for all metadata files.
2025-10-13 06:54:37.369847 | controller | baseos: has expired and will be refreshed.
2025-10-13 06:54:37.369877 | controller | appstream: has expired and will be refreshed.
2025-10-13 06:54:37.369895 | controller | crb: has expired and will be refreshed.
2025-10-13 06:54:37.369918 | controller | extras-common: has expired and will be refreshed.
2025-10-13 06:54:37.369934 | controller | repo: downloading from remote: baseos
2025-10-13 06:54:37.369976 | controller | CentOS Stream 9 - BaseOS                         65 MB/s | 8.8 MB     00:00
2025-10-13 06:54:37.370000 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 06:54:37.370018 | controller | repo: downloading from remote: appstream
2025-10-13 06:54:37.370034 | controller | CentOS Stream 9 - AppStream                      88 MB/s |  25 MB     00:00
2025-10-13 06:54:37.370063 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 06:54:37.370080 | controller | repo: downloading from remote: crb
2025-10-13 06:54:37.370096 | controller | CentOS Stream 9 - CRB                            71 MB/s | 7.2 MB     00:00
2025-10-13 06:54:37.370328 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 06:54:37.370360 | controller | repo: downloading from remote: extras-common
2025-10-13 06:54:37.370380 | controller | CentOS Stream 9 - Extras packages               575 kB/s |  20 kB     00:00
2025-10-13 06:54:37.370397 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 06:54:37.370414 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 06:54:37.370430 | controller | Completion plugin: Generating completion cache...
2025-10-13 06:54:37.370476 | controller | Metadata cache created.
2025-10-13 06:54:37.370505 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.362469
2025-10-13 06:54:37.393232 | 
2025-10-13 06:54:37.393334 | PLAY RECAP
2025-10-13 06:54:37.393376 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 06:54:37.393401 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:54:37.393419 | 
2025-10-13 06:54:37.591495 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:54:37.592314 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:54:38.217279 | 
2025-10-13 06:54:38.217402 | PLAY [all]
2025-10-13 06:54:38.245930 | 
2025-10-13 06:54:38.246076 | TASK [Install binary dependencies]
2025-10-13 06:54:38.296702 | controller | ok
2025-10-13 06:54:38.334959 | 
2025-10-13 06:54:38.335094 | TASK [bindep : Include find tasks]
2025-10-13 06:54:38.387478 | controller | ok
2025-10-13 06:54:38.395756 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 06:54:38.403879 | 
2025-10-13 06:54:38.404011 | TASK [bindep : Look for bindep.txt]
2025-10-13 06:54:38.880323 | controller | ok
2025-10-13 06:54:38.887095 | 
2025-10-13 06:54:38.887161 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:54:38.916566 | controller | ok
2025-10-13 06:54:38.921716 | 
2025-10-13 06:54:38.921779 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 06:54:38.935812 | controller | skipping: Conditional result was False
2025-10-13 06:54:38.942126 | 
2025-10-13 06:54:38.942206 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:54:38.970449 | controller | skipping: Conditional result was False
2025-10-13 06:54:38.976148 | 
2025-10-13 06:54:38.976213 | TASK [bindep : Look for bindep fallback file]
2025-10-13 06:54:39.000149 | controller | skipping: Conditional result was False
2025-10-13 06:54:39.006016 | 
2025-10-13 06:54:39.006083 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:54:39.031590 | controller | skipping: Conditional result was False
2025-10-13 06:54:39.038234 | 
2025-10-13 06:54:39.038303 | TASK [bindep : Include bindep tasks]
2025-10-13 06:54:39.069280 | controller | ok
2025-10-13 06:54:39.075943 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 06:54:39.084178 | 
2025-10-13 06:54:39.084238 | TASK [bindep : Look for bindep command]
2025-10-13 06:54:39.108547 | controller | skipping: Conditional result was False
2025-10-13 06:54:39.115164 | 
2025-10-13 06:54:39.115232 | TASK [bindep : Check for system bindep]
2025-10-13 06:54:39.647414 | controller | ok: Runtime: 0:00:00.007083
2025-10-13 06:54:39.655224 | 
2025-10-13 06:54:39.655302 | TASK [bindep : Define bindep_command fact]
2025-10-13 06:54:39.700109 | controller | skipping: Conditional result was False
2025-10-13 06:54:39.707242 | 
2025-10-13 06:54:39.707324 | TASK [bindep : Include install tasks]
2025-10-13 06:54:39.748369 | controller | ok
2025-10-13 06:54:39.758369 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 06:54:39.770084 | 
2025-10-13 06:54:39.770420 | TASK [bindep : Create temp dir for bindep]
2025-10-13 06:54:40.178299 | controller | changed
2025-10-13 06:54:40.185546 | 
2025-10-13 06:54:40.185606 | TASK [Ensure we have pip dependencies]
2025-10-13 06:54:40.231714 | controller | ok
2025-10-13 06:54:40.275750 | 
2025-10-13 06:54:40.275854 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 02:54:40.709873 | controller | /usr/bin/pip3
2025-10-13 02:54:40.755798 | controller | /usr/bin/python3: No module named wheel
2025-10-13 06:54:40.837715 | controller | ok: Runtime: 0:00:00.059582
2025-10-13 06:54:40.843449 | 
2025-10-13 06:54:40.843516 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 06:54:40.888816 | controller | ok: "/var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 06:54:40.898703 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 06:54:40.910563 | 
2025-10-13 06:54:40.910631 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 06:54:43.454741 | controller | changed
2025-10-13 06:54:43.462302 | 
2025-10-13 06:54:43.462369 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 06:54:43.548299 | controller | skipping: Conditional result was False
2025-10-13 06:54:43.555201 | 
2025-10-13 06:54:43.555269 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 06:54:43.603155 | controller | skipping: Conditional result was False
2025-10-13 06:54:43.611149 | 
2025-10-13 06:54:43.611217 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 06:54:43.658433 | controller | skipping: Conditional result was False
2025-10-13 06:54:43.667188 | 
2025-10-13 06:54:43.667286 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 06:54:43.697158 | controller | skipping: Conditional result was False
2025-10-13 06:54:43.705513 | 
2025-10-13 06:54:43.705591 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 06:54:44.244964 | controller | skipping: Conditional result was False
2025-10-13 06:54:44.255311 | 
2025-10-13 06:54:44.255410 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 06:54:44.280351 | controller | skipping: Conditional result was False
2025-10-13 06:54:44.288016 | 
2025-10-13 06:54:44.288131 | TASK [ensure-pip : Install pip from source]
2025-10-13 06:54:44.325576 | controller | skipping: Conditional result was False
2025-10-13 06:54:44.333207 | 
2025-10-13 06:54:44.333301 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 02:54:44.705875 | controller | /usr/bin/python3
2025-10-13 06:54:44.898732 | controller | ok: Runtime: 0:00:00.007927
2025-10-13 06:54:44.906470 | 
2025-10-13 06:54:44.906546 | TASK [ensure-pip : Set host default]
2025-10-13 06:54:44.971876 | controller | ok
2025-10-13 06:54:44.984477 | 
2025-10-13 06:54:44.984551 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 06:54:45.061793 | controller | ok
2025-10-13 06:54:45.079417 | 
2025-10-13 06:54:45.079487 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 06:54:49.406901 | controller | changed
2025-10-13 06:54:49.413064 | 
2025-10-13 06:54:49.413174 | TASK [bindep : Define bindep_command]
2025-10-13 06:54:49.469073 | controller | ok
2025-10-13 06:54:49.474414 | 
2025-10-13 06:54:49.474477 | LOOP [bindep : Include package tasks]
2025-10-13 06:54:49.612331 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 06:54:49.612496 | controller | ok: All items complete
2025-10-13 06:54:49.612521 | 
2025-10-13 06:54:49.625580 | controller | included: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 06:54:49.645865 | 
2025-10-13 06:54:49.645943 | TASK [bindep : Define bindep_run fact]
2025-10-13 06:54:49.702110 | controller | ok
2025-10-13 06:54:49.707286 | 
2025-10-13 06:54:49.707348 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 02:54:51.211958 | controller | podman
2025-10-13 02:54:51.250876 | controller | python3-jmespath
2025-10-13 02:54:51.250943 | controller | python3-libvirt
2025-10-13 02:54:51.250953 | controller | python3-lxml
2025-10-13 02:54:51.250962 | controller | python3-netaddr
2025-10-13 06:54:51.287535 | controller | ok: Runtime: 0:00:01.183846
2025-10-13 06:54:51.293103 | 
2025-10-13 06:54:51.293168 | TASK [bindep : Install distro packages from bindep]
2025-10-13 06:55:53.141797 | controller | changed
2025-10-13 06:55:53.148101 | 
2025-10-13 06:55:53.148161 | TASK [bindep : Check that packages are installed]
2025-10-13 06:55:54.688041 | controller | ok: Runtime: 0:00:01.095201
2025-10-13 06:55:54.693872 | 
2025-10-13 06:55:54.693937 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 06:55:54.717765 | controller | skipping: Conditional result was False
2025-10-13 06:55:54.728407 | 
2025-10-13 06:55:54.728474 | TASK [Run test-setup role]
2025-10-13 06:55:54.746515 | controller | ok
2025-10-13 06:55:54.763558 | 
2025-10-13 06:55:54.763623 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 06:55:54.984682 | controller | ok
2025-10-13 06:55:54.991145 | 
2025-10-13 06:55:54.991215 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 06:55:55.523402 | controller | skipping: Conditional result was False
2025-10-13 06:55:55.543421 | 
2025-10-13 06:55:55.543536 | TASK [bindep : Remove bindep temp dir]
2025-10-13 06:55:55.917222 | controller | ok
2025-10-13 06:55:55.928259 | 
2025-10-13 06:55:55.928317 | PLAY RECAP
2025-10-13 06:55:55.928362 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 06:55:55.928383 | 
2025-10-13 06:55:56.036778 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:55:56.037654 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:55:56.633920 | 
2025-10-13 06:55:56.634031 | PLAY [all]
2025-10-13 06:55:56.653188 | 
2025-10-13 06:55:56.653265 | TASK [Abort when test_command variable is undefined]
2025-10-13 06:55:56.678494 | controller | skipping: Conditional result was False
2025-10-13 06:55:56.684180 | 
2025-10-13 06:55:56.684313 | TASK [Convert test_command to list]
2025-10-13 06:55:56.718553 | controller | skipping: Conditional result was False
2025-10-13 06:55:56.725059 | 
2025-10-13 06:55:56.725125 | TASK [Use test_command list]
2025-10-13 06:55:56.775498 | controller | ok
2025-10-13 06:55:56.781726 | 
2025-10-13 06:55:56.781789 | LOOP [Run test_command]
2025-10-13 06:55:57.255811 | controller | no check to run
2025-10-13 06:55:57.256032 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005821
2025-10-13 06:55:57.306132 | 
2025-10-13 06:55:57.306275 | PLAY RECAP
2025-10-13 06:55:57.306328 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:55:57.306348 | 
2025-10-13 06:55:57.448034 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:55:57.449007 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:55:58.102434 | 
2025-10-13 06:55:58.102543 | PLAY [all]
2025-10-13 06:55:58.124340 | 
2025-10-13 06:55:58.124423 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 06:55:58.473252 | controller | changed: non-zero return code
2025-10-13 06:55:58.483824 | 
2025-10-13 06:55:58.483900 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 06:55:58.508175 | controller | skipping: Conditional result was False
2025-10-13 06:55:58.514248 | 
2025-10-13 06:55:58.514319 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 06:55:58.535581 | 
2025-10-13 06:55:58.535833 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 06:55:58.567713 | 
2025-10-13 06:55:58.567864 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 06:55:58.581206 | controller | skipping: Conditional result was False
2025-10-13 06:55:58.588393 | 
2025-10-13 06:55:58.588472 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 06:55:58.619875 | 
2025-10-13 06:55:58.620031 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 06:55:58.670720 | controller | skipping: Conditional result was False
2025-10-13 06:55:58.676442 | 
2025-10-13 06:55:58.676508 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 06:55:58.701150 | controller | skipping: Conditional result was False
2025-10-13 06:55:58.707611 | 
2025-10-13 06:55:58.707704 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 06:55:58.752371 | controller | skipping: Conditional result was False
2025-10-13 06:55:58.804152 | 
2025-10-13 06:55:58.804283 | PLAY RECAP
2025-10-13 06:55:58.804332 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 06:55:58.804353 | 
2025-10-13 06:55:58.958119 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:55:58.959027 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:55:59.671921 | 
2025-10-13 06:55:59.672023 | PLAY [all]
2025-10-13 06:55:59.716285 | 
2025-10-13 06:55:59.716397 | TASK [include_role : fetch-output]
2025-10-13 06:55:59.786173 | controller | ok
2025-10-13 06:55:59.813269 | 
2025-10-13 06:55:59.813383 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 06:55:59.922387 | controller | skipping: Conditional result was False
2025-10-13 06:55:59.928046 | 
2025-10-13 06:55:59.928112 | TASK [fetch-output : Set log path for single node]
2025-10-13 06:55:59.963952 | controller | ok
2025-10-13 06:55:59.969187 | 
2025-10-13 06:55:59.969260 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 06:56:00.519619 | controller -> localhost | ok: "/var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/logs"
2025-10-13 06:56:00.816502 | controller -> localhost | changed: "/var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/artifacts"
2025-10-13 06:56:01.119474 | controller -> localhost | changed: "/var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/docs"
2025-10-13 06:56:01.133378 | 
2025-10-13 06:56:01.133497 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 06:56:01.959458 | controller | changed: .d..t...... ./
2025-10-13 06:56:01.959653 | controller | changed: All items complete
2025-10-13 06:56:01.959716 | 
2025-10-13 06:56:02.550844 | controller | changed: .d..t...... ./
2025-10-13 06:56:03.024722 | controller | changed: .d..t...... ./
2025-10-13 06:56:03.039983 | 
2025-10-13 06:56:03.040083 | TASK [include_role : fetch-output-openshift]
2025-10-13 06:56:03.090309 | controller | skipping: Conditional result was False
2025-10-13 06:56:03.096523 | 
2025-10-13 06:56:03.096588 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 06:56:03.537017 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.027488
2025-10-13 06:56:03.809986 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.019047
2025-10-13 06:56:03.846499 | 
2025-10-13 06:56:03.846694 | PLAY [all]
2025-10-13 06:56:03.866635 | 
2025-10-13 06:56:03.866722 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 06:56:04.328080 | controller | changed
2025-10-13 06:56:04.371064 | 
2025-10-13 06:56:04.371144 | PLAY RECAP
2025-10-13 06:56:04.371372 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:56:04.371415 | 
2025-10-13 06:56:04.477789 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:56:04.478625 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 06:56:05.201564 | 
2025-10-13 06:56:05.201701 | PLAY [localhost]
2025-10-13 06:56:05.219888 | 
2025-10-13 06:56:05.219964 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 06:56:05.587395 | localhost | changed
2025-10-13 06:56:05.592123 | 
2025-10-13 06:56:05.592198 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 06:56:05.636038 | localhost | ok
2025-10-13 06:56:05.644694 | 
2025-10-13 06:56:05.644760 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 06:56:06.005036 | localhost | changed
2025-10-13 06:56:06.010271 | 
2025-10-13 06:56:06.010346 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 06:56:06.666957 | localhost | changed
2025-10-13 06:56:06.684566 | 
2025-10-13 06:56:06.684740 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 06:56:07.100810 | localhost | Identity added: /var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/tmp/ansible.u7yx3t5n (/var/lib/zuul/builds/c4d4846d6c37475bab01a318a3ba828a/work/tmp/ansible.u7yx3t5n)
2025-10-13 06:56:07.101104 | localhost | ok: Runtime: 0:00:00.006858
2025-10-13 06:56:07.105481 | 
2025-10-13 06:56:07.105546 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 06:56:07.364525 | localhost | ok: Runtime: 0:00:00.008610
2025-10-13 06:56:07.374990 | 
2025-10-13 06:56:07.375122 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 06:56:07.430770 | localhost | changed
2025-10-13 06:56:07.442183 | 
2025-10-13 06:56:07.442319 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 06:56:07.839402 | localhost | changed
2025-10-13 06:56:07.859871 | 
2025-10-13 06:56:07.859930 | PLAY [localhost]
2025-10-13 06:56:07.871410 | 
2025-10-13 06:56:07.871746 | TASK [Generate bulk log download script]
2025-10-13 06:56:07.890376 | localhost | ok
2025-10-13 06:56:07.901905 | 
2025-10-13 06:56:07.901971 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 06:56:07.933148 | localhost | ok: All assertions passed
2025-10-13 06:56:07.943864 | 
2025-10-13 06:56:07.943993 | TASK [local-log-download : Create download script]
2025-10-13 06:56:08.368411 | localhost -> localhost | changed
2025-10-13 06:56:08.390278 | 
2025-10-13 06:56:08.390415 | TASK [Register quick-download link]
2025-10-13 06:56:08.412110 | localhost | ok
2025-10-13 06:56:08.465975 | 
2025-10-13 06:56:08.466094 | PLAY [logserver.rdoproject.org]
2025-10-13 06:56:08.475780 | 
2025-10-13 06:56:08.475844 | TASK [Set zuul-log-path fact]
2025-10-13 06:56:08.492648 | logserver.rdoproject.org | ok
2025-10-13 06:56:08.502886 | 
2025-10-13 06:56:08.503013 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:56:08.530372 | logserver.rdoproject.org | ok
2025-10-13 06:56:08.536313 | 
2025-10-13 06:56:08.536377 | TASK [upload-logs : Create log directories]
2025-10-13 06:56:09.224408 | logserver.rdoproject.org | changed
2025-10-13 06:56:09.227719 | 
2025-10-13 06:56:09.227784 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 06:56:09.537289 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.013987
2025-10-13 06:56:09.542562 | 
2025-10-13 06:56:09.542626 | TASK [upload-logs : Upload logs to log server]
2025-10-13 06:56:10.241243 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 06:56:10.244292 | 
2025-10-13 06:56:10.244355 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 06:56:10.298750 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:56:10.309210 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:56:10.317058 | 
2025-10-13 06:56:10.317189 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 06:56:10.381330 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:56:10.381647 | 
2025-10-13 06:56:10.386765 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:56:10.397491 | 
2025-10-13 06:56:10.397604 | LOOP [upload-logs : Upload console log and json output]