2025-10-03 09:59:50.947534 | Job console starting... 2025-10-03 09:59:50.959148 | Updating repositories 2025-10-03 09:59:50.990092 | Preparing job workspace 2025-10-03 09:59:54.766031 | Running Ansible setup... 2025-10-03 09:59:58.685882 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 09:59:59.430873 | 2025-10-03 09:59:59.430989 | PLAY [localhost] 2025-10-03 09:59:59.442269 | 2025-10-03 09:59:59.442381 | TASK [Gathering Facts] 2025-10-03 10:00:00.642611 | localhost | ok 2025-10-03 10:00:00.657323 | 2025-10-03 10:00:00.657467 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-03 10:00:01.157407 | localhost -> localhost | changed 2025-10-03 10:00:01.172069 | 2025-10-03 10:00:01.172186 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-03 10:00:02.312936 | localhost -> localhost | changed 2025-10-03 10:00:02.321917 | 2025-10-03 10:00:02.322014 | TASK [Setup log path fact] 2025-10-03 10:00:02.339428 | localhost | ok 2025-10-03 10:00:02.352006 | 2025-10-03 10:00:02.352163 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 10:00:02.382217 | localhost | ok 2025-10-03 10:00:02.415237 | 2025-10-03 10:00:02.415402 | TASK [emit-job-header : Print job information] 2025-10-03 10:00:02.446259 | # Job Information 2025-10-03 10:00:02.446447 | Ansible Version: 2.15.12 2025-10-03 10:00:02.446482 | Job: cifmw-molecule-cifmw_setup 2025-10-03 10:00:02.446507 | Pipeline: github-check 2025-10-03 10:00:02.446530 | Executor: ze03.softwarefactory-project.io 2025-10-03 10:00:02.446556 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-03 10:00:02.446581 | Log URL (when completed): https://logserver.rdoproject.org/b89/rdoproject.org/b89b58ea4d9d4999b0b29d187b8447b3/ 2025-10-03 10:00:02.446604 | Event ID: 79314020-a03f-11f0-87f2-6df8ed647fba 2025-10-03 10:00:02.457903 | 2025-10-03 10:00:02.458049 | LOOP [emit-job-header : Print node information] 2025-10-03 10:00:02.550750 | localhost | ok: 2025-10-03 10:00:02.550950 | localhost | # Node Information 2025-10-03 10:00:02.550979 | localhost | Inventory Hostname: controller 2025-10-03 10:00:02.551002 | localhost | Hostname: np0005468513 2025-10-03 10:00:02.551022 | localhost | Username: zuul 2025-10-03 10:00:02.551044 | localhost | Distro: CentOS 9 2025-10-03 10:00:02.551063 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-03 10:00:02.551081 | localhost | Region: RegionOne 2025-10-03 10:00:02.551098 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-03 10:00:02.551116 | localhost | Product Name: OpenStack Nova 2025-10-03 10:00:02.551133 | localhost | Interface IP: 38.102.83.179 2025-10-03 10:00:02.592256 | 2025-10-03 10:00:02.592347 | PLAY [all] 2025-10-03 10:00:02.601001 | 2025-10-03 10:00:02.601080 | TASK [Gather network facts] 2025-10-03 10:00:03.055900 | controller | ok 2025-10-03 10:00:03.109522 | 2025-10-03 10:00:03.109623 | TASK [include_role : start-zuul-console] 2025-10-03 10:00:03.130108 | controller | ok 2025-10-03 10:00:03.142795 | 2025-10-03 10:00:03.142892 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-03 10:00:03.525330 | controller | ok 2025-10-03 10:00:03.533854 | 2025-10-03 10:00:03.533915 | TASK [include_role : add-build-sshkey] 2025-10-03 10:00:03.552931 | controller | ok 2025-10-03 10:00:03.569923 | 2025-10-03 10:00:03.570044 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-03 10:00:03.829959 | controller -> localhost | ok 2025-10-03 10:00:03.837469 | 2025-10-03 10:00:03.837567 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-03 10:00:03.889167 | controller | ok 2025-10-03 10:00:03.914180 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-03 10:00:03.931182 | 2025-10-03 10:00:03.931296 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-03 10:00:04.889946 | controller -> localhost | Generating public/private rsa key pair. 2025-10-03 10:00:04.890167 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/b89b58ea4d9d4999b0b29d187b8447b3_id_rsa. 2025-10-03 10:00:04.890199 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/b89b58ea4d9d4999b0b29d187b8447b3_id_rsa.pub. 2025-10-03 10:00:04.890222 | controller -> localhost | The key fingerprint is: 2025-10-03 10:00:04.890242 | controller -> localhost | SHA256:ca2T9LtBBhKICB5bQLxm9TrbM3rChIbeJjyRMlaSwgI zuul-build-sshkey 2025-10-03 10:00:04.890261 | controller -> localhost | The key's randomart image is: 2025-10-03 10:00:04.890280 | controller -> localhost | +---[RSA 3072]----+ 2025-10-03 10:00:04.890298 | controller -> localhost | |+=.o . .. | 2025-10-03 10:00:04.890317 | controller -> localhost | |E.=.. . . . | 2025-10-03 10:00:04.890335 | controller -> localhost | |oo+ . o + . | 2025-10-03 10:00:04.890353 | controller -> localhost | |oB . . = = | 2025-10-03 10:00:04.890371 | controller -> localhost | |* = . S + + | 2025-10-03 10:00:04.890389 | controller -> localhost | |+* + + . | 2025-10-03 10:00:04.890406 | controller -> localhost | |*.= + o | 2025-10-03 10:00:04.890424 | controller -> localhost | | = * = o | 2025-10-03 10:00:04.890442 | controller -> localhost | | +.+ o . | 2025-10-03 10:00:04.890459 | controller -> localhost | +----[SHA256]-----+ 2025-10-03 10:00:04.890507 | controller -> localhost | ok: Runtime: 0:00:00.430355 2025-10-03 10:00:04.896575 | 2025-10-03 10:00:04.896637 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-03 10:00:04.974037 | controller | ok 2025-10-03 10:00:04.995465 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-03 10:00:05.027353 | 2025-10-03 10:00:05.028638 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-03 10:00:05.048754 | controller | skipping: Conditional result was False 2025-10-03 10:00:05.055559 | 2025-10-03 10:00:05.055674 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-03 10:00:05.513949 | controller | changed 2025-10-03 10:00:05.519417 | 2025-10-03 10:00:05.519485 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-03 10:00:05.782367 | controller | ok 2025-10-03 10:00:05.788219 | 2025-10-03 10:00:05.788288 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-03 10:00:06.668646 | controller | changed 2025-10-03 10:00:06.677507 | 2025-10-03 10:00:06.677625 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-03 10:00:07.513708 | controller | changed 2025-10-03 10:00:07.519014 | 2025-10-03 10:00:07.519082 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-03 10:00:07.543566 | controller | skipping: Conditional result was False 2025-10-03 10:00:07.550546 | 2025-10-03 10:00:07.550659 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-03 10:00:07.965401 | controller -> localhost | changed 2025-10-03 10:00:07.976231 | 2025-10-03 10:00:07.976351 | TASK [add-build-sshkey : Add back temp key] 2025-10-03 10:00:08.256071 | controller -> localhost | Identity added: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/b89b58ea4d9d4999b0b29d187b8447b3_id_rsa (zuul-build-sshkey) 2025-10-03 10:00:08.256263 | controller -> localhost | ok: Runtime: 0:00:00.008461 2025-10-03 10:00:08.262650 | 2025-10-03 10:00:08.262767 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-03 10:00:08.638411 | controller | ok 2025-10-03 10:00:08.643074 | 2025-10-03 10:00:08.643139 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-03 10:00:08.676961 | controller | skipping: Conditional result was False 2025-10-03 10:00:08.686797 | 2025-10-03 10:00:08.686887 | TASK [include_role : validate-host] 2025-10-03 10:00:08.706238 | controller | ok 2025-10-03 10:00:08.726618 | 2025-10-03 10:00:08.726716 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-03 10:00:08.755289 | controller | ok 2025-10-03 10:00:08.761335 | 2025-10-03 10:00:08.761407 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-03 10:00:08.988431 | controller -> localhost | ok 2025-10-03 10:00:08.995525 | 2025-10-03 10:00:08.995593 | TASK [validate-host : Collect information about the host] 2025-10-03 10:00:09.826898 | controller | ok 2025-10-03 10:00:09.847500 | 2025-10-03 10:00:09.847599 | TASK [validate-host : Sanitize hostname] 2025-10-03 10:00:09.920460 | controller | ok 2025-10-03 10:00:09.928339 | 2025-10-03 10:00:09.928422 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-03 10:00:10.540999 | controller -> localhost | changed 2025-10-03 10:00:10.548189 | 2025-10-03 10:00:10.548307 | TASK [validate-host : Collect information about zuul worker] 2025-10-03 10:00:11.038272 | controller | ok 2025-10-03 10:00:11.043800 | 2025-10-03 10:00:11.043878 | TASK [validate-host : Write out all zuul information for each host] 2025-10-03 10:00:11.573423 | controller -> localhost | changed 2025-10-03 10:00:11.583816 | 2025-10-03 10:00:11.583900 | TASK [include_role : prepare-workspace-openshift] 2025-10-03 10:00:11.609094 | controller | skipping: Conditional result was False 2025-10-03 10:00:11.615269 | 2025-10-03 10:00:11.615348 | TASK [include_role : remove-zuul-sshkey] 2025-10-03 10:00:11.640173 | controller | skipping: Conditional result was False 2025-10-03 10:00:11.645809 | 2025-10-03 10:00:11.645876 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 10:00:11.904803 | controller | ok: "logs" 2025-10-03 10:00:11.905289 | controller | ok: All items complete 2025-10-03 10:00:11.905334 | 2025-10-03 10:00:12.141783 | controller | ok: "artifacts" 2025-10-03 10:00:12.332712 | controller | ok: "docs" 2025-10-03 10:00:12.340960 | 2025-10-03 10:00:12.341080 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 10:00:12.575455 | controller | changed: "logs" 2025-10-03 10:00:12.776457 | controller | changed: "artifacts" 2025-10-03 10:00:12.996785 | controller | changed: "docs" 2025-10-03 10:00:13.049469 | 2025-10-03 10:00:13.049566 | PLAY RECAP 2025-10-03 10:00:13.049614 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-03 10:00:13.049645 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 10:00:13.049670 | 2025-10-03 10:00:13.244465 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 10:00:13.245260 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 10:00:14.231184 | 2025-10-03 10:00:14.231346 | PLAY [localhost] 2025-10-03 10:00:14.248856 | 2025-10-03 10:00:14.248982 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-03 10:00:14.798432 | localhost | ok 2025-10-03 10:00:14.807297 | 2025-10-03 10:00:14.807437 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-03 10:00:16.032470 | localhost | changed 2025-10-03 10:00:16.083418 | 2025-10-03 10:00:16.083586 | PLAY [all] 2025-10-03 10:00:16.126927 | 2025-10-03 10:00:16.127065 | TASK [include_role : prepare-workspace] 2025-10-03 10:00:16.179379 | controller | ok 2025-10-03 10:00:16.216868 | 2025-10-03 10:00:16.216997 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-03 10:00:16.695405 | controller | ok 2025-10-03 10:00:16.706077 | 2025-10-03 10:00:16.706196 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-03 10:00:18.933031 | controller | Output suppressed because no_log was given 2025-10-03 10:00:18.942990 | 2025-10-03 10:00:18.943089 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 10:00:19.203920 | controller | changed: "logs" 2025-10-03 10:00:19.453631 | controller | changed: "artifacts" 2025-10-03 10:00:19.661415 | controller | changed: "docs" 2025-10-03 10:00:19.695083 | 2025-10-03 10:00:19.695349 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 10:00:19.994616 | controller | changed: "logs" 2025-10-03 10:00:19.994876 | controller | changed: All items complete 2025-10-03 10:00:19.994906 | 2025-10-03 10:00:20.264032 | controller | changed: "artifacts" 2025-10-03 10:00:20.520831 | controller | changed: "docs" 2025-10-03 10:00:20.533172 | 2025-10-03 10:00:20.533279 | TASK [Check if worker can sudo] 2025-10-03 10:00:21.576183 | controller | ok: Runtime: 0:00:00.046625 2025-10-03 10:00:21.585687 | 2025-10-03 10:00:21.585838 | TASK [configure-mirrors : Gather needed facts] 2025-10-03 10:00:21.696666 | controller | skipping: Conditional result was False 2025-10-03 10:00:21.703303 | 2025-10-03 10:00:21.703416 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-03 10:00:21.795624 | controller | ok 2025-10-03 10:00:21.843823 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-03 10:00:21.850050 | 2025-10-03 10:00:21.850155 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-03 10:00:22.132473 | controller | ok 2025-10-03 10:00:22.139459 | 2025-10-03 10:00:22.139543 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-03 10:00:22.251258 | controller | ok: "/var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-03 10:00:22.261380 | 2025-10-03 10:00:22.261489 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-03 10:00:23.249931 | controller | changed 2025-10-03 10:00:23.257674 | 2025-10-03 10:00:23.257786 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-03 10:00:23.315395 | controller | ok: "/var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-03 10:00:23.315566 | controller | ok: All items complete 2025-10-03 10:00:23.315593 | 2025-10-03 10:00:23.368199 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-03 10:00:23.375194 | 2025-10-03 10:00:23.375301 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-03 10:00:24.308132 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-03 10:00:25.189820 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-03 10:00:25.206671 | 2025-10-03 10:00:25.206881 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-03 10:00:25.709419 | controller | changed: section and option added 2025-10-03 10:00:25.737199 | 2025-10-03 10:00:25.737328 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-03 10:00:26.532575 | controller | 29 files removed 2025-10-03 10:00:26.533038 | controller | ok: Item: dnf clean all Runtime: 0:00:00.463861 2025-10-03 10:00:26.533186 | controller | changed: All items complete 2025-10-03 10:00:26.533229 | 2025-10-03 10:00:37.384829 | 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 10:00:37.384961 | controller | DNF version: 4.14.0 2025-10-03 10:00:37.384999 | controller | cachedir: /var/cache/dnf 2025-10-03 10:00:37.385031 | controller | Making cache files for all metadata files. 2025-10-03 10:00:37.385061 | controller | baseos: has expired and will be refreshed. 2025-10-03 10:00:37.385090 | controller | appstream: has expired and will be refreshed. 2025-10-03 10:00:37.385121 | controller | crb: has expired and will be refreshed. 2025-10-03 10:00:37.385167 | controller | extras-common: has expired and will be refreshed. 2025-10-03 10:00:37.385204 | controller | repo: downloading from remote: baseos 2025-10-03 10:00:37.385234 | controller | CentOS Stream 9 - BaseOS 53 MB/s | 8.8 MB 00:00 2025-10-03 10:00:37.385262 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-03 10:00:37.385288 | controller | repo: downloading from remote: appstream 2025-10-03 10:00:37.385319 | controller | CentOS Stream 9 - AppStream 85 MB/s | 25 MB 00:00 2025-10-03 10:00:37.385353 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-03 10:00:37.385387 | controller | repo: downloading from remote: crb 2025-10-03 10:00:37.385422 | controller | CentOS Stream 9 - CRB 81 MB/s | 7.1 MB 00:00 2025-10-03 10:00:37.385457 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-03 10:00:37.385492 | controller | repo: downloading from remote: extras-common 2025-10-03 10:00:37.385528 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-10-03 10:00:37.385562 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-03 10:00:37.385591 | controller | Last metadata expiration check: 0:00:01 ago on Fri 03 Oct 2025 06:00:35 AM EDT. 2025-10-03 10:00:37.385614 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-03 10:00:37.385632 | controller | Completion plugin: Generating completion cache... 2025-10-03 10:00:37.385650 | controller | Metadata cache created. 2025-10-03 10:00:37.385677 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.571586 2025-10-03 10:00:37.414045 | 2025-10-03 10:00:37.414302 | PLAY RECAP 2025-10-03 10:00:37.414356 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-03 10:00:37.414383 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 10:00:37.414402 | 2025-10-03 10:00:37.732155 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 10:00:37.732974 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 10:00:38.426672 | 2025-10-03 10:00:38.426867 | PLAY [all] 2025-10-03 10:00:38.453674 | 2025-10-03 10:00:38.453840 | TASK [Install binary dependencies] 2025-10-03 10:00:38.504189 | controller | ok 2025-10-03 10:00:38.524489 | 2025-10-03 10:00:38.524638 | TASK [bindep : Include find tasks] 2025-10-03 10:00:38.554303 | controller | ok 2025-10-03 10:00:38.562614 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-03 10:00:38.569983 | 2025-10-03 10:00:38.570088 | TASK [bindep : Look for bindep.txt] 2025-10-03 10:00:39.003959 | controller | ok 2025-10-03 10:00:39.011585 | 2025-10-03 10:00:39.011698 | TASK [bindep : Define bindep_file fact] 2025-10-03 10:00:39.067882 | controller | ok 2025-10-03 10:00:39.075588 | 2025-10-03 10:00:39.075693 | TASK [bindep : Look for other-requirements.txt] 2025-10-03 10:00:39.093156 | controller | skipping: Conditional result was False 2025-10-03 10:00:39.102308 | 2025-10-03 10:00:39.102411 | TASK [bindep : Define bindep_file fact] 2025-10-03 10:00:39.129901 | controller | skipping: Conditional result was False 2025-10-03 10:00:39.136548 | 2025-10-03 10:00:39.136641 | TASK [bindep : Look for bindep fallback file] 2025-10-03 10:00:39.173934 | controller | skipping: Conditional result was False 2025-10-03 10:00:39.182929 | 2025-10-03 10:00:39.183062 | TASK [bindep : Define bindep_file fact] 2025-10-03 10:00:39.208238 | controller | skipping: Conditional result was False 2025-10-03 10:00:39.223107 | 2025-10-03 10:00:39.223449 | TASK [bindep : Include bindep tasks] 2025-10-03 10:00:39.273238 | controller | ok 2025-10-03 10:00:39.280848 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-03 10:00:39.290623 | 2025-10-03 10:00:39.290784 | TASK [bindep : Look for bindep command] 2025-10-03 10:00:39.320219 | controller | skipping: Conditional result was False 2025-10-03 10:00:39.326925 | 2025-10-03 10:00:39.327027 | TASK [bindep : Check for system bindep] 2025-10-03 10:00:39.858551 | controller | ok: Runtime: 0:00:00.007740 2025-10-03 10:00:39.872640 | 2025-10-03 10:00:39.872792 | TASK [bindep : Define bindep_command fact] 2025-10-03 10:00:39.898507 | controller | skipping: Conditional result was False 2025-10-03 10:00:39.907691 | 2025-10-03 10:00:39.907845 | TASK [bindep : Include install tasks] 2025-10-03 10:00:39.952866 | controller | ok 2025-10-03 10:00:39.961748 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-03 10:00:39.971420 | 2025-10-03 10:00:39.971567 | TASK [bindep : Create temp dir for bindep] 2025-10-03 10:00:40.409073 | controller | changed 2025-10-03 10:00:40.415242 | 2025-10-03 10:00:40.415321 | TASK [Ensure we have pip dependencies] 2025-10-03 10:00:40.444965 | controller | ok 2025-10-03 10:00:40.469744 | 2025-10-03 10:00:40.469851 | TASK [ensure-pip : Check if pip is installed] 2025-10-03 06:00:40.765528 | controller | /usr/bin/pip3 2025-10-03 06:00:40.791775 | controller | /usr/bin/python3: No module named wheel 2025-10-03 10:00:41.000587 | controller | ok: Runtime: 0:00:00.038366 2025-10-03 10:00:41.006854 | 2025-10-03 10:00:41.007067 | LOOP [ensure-pip : Install pip from packages] 2025-10-03 10:00:41.035065 | controller | ok: "/var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-03 10:00:41.050924 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-03 10:00:41.063259 | 2025-10-03 10:00:41.063413 | TASK [ensure-pip : Install Python 3 pip] 2025-10-03 10:00:43.542081 | controller | changed 2025-10-03 10:00:43.549009 | 2025-10-03 10:00:43.549117 | TASK [ensure-pip : Check for EPEL repository] 2025-10-03 10:00:43.622455 | controller | skipping: Conditional result was False 2025-10-03 10:00:43.633471 | 2025-10-03 10:00:43.633614 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-03 10:00:43.678446 | controller | skipping: Conditional result was False 2025-10-03 10:00:43.685067 | 2025-10-03 10:00:43.685184 | TASK [ensure-pip : Install Python 2 pip] 2025-10-03 10:00:43.761103 | controller | skipping: Conditional result was False 2025-10-03 10:00:43.767689 | 2025-10-03 10:00:43.767809 | TASK [ensure-pip : Ensure setuptools] 2025-10-03 10:00:43.782574 | controller | skipping: Conditional result was False 2025-10-03 10:00:43.789902 | 2025-10-03 10:00:43.790063 | TASK [ensure-pip : Check for ensurepip module] 2025-10-03 10:00:44.325425 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.340763 | 2025-10-03 10:00:44.340928 | TASK [ensure-pip : Ensure python3-venv] 2025-10-03 10:00:44.376482 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.386091 | 2025-10-03 10:00:44.386219 | TASK [ensure-pip : Install pip from source] 2025-10-03 10:00:44.421976 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.429217 | 2025-10-03 10:00:44.429333 | TASK [ensure-pip : Probe for venv python full path] 2025-10-03 06:00:44.677393 | controller | /usr/bin/python3 2025-10-03 10:00:44.972206 | controller | ok: Runtime: 0:00:00.005756 2025-10-03 10:00:44.978438 | 2025-10-03 10:00:44.978507 | TASK [ensure-pip : Set host default] 2025-10-03 10:00:45.028275 | controller | ok 2025-10-03 10:00:45.034020 | 2025-10-03 10:00:45.034096 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-03 10:00:45.086282 | controller | ok 2025-10-03 10:00:45.099852 | 2025-10-03 10:00:45.099968 | TASK [bindep : Install bindep into temporary venv] 2025-10-03 10:00:49.221858 | controller | changed 2025-10-03 10:00:49.231290 | 2025-10-03 10:00:49.231398 | TASK [bindep : Define bindep_command] 2025-10-03 10:00:49.273151 | controller | ok 2025-10-03 10:00:49.279245 | 2025-10-03 10:00:49.279323 | LOOP [bindep : Include package tasks] 2025-10-03 10:00:49.326702 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-03 10:00:49.326969 | controller | ok: All items complete 2025-10-03 10:00:49.326998 | 2025-10-03 10:00:49.346097 | controller | included: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-03 10:00:49.358991 | 2025-10-03 10:00:49.359255 | TASK [bindep : Define bindep_run fact] 2025-10-03 10:00:49.389855 | controller | ok 2025-10-03 10:00:49.396792 | 2025-10-03 10:00:49.396883 | TASK [bindep : Get list of packages to install from bindep] 2025-10-03 06:00:50.657297 | controller | podman 2025-10-03 06:00:50.707044 | controller | python3-jmespath 2025-10-03 06:00:50.707127 | controller | python3-libvirt 2025-10-03 06:00:50.707145 | controller | python3-lxml 2025-10-03 06:00:50.707257 | controller | python3-netaddr 2025-10-03 10:00:50.932608 | controller | ok: Runtime: 0:00:01.057525 2025-10-03 10:00:50.946755 | 2025-10-03 10:00:50.946983 | TASK [bindep : Install distro packages from bindep] 2025-10-03 10:01:53.852294 | controller | changed 2025-10-03 10:01:53.871190 | 2025-10-03 10:01:53.871376 | TASK [bindep : Check that packages are installed] 2025-10-03 10:01:55.430123 | controller | ok: Runtime: 0:00:01.135559 2025-10-03 10:01:55.439285 | 2025-10-03 10:01:55.439625 | TASK [bindep : Fail if we cannot install all packages] 2025-10-03 10:01:55.474867 | controller | skipping: Conditional result was False 2025-10-03 10:01:55.491469 | 2025-10-03 10:01:55.491590 | TASK [Run test-setup role] 2025-10-03 10:01:55.514744 | controller | ok 2025-10-03 10:01:55.540364 | 2025-10-03 10:01:55.540593 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-03 10:01:55.767138 | controller | ok 2025-10-03 10:01:55.779935 | 2025-10-03 10:01:55.780108 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-03 10:01:56.325833 | controller | skipping: Conditional result was False 2025-10-03 10:01:56.385151 | 2025-10-03 10:01:56.385357 | TASK [bindep : Remove bindep temp dir] 2025-10-03 10:01:56.820048 | controller | ok 2025-10-03 10:01:56.830635 | 2025-10-03 10:01:56.830751 | PLAY RECAP 2025-10-03 10:01:56.830798 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-03 10:01:56.830820 | 2025-10-03 10:01:56.963053 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 10:01:56.964162 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 10:01:57.668098 | 2025-10-03 10:01:57.668249 | PLAY [all] 2025-10-03 10:01:57.698521 | 2025-10-03 10:01:57.698679 | TASK [Abort when test_command variable is undefined] 2025-10-03 10:01:57.724482 | controller | skipping: Conditional result was False 2025-10-03 10:01:57.730472 | 2025-10-03 10:01:57.730572 | TASK [Convert test_command to list] 2025-10-03 10:01:57.805482 | controller | skipping: Conditional result was False 2025-10-03 10:01:57.812648 | 2025-10-03 10:01:57.812881 | TASK [Use test_command list] 2025-10-03 10:01:57.862848 | controller | ok 2025-10-03 10:01:57.868634 | 2025-10-03 10:01:57.868720 | LOOP [Run test_command] 2025-10-03 10:01:58.333402 | controller | no check to run 2025-10-03 10:01:58.334895 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006422 2025-10-03 10:01:58.395347 | 2025-10-03 10:01:58.395458 | PLAY RECAP 2025-10-03 10:01:58.395517 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 10:01:58.395556 | 2025-10-03 10:01:58.542601 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 10:01:58.543785 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 10:01:59.289303 | 2025-10-03 10:01:59.289438 | PLAY [all] 2025-10-03 10:01:59.310845 | 2025-10-03 10:01:59.310945 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-03 10:01:59.716278 | controller | changed: non-zero return code 2025-10-03 10:01:59.721856 | 2025-10-03 10:01:59.721959 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-03 10:01:59.775955 | controller | skipping: Conditional result was False 2025-10-03 10:01:59.785995 | 2025-10-03 10:01:59.786129 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-03 10:01:59.821109 | 2025-10-03 10:01:59.821283 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-03 10:01:59.852893 | 2025-10-03 10:01:59.853061 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-03 10:01:59.867415 | controller | skipping: Conditional result was False 2025-10-03 10:01:59.875209 | 2025-10-03 10:01:59.875310 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-03 10:01:59.902645 | 2025-10-03 10:01:59.902897 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-03 10:01:59.919953 | controller | skipping: Conditional result was False 2025-10-03 10:01:59.927425 | 2025-10-03 10:01:59.927511 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-03 10:01:59.943701 | controller | skipping: Conditional result was False 2025-10-03 10:01:59.950404 | 2025-10-03 10:01:59.950470 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-03 10:01:59.995184 | controller | skipping: Conditional result was False 2025-10-03 10:02:00.025787 | 2025-10-03 10:02:00.025872 | PLAY RECAP 2025-10-03 10:02:00.025911 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-03 10:02:00.025932 | 2025-10-03 10:02:00.137138 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 10:02:00.138042 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 10:02:00.827480 | 2025-10-03 10:02:00.827611 | PLAY [all] 2025-10-03 10:02:00.851622 | 2025-10-03 10:02:00.851762 | TASK [include_role : fetch-output] 2025-10-03 10:02:00.882547 | controller | ok 2025-10-03 10:02:00.904767 | 2025-10-03 10:02:00.904920 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-03 10:02:00.981028 | controller | skipping: Conditional result was False 2025-10-03 10:02:00.988425 | 2025-10-03 10:02:00.988537 | TASK [fetch-output : Set log path for single node] 2025-10-03 10:02:01.061417 | controller | ok 2025-10-03 10:02:01.068109 | 2025-10-03 10:02:01.068192 | LOOP [fetch-output : Ensure local output dirs] 2025-10-03 10:02:01.686359 | controller -> localhost | ok: "/var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/logs" 2025-10-03 10:02:01.972900 | controller -> localhost | changed: "/var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/artifacts" 2025-10-03 10:02:02.427454 | controller -> localhost | changed: "/var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/docs" 2025-10-03 10:02:02.437939 | 2025-10-03 10:02:02.438057 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-03 10:02:03.267195 | controller | changed: .d..t...... ./ 2025-10-03 10:02:03.267415 | controller | changed: All items complete 2025-10-03 10:02:03.267443 | 2025-10-03 10:02:03.985826 | controller | changed: .d..t...... ./ 2025-10-03 10:02:04.466613 | controller | changed: .d..t...... ./ 2025-10-03 10:02:04.488388 | 2025-10-03 10:02:04.488510 | TASK [include_role : fetch-output-openshift] 2025-10-03 10:02:04.503817 | controller | skipping: Conditional result was False 2025-10-03 10:02:04.510078 | 2025-10-03 10:02:04.510164 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-03 10:02:05.116387 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.035691 2025-10-03 10:02:05.385547 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.031803 2025-10-03 10:02:05.433388 | 2025-10-03 10:02:05.433521 | PLAY [all] 2025-10-03 10:02:05.468904 | 2025-10-03 10:02:05.469027 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-03 10:02:05.900933 | controller | changed 2025-10-03 10:02:05.933937 | 2025-10-03 10:02:05.934049 | PLAY RECAP 2025-10-03 10:02:05.934090 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 10:02:05.934111 | 2025-10-03 10:02:06.046578 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 10:02:06.047672 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-03 10:02:06.736802 | 2025-10-03 10:02:06.736928 | PLAY [localhost] 2025-10-03 10:02:06.756829 | 2025-10-03 10:02:06.756953 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-03 10:02:07.135507 | localhost | changed 2025-10-03 10:02:07.140355 | 2025-10-03 10:02:07.140431 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-03 10:02:07.170718 | localhost | ok 2025-10-03 10:02:07.179275 | 2025-10-03 10:02:07.179369 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-03 10:02:07.590555 | localhost | changed 2025-10-03 10:02:07.596398 | 2025-10-03 10:02:07.596471 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-03 10:02:08.293535 | localhost | changed 2025-10-03 10:02:08.299210 | 2025-10-03 10:02:08.299337 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-03 10:02:08.854712 | localhost | Identity added: /var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/tmp/ansible.mjlf3pae (/var/lib/zuul/builds/b89b58ea4d9d4999b0b29d187b8447b3/work/tmp/ansible.mjlf3pae) 2025-10-03 10:02:08.854941 | localhost | ok: Runtime: 0:00:00.023977 2025-10-03 10:02:08.860189 | 2025-10-03 10:02:08.860262 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-03 10:02:09.327638 | localhost | ok: Runtime: 0:00:00.023100 2025-10-03 10:02:09.333256 | 2025-10-03 10:02:09.333322 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-03 10:02:09.414244 | localhost | changed 2025-10-03 10:02:09.419111 | 2025-10-03 10:02:09.419183 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-03 10:02:09.946801 | localhost | changed 2025-10-03 10:02:09.979109 | 2025-10-03 10:02:09.979214 | PLAY [localhost] 2025-10-03 10:02:10.006477 | 2025-10-03 10:02:10.006581 | TASK [Generate bulk log download script] 2025-10-03 10:02:10.035906 | localhost | ok 2025-10-03 10:02:10.049133 | 2025-10-03 10:02:10.049255 | TASK [local-log-download : Check API endpoint is defined] 2025-10-03 10:02:10.080983 | localhost | ok: All assertions passed 2025-10-03 10:02:10.085903 | 2025-10-03 10:02:10.085981 | TASK [local-log-download : Create download script] 2025-10-03 10:02:10.799115 | localhost -> localhost | changed 2025-10-03 10:02:10.810144 | 2025-10-03 10:02:10.810233 | TASK [Register quick-download link] 2025-10-03 10:02:10.912693 | localhost | ok 2025-10-03 10:02:10.941994 | 2025-10-03 10:02:10.942104 | PLAY [logserver.rdoproject.org] 2025-10-03 10:02:10.969179 | 2025-10-03 10:02:10.969291 | TASK [Set zuul-log-path fact] 2025-10-03 10:02:11.012296 | logserver.rdoproject.org | ok 2025-10-03 10:02:11.024043 | 2025-10-03 10:02:11.024141 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 10:02:11.062313 | logserver.rdoproject.org | ok 2025-10-03 10:02:11.068972 | 2025-10-03 10:02:11.069057 | TASK [upload-logs : Create log directories] 2025-10-03 10:02:11.701287 | logserver.rdoproject.org | changed 2025-10-03 10:02:11.711853 | 2025-10-03 10:02:11.711960 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-03 10:02:11.985353 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007856 2025-10-03 10:02:11.992333 | 2025-10-03 10:02:11.992420 | TASK [upload-logs : Upload logs to log server] 2025-10-03 10:02:12.624142 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-03 10:02:12.627838 | 2025-10-03 10:02:12.627954 | LOOP [upload-logs : Compress console log and json output] 2025-10-03 10:02:12.684424 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:12.685326 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:12.697551 | 2025-10-03 10:02:12.697683 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-03 10:02:12.742340 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:12.742771 | 2025-10-03 10:02:12.743301 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:12.756230 | 2025-10-03 10:02:12.756333 | LOOP [upload-logs : Upload console log and json output]