2025-10-13 15:55:47.701005 | Job console starting...
2025-10-13 15:55:47.711739 | Updating repositories
2025-10-13 15:55:47.874472 | Preparing job workspace
2025-10-13 15:55:53.126889 | Running Ansible setup...
2025-10-13 15:55:57.399347 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 15:55:58.120299 | 
2025-10-13 15:55:58.120455 | PLAY [localhost]
2025-10-13 15:55:58.129056 | 
2025-10-13 15:55:58.129130 | TASK [Gathering Facts]
2025-10-13 15:55:59.101457 | localhost | ok
2025-10-13 15:55:59.115598 | 
2025-10-13 15:55:59.115695 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 15:55:59.686433 | localhost -> localhost | changed
2025-10-13 15:55:59.692020 | 
2025-10-13 15:55:59.692089 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 15:56:00.753441 | localhost -> localhost | changed
2025-10-13 15:56:00.762201 | 
2025-10-13 15:56:00.762269 | TASK [Setup log path fact]
2025-10-13 15:56:00.794504 | localhost | ok
2025-10-13 15:56:00.805752 | 
2025-10-13 15:56:00.805847 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 15:56:00.841841 | localhost | ok
2025-10-13 15:56:00.849274 | 
2025-10-13 15:56:00.849365 | TASK [emit-job-header : Print job information]
2025-10-13 15:56:00.930156 | # Job Information
2025-10-13 15:56:00.930309 | Ansible Version: 2.15.12
2025-10-13 15:56:00.930335 | Job: cifmw-molecule-cifmw_nfs
2025-10-13 15:56:00.930354 | Pipeline: github-check
2025-10-13 15:56:00.930372 | Executor: ze02.softwarefactory-project.io
2025-10-13 15:56:00.930390 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402
2025-10-13 15:56:00.930408 | Log URL (when completed): https://logserver.rdoproject.org/345/rdoproject.org/3459495a337d4c7fa6bb3c47f73f4215/
2025-10-13 15:56:00.930426 | Event ID: c6d787c0-a84c-11f0-88a9-fcb21b577847
2025-10-13 15:56:00.934242 | 
2025-10-13 15:56:00.934312 | LOOP [emit-job-header : Print node information]
2025-10-13 15:56:01.096542 | localhost | ok:
2025-10-13 15:56:01.096714 | localhost | # Node Information
2025-10-13 15:56:01.096743 | localhost | Inventory Hostname: controller
2025-10-13 15:56:01.096765 | localhost | Hostname: np0005485630
2025-10-13 15:56:01.096785 | localhost | Username: zuul
2025-10-13 15:56:01.096805 | localhost | Distro: CentOS 9
2025-10-13 15:56:01.096823 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 15:56:01.096840 | localhost | Region: RegionOne
2025-10-13 15:56:01.096857 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 15:56:01.096873 | localhost | Product Name: OpenStack Nova
2025-10-13 15:56:01.096889 | localhost | Interface IP: 38.102.83.138
2025-10-13 15:56:01.122286 | 
2025-10-13 15:56:01.122364 | PLAY [all]
2025-10-13 15:56:01.137633 | 
2025-10-13 15:56:01.137771 | TASK [Gather network facts]
2025-10-13 15:56:01.604994 | controller | ok
2025-10-13 15:56:01.621946 | 
2025-10-13 15:56:01.622068 | TASK [include_role : start-zuul-console]
2025-10-13 15:56:01.641502 | controller | ok
2025-10-13 15:56:01.656268 | 
2025-10-13 15:56:01.656360 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 15:56:02.057589 | controller | ok
2025-10-13 15:56:02.070793 | 
2025-10-13 15:56:02.070927 | TASK [include_role : add-build-sshkey]
2025-10-13 15:56:02.100744 | controller | ok
2025-10-13 15:56:02.113562 | 
2025-10-13 15:56:02.113650 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 15:56:02.364339 | controller -> localhost | ok
2025-10-13 15:56:02.369830 | 
2025-10-13 15:56:02.369891 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 15:56:02.400236 | controller | ok
2025-10-13 15:56:02.413190 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 15:56:02.418901 | 
2025-10-13 15:56:02.418961 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 15:56:03.191118 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 15:56:03.191339 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/3459495a337d4c7fa6bb3c47f73f4215_id_rsa.
2025-10-13 15:56:03.191373 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/3459495a337d4c7fa6bb3c47f73f4215_id_rsa.pub.
2025-10-13 15:56:03.191395 | controller -> localhost | The key fingerprint is:
2025-10-13 15:56:03.191414 | controller -> localhost | SHA256:Hrwsz5KV9xgvXhhAbRm/b6cosMJ+3f2zYHiZwbqj1rg zuul-build-sshkey
2025-10-13 15:56:03.191433 | controller -> localhost | The key's randomart image is:
2025-10-13 15:56:03.191452 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 15:56:03.191470 | controller -> localhost | |        ...o     |
2025-10-13 15:56:03.191488 | controller -> localhost | |       .  +.     |
2025-10-13 15:56:03.191506 | controller -> localhost | |        ..  .    |
2025-10-13 15:56:03.191524 | controller -> localhost | |       . .  ..   |
2025-10-13 15:56:03.191541 | controller -> localhost | |        S.. .o   |
2025-10-13 15:56:03.191558 | controller -> localhost | |       o+oooo.+  |
2025-10-13 15:56:03.191575 | controller -> localhost | |     ..o+=+O.Bo .|
2025-10-13 15:56:03.191593 | controller -> localhost | |      =+oo=+Boo+ |
2025-10-13 15:56:03.191610 | controller -> localhost | |     ..++E++o .o+|
2025-10-13 15:56:03.191627 | controller -> localhost | +----[SHA256]-----+
2025-10-13 15:56:03.191687 | controller -> localhost | ok: Runtime: 0:00:00.352096
2025-10-13 15:56:03.197365 | 
2025-10-13 15:56:03.197425 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 15:56:03.216749 | controller | ok
2025-10-13 15:56:03.226568 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 15:56:03.235710 | 
2025-10-13 15:56:03.235778 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 15:56:03.260316 | controller | skipping: Conditional result was False
2025-10-13 15:56:03.265638 | 
2025-10-13 15:56:03.265720 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 15:56:03.720114 | controller | changed
2025-10-13 15:56:03.725073 | 
2025-10-13 15:56:03.725136 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 15:56:03.990385 | controller | ok
2025-10-13 15:56:03.999570 | 
2025-10-13 15:56:03.999742 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 15:56:04.831601 | controller | changed
2025-10-13 15:56:04.839515 | 
2025-10-13 15:56:04.839616 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 15:56:05.701809 | controller | changed
2025-10-13 15:56:05.714969 | 
2025-10-13 15:56:05.715153 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 15:56:05.744017 | controller | skipping: Conditional result was False
2025-10-13 15:56:05.754793 | 
2025-10-13 15:56:05.754954 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 15:56:06.355261 | controller -> localhost | changed
2025-10-13 15:56:06.367727 | 
2025-10-13 15:56:06.367812 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 15:56:06.711329 | controller -> localhost | Identity added: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/3459495a337d4c7fa6bb3c47f73f4215_id_rsa (zuul-build-sshkey)
2025-10-13 15:56:06.711581 | controller -> localhost | ok: Runtime: 0:00:00.012605
2025-10-13 15:56:06.718244 | 
2025-10-13 15:56:06.718313 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 15:56:07.174522 | controller | ok
2025-10-13 15:56:07.182965 | 
2025-10-13 15:56:07.183030 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 15:56:07.239975 | controller | skipping: Conditional result was False
2025-10-13 15:56:07.250564 | 
2025-10-13 15:56:07.250634 | TASK [include_role : validate-host]
2025-10-13 15:56:07.292367 | controller | ok
2025-10-13 15:56:07.326750 | 
2025-10-13 15:56:07.326858 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 15:56:07.388833 | controller | ok
2025-10-13 15:56:07.393523 | 
2025-10-13 15:56:07.393583 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 15:56:07.870106 | controller -> localhost | ok
2025-10-13 15:56:07.875040 | 
2025-10-13 15:56:07.875099 | TASK [validate-host : Collect information about the host]
2025-10-13 15:56:08.639770 | controller | ok
2025-10-13 15:56:08.667234 | 
2025-10-13 15:56:08.667319 | TASK [validate-host : Sanitize hostname]
2025-10-13 15:56:08.715588 | controller | ok
2025-10-13 15:56:08.720404 | 
2025-10-13 15:56:08.720465 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 15:56:09.491071 | controller -> localhost | changed
2025-10-13 15:56:09.497069 | 
2025-10-13 15:56:09.497138 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 15:56:10.036101 | controller | ok
2025-10-13 15:56:10.046149 | 
2025-10-13 15:56:10.046246 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 15:56:10.718229 | controller -> localhost | changed
2025-10-13 15:56:10.728826 | 
2025-10-13 15:56:10.728924 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 15:56:10.765894 | controller | skipping: Conditional result was False
2025-10-13 15:56:10.772463 | 
2025-10-13 15:56:10.773312 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 15:56:10.797767 | controller | skipping: Conditional result was False
2025-10-13 15:56:10.804343 | 
2025-10-13 15:56:10.804469 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 15:56:11.096040 | controller | ok: "logs"
2025-10-13 15:56:11.096371 | controller | ok: All items complete
2025-10-13 15:56:11.096404 | 
2025-10-13 15:56:11.290350 | controller | ok: "artifacts"
2025-10-13 15:56:11.483313 | controller | ok: "docs"
2025-10-13 15:56:11.496925 | 
2025-10-13 15:56:11.497029 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 15:56:11.770937 | controller | changed: "logs"
2025-10-13 15:56:11.983843 | controller | changed: "artifacts"
2025-10-13 15:56:12.199719 | controller | changed: "docs"
2025-10-13 15:56:12.230838 | 
2025-10-13 15:56:12.230941 | PLAY RECAP
2025-10-13 15:56:12.230984 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 15:56:12.231010 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 15:56:12.231028 | 
2025-10-13 15:56:12.334765 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 15:56:12.335535 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 15:56:12.967280 | 
2025-10-13 15:56:12.967396 | PLAY [localhost]
2025-10-13 15:56:12.985048 | 
2025-10-13 15:56:12.985165 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 15:56:13.440403 | localhost | ok
2025-10-13 15:56:13.446432 | 
2025-10-13 15:56:13.446507 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 15:56:14.325304 | localhost | changed
2025-10-13 15:56:14.345622 | 
2025-10-13 15:56:14.345702 | PLAY [all]
2025-10-13 15:56:14.360904 | 
2025-10-13 15:56:14.360969 | TASK [include_role : prepare-workspace]
2025-10-13 15:56:14.380657 | controller | ok
2025-10-13 15:56:14.397772 | 
2025-10-13 15:56:14.397923 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 15:56:14.848215 | controller | ok
2025-10-13 15:56:14.859313 | 
2025-10-13 15:56:14.859414 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 15:56:16.906040 | controller | Output suppressed because no_log was given
2025-10-13 15:56:16.924231 | 
2025-10-13 15:56:16.924368 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 15:56:17.209418 | controller | changed: "logs"
2025-10-13 15:56:17.412736 | controller | changed: "artifacts"
2025-10-13 15:56:17.662152 | controller | changed: "docs"
2025-10-13 15:56:17.690119 | 
2025-10-13 15:56:17.690321 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 15:56:17.973050 | controller | changed: "logs"
2025-10-13 15:56:17.974227 | controller | changed: All items complete
2025-10-13 15:56:17.974326 | 
2025-10-13 15:56:18.201962 | controller | changed: "artifacts"
2025-10-13 15:56:18.438314 | controller | changed: "docs"
2025-10-13 15:56:18.457414 | 
2025-10-13 15:56:18.457547 | TASK [Check if worker can sudo]
2025-10-13 15:56:18.989953 | controller | ok: Runtime: 0:00:00.041733
2025-10-13 15:56:18.998941 | 
2025-10-13 15:56:18.999026 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 15:56:19.115688 | controller | skipping: Conditional result was False
2025-10-13 15:56:19.124249 | 
2025-10-13 15:56:19.124334 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 15:56:19.227267 | controller | ok
2025-10-13 15:56:19.258935 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 15:56:19.275720 | 
2025-10-13 15:56:19.275859 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 15:56:19.535456 | controller | ok
2025-10-13 15:56:19.541349 | 
2025-10-13 15:56:19.541415 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 15:56:19.625036 | controller | ok: "/var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 15:56:19.647281 | 
2025-10-13 15:56:19.647387 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 15:56:20.499415 | controller | changed
2025-10-13 15:56:20.507046 | 
2025-10-13 15:56:20.507131 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 15:56:20.598355 | controller | ok: "/var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 15:56:20.598514 | controller | ok: All items complete
2025-10-13 15:56:20.598540 | 
2025-10-13 15:56:20.676233 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 15:56:20.682921 | 
2025-10-13 15:56:20.682991 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 15:56:21.603487 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 15:56:22.439287 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 15:56:22.451031 | 
2025-10-13 15:56:22.451122 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 15:56:22.937158 | controller | changed: section and option added
2025-10-13 15:56:22.969932 | 
2025-10-13 15:56:22.970045 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 15:56:23.782654 | controller | 29 files removed
2025-10-13 15:56:23.783066 | controller | ok: Item: dnf clean all Runtime: 0:00:00.504301
2025-10-13 15:56:23.783157 | controller | changed: All items complete
2025-10-13 15:56:23.783204 | 
2025-10-13 15:56:34.887366 | 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 15:56:34.887587 | controller | DNF version: 4.14.0
2025-10-13 15:56:34.887659 | controller | cachedir: /var/cache/dnf
2025-10-13 15:56:34.887758 | controller | Making cache files for all metadata files.
2025-10-13 15:56:34.887804 | controller | baseos: has expired and will be refreshed.
2025-10-13 15:56:34.887844 | controller | appstream: has expired and will be refreshed.
2025-10-13 15:56:34.887883 | controller | crb: has expired and will be refreshed.
2025-10-13 15:56:34.887942 | controller | extras-common: has expired and will be refreshed.
2025-10-13 15:56:34.887982 | controller | repo: downloading from remote: baseos
2025-10-13 15:56:34.888021 | controller | CentOS Stream 9 - BaseOS                         87 MB/s | 8.8 MB     00:00
2025-10-13 15:56:34.888060 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 15:56:34.888098 | controller | repo: downloading from remote: appstream
2025-10-13 15:56:34.888137 | controller | CentOS Stream 9 - AppStream                      89 MB/s |  25 MB     00:00
2025-10-13 15:56:34.888175 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 15:56:34.888213 | controller | repo: downloading from remote: crb
2025-10-13 15:56:34.888251 | controller | CentOS Stream 9 - CRB                            81 MB/s | 7.2 MB     00:00
2025-10-13 15:56:34.888290 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 15:56:34.888327 | controller | repo: downloading from remote: extras-common
2025-10-13 15:56:34.888365 | controller | CentOS Stream 9 - Extras packages               1.4 MB/s |  20 kB     00:00
2025-10-13 15:56:34.888403 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 15:56:34.888440 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 15:56:34.888479 | controller | Completion plugin: Generating completion cache...
2025-10-13 15:56:34.888717 | controller | Metadata cache created.
2025-10-13 15:56:34.888784 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.822423
2025-10-13 15:56:34.914233 | 
2025-10-13 15:56:34.914324 | PLAY RECAP
2025-10-13 15:56:34.914378 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 15:56:34.914412 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 15:56:34.914437 | 
2025-10-13 15:56:35.047589 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 15:56:35.048740 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 15:56:35.678052 | 
2025-10-13 15:56:35.678185 | PLAY [all]
2025-10-13 15:56:35.700838 | 
2025-10-13 15:56:35.701021 | TASK [Install binary dependencies]
2025-10-13 15:56:35.763485 | controller | ok
2025-10-13 15:56:35.783175 | 
2025-10-13 15:56:35.783298 | TASK [bindep : Include find tasks]
2025-10-13 15:56:35.812798 | controller | ok
2025-10-13 15:56:35.821416 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 15:56:35.827745 | 
2025-10-13 15:56:35.827814 | TASK [bindep : Look for bindep.txt]
2025-10-13 15:56:36.248925 | controller | ok
2025-10-13 15:56:36.255848 | 
2025-10-13 15:56:36.255940 | TASK [bindep : Define bindep_file fact]
2025-10-13 15:56:36.286528 | controller | ok
2025-10-13 15:56:36.291828 | 
2025-10-13 15:56:36.291900 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 15:56:36.308384 | controller | skipping: Conditional result was False
2025-10-13 15:56:36.316682 | 
2025-10-13 15:56:36.316845 | TASK [bindep : Define bindep_file fact]
2025-10-13 15:56:36.345971 | controller | skipping: Conditional result was False
2025-10-13 15:56:36.353571 | 
2025-10-13 15:56:36.353782 | TASK [bindep : Look for bindep fallback file]
2025-10-13 15:56:36.379150 | controller | skipping: Conditional result was False
2025-10-13 15:56:36.385070 | 
2025-10-13 15:56:36.385162 | TASK [bindep : Define bindep_file fact]
2025-10-13 15:56:36.410426 | controller | skipping: Conditional result was False
2025-10-13 15:56:36.417639 | 
2025-10-13 15:56:36.417732 | TASK [bindep : Include bindep tasks]
2025-10-13 15:56:36.459224 | controller | ok
2025-10-13 15:56:36.468729 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 15:56:36.478058 | 
2025-10-13 15:56:36.478139 | TASK [bindep : Look for bindep command]
2025-10-13 15:56:36.502389 | controller | skipping: Conditional result was False
2025-10-13 15:56:36.509330 | 
2025-10-13 15:56:36.509398 | TASK [bindep : Check for system bindep]
2025-10-13 15:56:37.038763 | controller | ok: Runtime: 0:00:00.007037
2025-10-13 15:56:37.048141 | 
2025-10-13 15:56:37.048267 | TASK [bindep : Define bindep_command fact]
2025-10-13 15:56:37.073919 | controller | skipping: Conditional result was False
2025-10-13 15:56:37.080098 | 
2025-10-13 15:56:37.080188 | TASK [bindep : Include install tasks]
2025-10-13 15:56:37.119165 | controller | ok
2025-10-13 15:56:37.126582 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 15:56:37.135399 | 
2025-10-13 15:56:37.135472 | TASK [bindep : Create temp dir for bindep]
2025-10-13 15:56:37.476230 | controller | changed
2025-10-13 15:56:37.488907 | 
2025-10-13 15:56:37.489040 | TASK [Ensure we have pip dependencies]
2025-10-13 15:56:37.520867 | controller | ok
2025-10-13 15:56:37.559048 | 
2025-10-13 15:56:37.559163 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 11:56:37.828763 | controller | /usr/bin/pip3
2025-10-13 11:56:37.852843 | controller | /usr/bin/python3: No module named wheel
2025-10-13 15:56:38.093603 | controller | ok: Runtime: 0:00:00.036314
2025-10-13 15:56:38.101973 | 
2025-10-13 15:56:38.102061 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 15:56:38.165251 | controller | ok: "/var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 15:56:38.184282 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 15:56:38.208833 | 
2025-10-13 15:56:38.208950 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 15:56:40.669423 | controller | changed
2025-10-13 15:56:40.692639 | 
2025-10-13 15:56:40.692859 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 15:56:40.750186 | controller | skipping: Conditional result was False
2025-10-13 15:56:40.758329 | 
2025-10-13 15:56:40.758406 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 15:56:40.803719 | controller | skipping: Conditional result was False
2025-10-13 15:56:40.812408 | 
2025-10-13 15:56:40.812507 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 15:56:40.861859 | controller | skipping: Conditional result was False
2025-10-13 15:56:40.868308 | 
2025-10-13 15:56:40.868382 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 15:56:40.907052 | controller | skipping: Conditional result was False
2025-10-13 15:56:40.916315 | 
2025-10-13 15:56:40.916385 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 15:56:41.469238 | controller | skipping: Conditional result was False
2025-10-13 15:56:41.476192 | 
2025-10-13 15:56:41.476279 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 15:56:41.500347 | controller | skipping: Conditional result was False
2025-10-13 15:56:41.507159 | 
2025-10-13 15:56:41.507231 | TASK [ensure-pip : Install pip from source]
2025-10-13 15:56:41.530226 | controller | skipping: Conditional result was False
2025-10-13 15:56:41.548288 | 
2025-10-13 15:56:41.548571 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 11:56:41.878014 | controller | /usr/bin/python3
2025-10-13 15:56:42.125352 | controller | ok: Runtime: 0:00:00.007573
2025-10-13 15:56:42.131382 | 
2025-10-13 15:56:42.131446 | TASK [ensure-pip : Set host default]
2025-10-13 15:56:42.190800 | controller | ok
2025-10-13 15:56:42.196237 | 
2025-10-13 15:56:42.196300 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 15:56:42.243729 | controller | ok
2025-10-13 15:56:42.254732 | 
2025-10-13 15:56:42.254793 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 15:56:46.543638 | controller | changed
2025-10-13 15:56:46.550949 | 
2025-10-13 15:56:46.551067 | TASK [bindep : Define bindep_command]
2025-10-13 15:56:46.591611 | controller | ok
2025-10-13 15:56:46.598627 | 
2025-10-13 15:56:46.598708 | LOOP [bindep : Include package tasks]
2025-10-13 15:56:46.648544 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 15:56:46.648725 | controller | ok: All items complete
2025-10-13 15:56:46.648752 | 
2025-10-13 15:56:46.662439 | controller | included: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 15:56:46.684160 | 
2025-10-13 15:56:46.684244 | TASK [bindep : Define bindep_run fact]
2025-10-13 15:56:46.749451 | controller | ok
2025-10-13 15:56:46.767084 | 
2025-10-13 15:56:46.767208 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 11:56:48.225606 | controller | podman
2025-10-13 11:56:48.256026 | controller | python3-jmespath
2025-10-13 11:56:48.256189 | controller | python3-libvirt
2025-10-13 11:56:48.256199 | controller | python3-lxml
2025-10-13 11:56:48.256207 | controller | python3-netaddr
2025-10-13 15:56:48.342392 | controller | ok: Runtime: 0:00:01.141149
2025-10-13 15:56:48.349257 | 
2025-10-13 15:56:48.349395 | TASK [bindep : Install distro packages from bindep]
2025-10-13 15:57:52.189020 | controller | changed
2025-10-13 15:57:52.202209 | 
2025-10-13 15:57:52.202381 | TASK [bindep : Check that packages are installed]
2025-10-13 15:57:53.748164 | controller | ok: Runtime: 0:00:01.078549
2025-10-13 15:57:53.761653 | 
2025-10-13 15:57:53.761872 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 15:57:53.798821 | controller | skipping: Conditional result was False
2025-10-13 15:57:53.814687 | 
2025-10-13 15:57:53.814783 | TASK [Run test-setup role]
2025-10-13 15:57:53.846586 | controller | ok
2025-10-13 15:57:53.870433 | 
2025-10-13 15:57:53.870552 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 15:57:54.120613 | controller | ok
2025-10-13 15:57:54.131879 | 
2025-10-13 15:57:54.132012 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 15:57:54.680261 | controller | skipping: Conditional result was False
2025-10-13 15:57:54.729101 | 
2025-10-13 15:57:54.729242 | TASK [bindep : Remove bindep temp dir]
2025-10-13 15:57:55.109746 | controller | ok
2025-10-13 15:57:55.120894 | 
2025-10-13 15:57:55.120955 | PLAY RECAP
2025-10-13 15:57:55.121002 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 15:57:55.121028 | 
2025-10-13 15:57:55.220132 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 15:57:55.220983 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 15:57:55.827598 | 
2025-10-13 15:57:55.827723 | PLAY [all]
2025-10-13 15:57:55.848273 | 
2025-10-13 15:57:55.848353 | TASK [Abort when test_command variable is undefined]
2025-10-13 15:57:55.883193 | controller | skipping: Conditional result was False
2025-10-13 15:57:55.889270 | 
2025-10-13 15:57:55.889344 | TASK [Convert test_command to list]
2025-10-13 15:57:55.924074 | controller | skipping: Conditional result was False
2025-10-13 15:57:55.931421 | 
2025-10-13 15:57:55.931502 | TASK [Use test_command list]
2025-10-13 15:57:55.984283 | controller | ok
2025-10-13 15:57:55.992546 | 
2025-10-13 15:57:55.992657 | LOOP [Run test_command]
2025-10-13 15:57:56.406161 | controller | no check to run
2025-10-13 15:57:56.406429 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005341
2025-10-13 15:57:56.457469 | 
2025-10-13 15:57:56.457604 | PLAY RECAP
2025-10-13 15:57:56.457728 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 15:57:56.457784 | 
2025-10-13 15:57:56.574978 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 15:57:56.576882 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 15:57:57.169890 | 
2025-10-13 15:57:57.170003 | PLAY [all]
2025-10-13 15:57:57.190717 | 
2025-10-13 15:57:57.190808 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 15:57:57.545433 | controller | changed: non-zero return code
2025-10-13 15:57:57.558651 | 
2025-10-13 15:57:57.558882 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 15:57:57.596395 | controller | skipping: Conditional result was False
2025-10-13 15:57:57.604722 | 
2025-10-13 15:57:57.604825 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 15:57:57.641086 | 
2025-10-13 15:57:57.641324 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 15:57:57.674516 | 
2025-10-13 15:57:57.674708 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 15:57:57.699645 | controller | skipping: Conditional result was False
2025-10-13 15:57:57.707566 | 
2025-10-13 15:57:57.707658 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 15:57:57.741489 | 
2025-10-13 15:57:57.741684 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 15:57:57.766990 | controller | skipping: Conditional result was False
2025-10-13 15:57:57.778963 | 
2025-10-13 15:57:57.779105 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 15:57:57.805229 | controller | skipping: Conditional result was False
2025-10-13 15:57:57.812949 | 
2025-10-13 15:57:57.813033 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 15:57:57.837861 | controller | skipping: Conditional result was False
2025-10-13 15:57:57.873513 | 
2025-10-13 15:57:57.873585 | PLAY RECAP
2025-10-13 15:57:57.873638 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 15:57:57.873709 | 
2025-10-13 15:57:57.962892 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 15:57:57.964571 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 15:57:58.608491 | 
2025-10-13 15:57:58.608612 | PLAY [all]
2025-10-13 15:57:58.638678 | 
2025-10-13 15:57:58.638822 | TASK [include_role : fetch-output]
2025-10-13 15:57:58.711171 | controller | ok
2025-10-13 15:57:58.736632 | 
2025-10-13 15:57:58.736831 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 15:57:58.802782 | controller | skipping: Conditional result was False
2025-10-13 15:57:58.808783 | 
2025-10-13 15:57:58.808859 | TASK [fetch-output : Set log path for single node]
2025-10-13 15:57:58.860064 | controller | ok
2025-10-13 15:57:58.865312 | 
2025-10-13 15:57:58.865383 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 15:57:59.260116 | controller -> localhost | ok: "/var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/logs"
2025-10-13 15:57:59.493202 | controller -> localhost | changed: "/var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/artifacts"
2025-10-13 15:57:59.765310 | controller -> localhost | changed: "/var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/docs"
2025-10-13 15:57:59.776456 | 
2025-10-13 15:57:59.776562 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 15:58:00.385059 | controller | changed: .d..t...... ./
2025-10-13 15:58:00.385483 | controller | changed: All items complete
2025-10-13 15:58:00.385552 | 
2025-10-13 15:58:00.850234 | controller | changed: .d..t...... ./
2025-10-13 15:58:01.316822 | controller | changed: .d..t...... ./
2025-10-13 15:58:01.347819 | 
2025-10-13 15:58:01.348017 | TASK [include_role : fetch-output-openshift]
2025-10-13 15:58:01.375480 | controller | skipping: Conditional result was False
2025-10-13 15:58:01.390065 | 
2025-10-13 15:58:01.390334 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 15:58:01.897852 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.015331
2025-10-13 15:58:02.186677 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009341
2025-10-13 15:58:02.230296 | 
2025-10-13 15:58:02.230499 | PLAY [all]
2025-10-13 15:58:02.246252 | 
2025-10-13 15:58:02.246323 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 15:58:02.691473 | controller | changed
2025-10-13 15:58:02.716402 | 
2025-10-13 15:58:02.716476 | PLAY RECAP
2025-10-13 15:58:02.716519 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 15:58:02.716540 | 
2025-10-13 15:58:02.831342 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 15:58:02.833131 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 15:58:03.453109 | 
2025-10-13 15:58:03.453239 | PLAY [localhost]
2025-10-13 15:58:03.473503 | 
2025-10-13 15:58:03.473612 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 15:58:03.837445 | localhost | changed
2025-10-13 15:58:03.842159 | 
2025-10-13 15:58:03.842231 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 15:58:03.869923 | localhost | ok
2025-10-13 15:58:03.877987 | 
2025-10-13 15:58:03.878051 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 15:58:04.237272 | localhost | changed
2025-10-13 15:58:04.250347 | 
2025-10-13 15:58:04.250487 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 15:58:04.921113 | localhost | changed
2025-10-13 15:58:04.926048 | 
2025-10-13 15:58:04.926107 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 15:58:05.320625 | localhost | Identity added: /var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/tmp/ansible.i92i2suh (/var/lib/zuul/builds/3459495a337d4c7fa6bb3c47f73f4215/work/tmp/ansible.i92i2suh)
2025-10-13 15:58:05.320836 | localhost | ok: Runtime: 0:00:00.014512
2025-10-13 15:58:05.325496 | 
2025-10-13 15:58:05.325573 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 15:58:05.578146 | localhost | ok: Runtime: 0:00:00.009769
2025-10-13 15:58:05.583213 | 
2025-10-13 15:58:05.583279 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 15:58:05.633194 | localhost | changed
2025-10-13 15:58:05.637599 | 
2025-10-13 15:58:05.637793 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 15:58:06.042456 | localhost | changed
2025-10-13 15:58:06.063287 | 
2025-10-13 15:58:06.063376 | PLAY [localhost]
2025-10-13 15:58:06.075293 | 
2025-10-13 15:58:06.075368 | TASK [Generate bulk log download script]
2025-10-13 15:58:06.097856 | localhost | ok
2025-10-13 15:58:06.110417 | 
2025-10-13 15:58:06.110763 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 15:58:06.154640 | localhost | ok: All assertions passed
2025-10-13 15:58:06.165132 | 
2025-10-13 15:58:06.165283 | TASK [local-log-download : Create download script]
2025-10-13 15:58:06.578280 | localhost -> localhost | changed
2025-10-13 15:58:06.586938 | 
2025-10-13 15:58:06.587014 | TASK [Register quick-download link]
2025-10-13 15:58:06.605174 | localhost | ok
2025-10-13 15:58:06.645822 | 
2025-10-13 15:58:06.645922 | PLAY [logserver.rdoproject.org]
2025-10-13 15:58:06.655604 | 
2025-10-13 15:58:06.655678 | TASK [Set zuul-log-path fact]
2025-10-13 15:58:06.672789 | logserver.rdoproject.org | ok
2025-10-13 15:58:06.681889 | 
2025-10-13 15:58:06.681969 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 15:58:06.708562 | logserver.rdoproject.org | ok
2025-10-13 15:58:06.714091 | 
2025-10-13 15:58:06.714149 | TASK [upload-logs : Create log directories]
2025-10-13 15:58:07.430782 | logserver.rdoproject.org | changed
2025-10-13 15:58:07.437754 | 
2025-10-13 15:58:07.437922 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 15:58:07.747737 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008962
2025-10-13 15:58:07.753751 | 
2025-10-13 15:58:07.753857 | TASK [upload-logs : Upload logs to log server]
2025-10-13 15:58:08.503916 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 15:58:08.507078 | 
2025-10-13 15:58:08.507140 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 15:58:08.582101 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:58:08.595139 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:58:08.603405 | 
2025-10-13 15:58:08.603600 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 15:58:08.652411 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:58:08.652712 | 
2025-10-13 15:58:08.655809 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 15:58:08.668140 | 
2025-10-13 15:58:08.668307 | LOOP [upload-logs : Upload console log and json output]