2025-10-02 15:27:59.216765 | Job console starting... 2025-10-02 15:27:59.228961 | Updating repositories 2025-10-02 15:27:59.263783 | Preparing job workspace 2025-10-02 15:28:02.800559 | Running Ansible setup... 2025-10-02 15:28:07.144792 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 15:28:07.752075 | 2025-10-02 15:28:07.752236 | PLAY [localhost] 2025-10-02 15:28:07.767793 | 2025-10-02 15:28:07.767909 | TASK [Gathering Facts] 2025-10-02 15:28:08.856055 | localhost | ok 2025-10-02 15:28:08.869578 | 2025-10-02 15:28:08.869681 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 15:28:09.342580 | localhost -> localhost | changed 2025-10-02 15:28:09.348103 | 2025-10-02 15:28:09.348183 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 15:28:10.542053 | localhost -> localhost | changed 2025-10-02 15:28:10.562434 | 2025-10-02 15:28:10.562575 | TASK [Setup log path fact] 2025-10-02 15:28:10.601160 | localhost | ok 2025-10-02 15:28:10.615821 | 2025-10-02 15:28:10.615932 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 15:28:10.649169 | localhost | ok 2025-10-02 15:28:10.659529 | 2025-10-02 15:28:10.659614 | TASK [emit-job-header : Print job information] 2025-10-02 15:28:10.698912 | # Job Information 2025-10-02 15:28:10.699046 | Ansible Version: 2.15.12 2025-10-02 15:28:10.699073 | Job: cifmw-molecule-cifmw_setup 2025-10-02 15:28:10.699092 | Pipeline: github-check 2025-10-02 15:28:10.699112 | Executor: ze02.softwarefactory-project.io 2025-10-02 15:28:10.699129 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 15:28:10.699148 | Log URL (when completed): https://logserver.rdoproject.org/a67/rdoproject.org/a67b53b2347142e2a8e7e71b55bf1ab9/ 2025-10-02 15:28:10.699166 | Event ID: 31e612e0-9fa4-11f0-8bb8-66cf2469bdc9 2025-10-02 15:28:10.703139 | 2025-10-02 15:28:10.703208 | LOOP [emit-job-header : Print node information] 2025-10-02 15:28:10.829430 | localhost | ok: 2025-10-02 15:28:10.829606 | localhost | # Node Information 2025-10-02 15:28:10.829641 | localhost | Inventory Hostname: controller 2025-10-02 15:28:10.831714 | localhost | Hostname: np0005466609 2025-10-02 15:28:10.831760 | localhost | Username: zuul 2025-10-02 15:28:10.831786 | localhost | Distro: CentOS 9 2025-10-02 15:28:10.831804 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 15:28:10.831822 | localhost | Region: RegionOne 2025-10-02 15:28:10.831839 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 15:28:10.831856 | localhost | Product Name: OpenStack Nova 2025-10-02 15:28:10.831872 | localhost | Interface IP: 38.102.83.130 2025-10-02 15:28:10.875312 | 2025-10-02 15:28:10.875408 | PLAY [all] 2025-10-02 15:28:10.895321 | 2025-10-02 15:28:10.895435 | TASK [Gather network facts] 2025-10-02 15:28:11.469343 | controller | ok 2025-10-02 15:28:11.485633 | 2025-10-02 15:28:11.485762 | TASK [include_role : start-zuul-console] 2025-10-02 15:28:11.509689 | controller | ok 2025-10-02 15:28:11.530918 | 2025-10-02 15:28:11.531001 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 15:28:11.951762 | controller | ok 2025-10-02 15:28:11.970632 | 2025-10-02 15:28:11.970732 | TASK [include_role : add-build-sshkey] 2025-10-02 15:28:12.009395 | controller | ok 2025-10-02 15:28:12.025574 | 2025-10-02 15:28:12.025648 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 15:28:12.342118 | controller -> localhost | ok 2025-10-02 15:28:12.351071 | 2025-10-02 15:28:12.351136 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 15:28:12.380274 | controller | ok 2025-10-02 15:28:12.401529 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 15:28:12.408042 | 2025-10-02 15:28:12.408105 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 15:28:13.194687 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 15:28:13.194905 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/a67b53b2347142e2a8e7e71b55bf1ab9_id_rsa. 2025-10-02 15:28:13.194938 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/a67b53b2347142e2a8e7e71b55bf1ab9_id_rsa.pub. 2025-10-02 15:28:13.194960 | controller -> localhost | The key fingerprint is: 2025-10-02 15:28:13.194979 | controller -> localhost | SHA256:xXkRoSMvycZnCPpLtwsZedTuGsPsU1j8wXj2ch/AGWQ zuul-build-sshkey 2025-10-02 15:28:13.194998 | controller -> localhost | The key's randomart image is: 2025-10-02 15:28:13.195018 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 15:28:13.195038 | controller -> localhost | | =E | 2025-10-02 15:28:13.195055 | controller -> localhost | | o o.o | 2025-10-02 15:28:13.195072 | controller -> localhost | | . o.Boo o | 2025-10-02 15:28:13.195089 | controller -> localhost | | . * B+o=+ | 2025-10-02 15:28:13.195106 | controller -> localhost | | . o So=+ o. | 2025-10-02 15:28:13.195122 | controller -> localhost | | . B.=. o o. | 2025-10-02 15:28:13.195138 | controller -> localhost | | = *.. o ..| 2025-10-02 15:28:13.195155 | controller -> localhost | | . =.= .| 2025-10-02 15:28:13.195170 | controller -> localhost | | . =o | 2025-10-02 15:28:13.195187 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 15:28:13.195228 | controller -> localhost | ok: Runtime: 0:00:00.275589 2025-10-02 15:28:13.201315 | 2025-10-02 15:28:13.201379 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 15:28:13.220145 | controller | ok 2025-10-02 15:28:13.234613 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 15:28:13.244529 | 2025-10-02 15:28:13.244597 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 15:28:13.312869 | controller | skipping: Conditional result was False 2025-10-02 15:28:13.318770 | 2025-10-02 15:28:13.318836 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 15:28:13.812166 | controller | changed 2025-10-02 15:28:13.818831 | 2025-10-02 15:28:13.818899 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 15:28:14.051132 | controller | ok 2025-10-02 15:28:14.056496 | 2025-10-02 15:28:14.056559 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 15:28:14.890372 | controller | changed 2025-10-02 15:28:14.898047 | 2025-10-02 15:28:14.898150 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 15:28:15.833921 | controller | changed 2025-10-02 15:28:15.840390 | 2025-10-02 15:28:15.840454 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 15:28:15.864157 | controller | skipping: Conditional result was False 2025-10-02 15:28:15.870151 | 2025-10-02 15:28:15.870217 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 15:28:16.376125 | controller -> localhost | changed 2025-10-02 15:28:16.385773 | 2025-10-02 15:28:16.385835 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 15:28:16.665131 | controller -> localhost | Identity added: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/a67b53b2347142e2a8e7e71b55bf1ab9_id_rsa (zuul-build-sshkey) 2025-10-02 15:28:16.665353 | controller -> localhost | ok: Runtime: 0:00:00.009117 2025-10-02 15:28:16.672709 | 2025-10-02 15:28:16.672831 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 15:28:17.229889 | controller | ok 2025-10-02 15:28:17.253124 | 2025-10-02 15:28:17.253214 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 15:28:17.316888 | controller | skipping: Conditional result was False 2025-10-02 15:28:17.329111 | 2025-10-02 15:28:17.329183 | TASK [include_role : validate-host] 2025-10-02 15:28:17.370997 | controller | ok 2025-10-02 15:28:17.407976 | 2025-10-02 15:28:17.408081 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 15:28:17.457424 | controller | ok 2025-10-02 15:28:17.461992 | 2025-10-02 15:28:17.462058 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 15:28:17.726007 | controller -> localhost | ok 2025-10-02 15:28:17.764467 | 2025-10-02 15:28:17.764603 | TASK [validate-host : Collect information about the host] 2025-10-02 15:28:18.529172 | controller | ok 2025-10-02 15:28:18.540498 | 2025-10-02 15:28:18.540566 | TASK [validate-host : Sanitize hostname] 2025-10-02 15:28:18.599124 | controller | ok 2025-10-02 15:28:18.603919 | 2025-10-02 15:28:18.603991 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 15:28:19.157583 | controller -> localhost | changed 2025-10-02 15:28:19.164260 | 2025-10-02 15:28:19.164365 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 15:28:19.542159 | controller | ok 2025-10-02 15:28:19.549182 | 2025-10-02 15:28:19.549294 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 15:28:20.032467 | controller -> localhost | changed 2025-10-02 15:28:20.047090 | 2025-10-02 15:28:20.047192 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 15:28:20.061885 | controller | skipping: Conditional result was False 2025-10-02 15:28:20.067189 | 2025-10-02 15:28:20.067251 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 15:28:20.091163 | controller | skipping: Conditional result was False 2025-10-02 15:28:20.096379 | 2025-10-02 15:28:20.096441 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 15:28:20.344888 | controller | ok: "logs" 2025-10-02 15:28:20.345290 | controller | ok: All items complete 2025-10-02 15:28:20.345353 | 2025-10-02 15:28:20.576498 | controller | ok: "artifacts" 2025-10-02 15:28:20.804351 | controller | ok: "docs" 2025-10-02 15:28:20.821054 | 2025-10-02 15:28:20.821184 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 15:28:21.083393 | controller | changed: "logs" 2025-10-02 15:28:21.367275 | controller | changed: "artifacts" 2025-10-02 15:28:21.616201 | controller | changed: "docs" 2025-10-02 15:28:21.703882 | 2025-10-02 15:28:21.703967 | PLAY RECAP 2025-10-02 15:28:21.704010 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 15:28:21.704036 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 15:28:21.704054 | 2025-10-02 15:28:21.838625 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 15:28:21.839574 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 15:28:22.452758 | 2025-10-02 15:28:22.452871 | PLAY [localhost] 2025-10-02 15:28:22.468993 | 2025-10-02 15:28:22.469066 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 15:28:22.916899 | localhost | ok 2025-10-02 15:28:22.921913 | 2025-10-02 15:28:22.921985 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 15:28:23.571785 | localhost | changed 2025-10-02 15:28:23.612384 | 2025-10-02 15:28:23.612545 | PLAY [all] 2025-10-02 15:28:23.633558 | 2025-10-02 15:28:23.633643 | TASK [include_role : prepare-workspace] 2025-10-02 15:28:23.668436 | controller | ok 2025-10-02 15:28:23.689619 | 2025-10-02 15:28:23.689729 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 15:28:24.106169 | controller | ok 2025-10-02 15:28:24.112782 | 2025-10-02 15:28:24.112847 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 15:28:26.030316 | controller | Output suppressed because no_log was given 2025-10-02 15:28:26.043841 | 2025-10-02 15:28:26.043968 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 15:28:26.297939 | controller | changed: "logs" 2025-10-02 15:28:26.549619 | controller | changed: "artifacts" 2025-10-02 15:28:26.819615 | controller | changed: "docs" 2025-10-02 15:28:26.846129 | 2025-10-02 15:28:26.846350 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 15:28:27.145014 | controller | changed: "logs" 2025-10-02 15:28:27.145320 | controller | changed: All items complete 2025-10-02 15:28:27.145357 | 2025-10-02 15:28:27.409024 | controller | changed: "artifacts" 2025-10-02 15:28:27.665647 | controller | changed: "docs" 2025-10-02 15:28:27.699965 | 2025-10-02 15:28:27.700207 | TASK [Check if worker can sudo] 2025-10-02 15:28:28.249160 | controller | ok: Runtime: 0:00:00.049996 2025-10-02 15:28:28.254657 | 2025-10-02 15:28:28.254740 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 15:28:28.329083 | controller | skipping: Conditional result was False 2025-10-02 15:28:28.335327 | 2025-10-02 15:28:28.335421 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 15:28:28.394815 | controller | ok 2025-10-02 15:28:28.403272 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 15:28:28.433870 | 2025-10-02 15:28:28.433964 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 15:28:28.681900 | controller | ok 2025-10-02 15:28:28.702358 | 2025-10-02 15:28:28.702595 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 15:28:28.779842 | controller | ok: "/var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 15:28:28.790154 | 2025-10-02 15:28:28.790314 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 15:28:29.634012 | controller | changed 2025-10-02 15:28:29.640368 | 2025-10-02 15:28:29.640461 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 15:28:29.688480 | controller | ok: "/var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 15:28:29.688715 | controller | ok: All items complete 2025-10-02 15:28:29.688748 | 2025-10-02 15:28:29.736716 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 15:28:29.743919 | 2025-10-02 15:28:29.744013 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 15:28:30.684234 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 15:28:31.562647 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 15:28:31.579865 | 2025-10-02 15:28:31.579971 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 15:28:32.082726 | controller | changed: section and option added 2025-10-02 15:28:32.119500 | 2025-10-02 15:28:32.119618 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 15:28:32.931109 | controller | 29 files removed 2025-10-02 15:28:32.931329 | controller | ok: Item: dnf clean all Runtime: 0:00:00.485207 2025-10-02 15:28:32.931370 | controller | changed: All items complete 2025-10-02 15:28:32.931391 | 2025-10-02 15:28:44.212861 | 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-02 15:28:44.213018 | controller | DNF version: 4.14.0 2025-10-02 15:28:44.213067 | controller | cachedir: /var/cache/dnf 2025-10-02 15:28:44.213107 | controller | Making cache files for all metadata files. 2025-10-02 15:28:44.213146 | controller | baseos: has expired and will be refreshed. 2025-10-02 15:28:44.213184 | controller | appstream: has expired and will be refreshed. 2025-10-02 15:28:44.213219 | controller | crb: has expired and will be refreshed. 2025-10-02 15:28:44.213268 | controller | extras-common: has expired and will be refreshed. 2025-10-02 15:28:44.213304 | controller | repo: downloading from remote: baseos 2025-10-02 15:28:44.213340 | controller | CentOS Stream 9 - BaseOS 78 MB/s | 8.8 MB 00:00 2025-10-02 15:28:44.213376 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 15:28:44.213413 | controller | repo: downloading from remote: appstream 2025-10-02 15:28:44.213450 | controller | CentOS Stream 9 - AppStream 143 MB/s | 25 MB 00:00 2025-10-02 15:28:44.213487 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 15:28:44.213522 | controller | repo: downloading from remote: crb 2025-10-02 15:28:44.213557 | controller | CentOS Stream 9 - CRB 102 MB/s | 7.1 MB 00:00 2025-10-02 15:28:44.213593 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 15:28:44.213630 | controller | repo: downloading from remote: extras-common 2025-10-02 15:28:44.213687 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-10-02 15:28:44.213735 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 15:28:44.213774 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 15:28:44.213810 | controller | Completion plugin: Generating completion cache... 2025-10-02 15:28:44.213848 | controller | Metadata cache created. 2025-10-02 15:28:44.213901 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.003690 2025-10-02 15:28:44.227962 | 2025-10-02 15:28:44.228074 | PLAY RECAP 2025-10-02 15:28:44.228117 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 15:28:44.228142 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 15:28:44.228160 | 2025-10-02 15:28:44.328374 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 15:28:44.330062 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 15:28:44.861605 | 2025-10-02 15:28:44.861734 | PLAY [all] 2025-10-02 15:28:44.882923 | 2025-10-02 15:28:44.883015 | TASK [Install binary dependencies] 2025-10-02 15:28:44.948444 | controller | ok 2025-10-02 15:28:44.973035 | 2025-10-02 15:28:44.973141 | TASK [bindep : Include find tasks] 2025-10-02 15:28:45.013131 | controller | ok 2025-10-02 15:28:45.020574 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 15:28:45.026392 | 2025-10-02 15:28:45.026453 | TASK [bindep : Look for bindep.txt] 2025-10-02 15:28:45.458764 | controller | ok 2025-10-02 15:28:45.474438 | 2025-10-02 15:28:45.474596 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:45.527408 | controller | ok 2025-10-02 15:28:45.539350 | 2025-10-02 15:28:45.539492 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 15:28:45.568040 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.582172 | 2025-10-02 15:28:45.582323 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:45.611303 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.624946 | 2025-10-02 15:28:45.625095 | TASK [bindep : Look for bindep fallback file] 2025-10-02 15:28:45.652618 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.666641 | 2025-10-02 15:28:45.666823 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:45.693894 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.707063 | 2025-10-02 15:28:45.707231 | TASK [bindep : Include bindep tasks] 2025-10-02 15:28:45.757874 | controller | ok 2025-10-02 15:28:45.767502 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 15:28:45.778837 | 2025-10-02 15:28:45.778925 | TASK [bindep : Look for bindep command] 2025-10-02 15:28:45.814615 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.828768 | 2025-10-02 15:28:45.828905 | TASK [bindep : Check for system bindep] 2025-10-02 15:28:46.375448 | controller | ok: Runtime: 0:00:00.006292 2025-10-02 15:28:46.389285 | 2025-10-02 15:28:46.389475 | TASK [bindep : Define bindep_command fact] 2025-10-02 15:28:46.427116 | controller | skipping: Conditional result was False 2025-10-02 15:28:46.440994 | 2025-10-02 15:28:46.441136 | TASK [bindep : Include install tasks] 2025-10-02 15:28:46.491302 | controller | ok 2025-10-02 15:28:46.509995 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 15:28:46.534395 | 2025-10-02 15:28:46.534602 | TASK [bindep : Create temp dir for bindep] 2025-10-02 15:28:46.986875 | controller | changed 2025-10-02 15:28:47.004066 | 2025-10-02 15:28:47.004293 | TASK [Ensure we have pip dependencies] 2025-10-02 15:28:47.036956 | controller | ok 2025-10-02 15:28:47.079990 | 2025-10-02 15:28:47.080136 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 11:28:47.422124 | controller | /usr/bin/pip3 2025-10-02 11:28:47.448321 | controller | /usr/bin/python3: No module named wheel 2025-10-02 15:28:47.614123 | controller | ok: Runtime: 0:00:00.039985 2025-10-02 15:28:47.633875 | 2025-10-02 15:28:47.634246 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 15:28:47.694226 | controller | ok: "/var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 15:28:47.724126 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 15:28:47.739252 | 2025-10-02 15:28:47.739350 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 15:28:50.832248 | controller | changed 2025-10-02 15:28:50.844137 | 2025-10-02 15:28:50.844433 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 15:28:50.883338 | controller | skipping: Conditional result was False 2025-10-02 15:28:50.898525 | 2025-10-02 15:28:50.898761 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 15:28:50.937617 | controller | skipping: Conditional result was False 2025-10-02 15:28:50.947563 | 2025-10-02 15:28:50.947719 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 15:28:50.984031 | controller | skipping: Conditional result was False 2025-10-02 15:28:50.993194 | 2025-10-02 15:28:50.993306 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 15:28:51.008884 | controller | skipping: Conditional result was False 2025-10-02 15:28:51.017851 | 2025-10-02 15:28:51.017963 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 15:28:51.562812 | controller | skipping: Conditional result was False 2025-10-02 15:28:51.573126 | 2025-10-02 15:28:51.573227 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 15:28:51.605011 | controller | skipping: Conditional result was False 2025-10-02 15:28:51.611738 | 2025-10-02 15:28:51.611824 | TASK [ensure-pip : Install pip from source] 2025-10-02 15:28:51.629032 | controller | skipping: Conditional result was False 2025-10-02 15:28:51.635201 | 2025-10-02 15:28:51.635271 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 11:28:51.883436 | controller | /usr/bin/python3 2025-10-02 15:28:52.164263 | controller | ok: Runtime: 0:00:00.005567 2025-10-02 15:28:52.176607 | 2025-10-02 15:28:52.176797 | TASK [ensure-pip : Set host default] 2025-10-02 15:28:52.225503 | controller | ok 2025-10-02 15:28:52.236697 | 2025-10-02 15:28:52.237005 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 15:28:52.288264 | controller | ok 2025-10-02 15:28:52.306855 | 2025-10-02 15:28:52.306951 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 15:28:57.721988 | controller | changed 2025-10-02 15:28:57.734181 | 2025-10-02 15:28:57.734268 | TASK [bindep : Define bindep_command] 2025-10-02 15:28:57.795130 | controller | ok 2025-10-02 15:28:57.804606 | 2025-10-02 15:28:57.804690 | LOOP [bindep : Include package tasks] 2025-10-02 15:28:57.848552 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 15:28:57.848829 | controller | ok: All items complete 2025-10-02 15:28:57.848860 | 2025-10-02 15:28:57.867427 | controller | included: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 15:28:57.885891 | 2025-10-02 15:28:57.885981 | TASK [bindep : Define bindep_run fact] 2025-10-02 15:28:57.918055 | controller | ok 2025-10-02 15:28:57.929452 | 2025-10-02 15:28:57.929553 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 11:28:59.471592 | controller | podman 2025-10-02 11:28:59.507560 | controller | python3-jmespath 2025-10-02 11:28:59.507745 | controller | python3-libvirt 2025-10-02 11:28:59.507767 | controller | python3-lxml 2025-10-02 11:28:59.507781 | controller | python3-netaddr 2025-10-02 15:28:59.984020 | controller | ok: Runtime: 0:00:01.316367 2025-10-02 15:28:59.989588 | 2025-10-02 15:28:59.989649 | TASK [bindep : Install distro packages from bindep] 2025-10-02 15:30:15.355397 | controller | changed 2025-10-02 15:30:15.366899 | 2025-10-02 15:30:15.366965 | TASK [bindep : Check that packages are installed] 2025-10-02 15:30:17.410860 | controller | ok: Runtime: 0:00:01.314571 2025-10-02 15:30:17.417050 | 2025-10-02 15:30:17.417130 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 15:30:17.441384 | controller | skipping: Conditional result was False 2025-10-02 15:30:17.452876 | 2025-10-02 15:30:17.452962 | TASK [Run test-setup role] 2025-10-02 15:30:17.472373 | controller | ok 2025-10-02 15:30:17.488181 | 2025-10-02 15:30:17.488247 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 15:30:17.753975 | controller | ok 2025-10-02 15:30:17.759437 | 2025-10-02 15:30:17.759502 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 15:30:18.290895 | controller | skipping: Conditional result was False 2025-10-02 15:30:18.319251 | 2025-10-02 15:30:18.319358 | TASK [bindep : Remove bindep temp dir] 2025-10-02 15:30:18.725620 | controller | ok 2025-10-02 15:30:18.746017 | 2025-10-02 15:30:18.746100 | PLAY RECAP 2025-10-02 15:30:18.746169 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 15:30:18.746204 | 2025-10-02 15:30:18.879455 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 15:30:18.880744 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 15:30:19.424795 | 2025-10-02 15:30:19.424923 | PLAY [all] 2025-10-02 15:30:19.449708 | 2025-10-02 15:30:19.449839 | TASK [Abort when test_command variable is undefined] 2025-10-02 15:30:19.474505 | controller | skipping: Conditional result was False 2025-10-02 15:30:19.480030 | 2025-10-02 15:30:19.480105 | TASK [Convert test_command to list] 2025-10-02 15:30:19.514638 | controller | skipping: Conditional result was False 2025-10-02 15:30:19.524092 | 2025-10-02 15:30:19.524190 | TASK [Use test_command list] 2025-10-02 15:30:19.577519 | controller | ok 2025-10-02 15:30:19.585134 | 2025-10-02 15:30:19.585219 | LOOP [Run test_command] 2025-10-02 15:30:20.022776 | controller | no check to run 2025-10-02 15:30:20.023039 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007660 2025-10-02 15:30:20.063226 | 2025-10-02 15:30:20.063335 | PLAY RECAP 2025-10-02 15:30:20.063404 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 15:30:20.063431 | 2025-10-02 15:30:20.161964 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 15:30:20.162883 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 15:30:20.803532 | 2025-10-02 15:30:20.803706 | PLAY [all] 2025-10-02 15:30:20.824175 | 2025-10-02 15:30:20.824263 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 15:30:21.235142 | controller | changed: non-zero return code 2025-10-02 15:30:21.241000 | 2025-10-02 15:30:21.241078 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 15:30:21.270513 | controller | skipping: Conditional result was False 2025-10-02 15:30:21.276351 | 2025-10-02 15:30:21.276418 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 15:30:21.308790 | 2025-10-02 15:30:21.308972 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 15:30:21.342988 | 2025-10-02 15:30:21.343187 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 15:30:21.358974 | controller | skipping: Conditional result was False 2025-10-02 15:30:21.368327 | 2025-10-02 15:30:21.368425 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 15:30:21.400604 | 2025-10-02 15:30:21.400775 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 15:30:21.424134 | controller | skipping: Conditional result was False 2025-10-02 15:30:21.433030 | 2025-10-02 15:30:21.433111 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 15:30:21.456900 | controller | skipping: Conditional result was False 2025-10-02 15:30:21.462740 | 2025-10-02 15:30:21.462809 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 15:30:21.478128 | controller | skipping: Conditional result was False 2025-10-02 15:30:21.512882 | 2025-10-02 15:30:21.513005 | PLAY RECAP 2025-10-02 15:30:21.513060 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 15:30:21.513082 | 2025-10-02 15:30:21.619872 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 15:30:21.620650 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 15:30:22.229716 | 2025-10-02 15:30:22.229836 | PLAY [all] 2025-10-02 15:30:22.249469 | 2025-10-02 15:30:22.249567 | TASK [include_role : fetch-output] 2025-10-02 15:30:22.288934 | controller | ok 2025-10-02 15:30:22.306997 | 2025-10-02 15:30:22.307105 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 15:30:22.383035 | controller | skipping: Conditional result was False 2025-10-02 15:30:22.389596 | 2025-10-02 15:30:22.389702 | TASK [fetch-output : Set log path for single node] 2025-10-02 15:30:22.419371 | controller | ok 2025-10-02 15:30:22.426764 | 2025-10-02 15:30:22.426893 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 15:30:22.799761 | controller -> localhost | ok: "/var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/logs" 2025-10-02 15:30:23.022003 | controller -> localhost | changed: "/var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/artifacts" 2025-10-02 15:30:23.223489 | controller -> localhost | changed: "/var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/docs" 2025-10-02 15:30:23.237746 | 2025-10-02 15:30:23.237866 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 15:30:23.986447 | controller | changed: .d..t...... ./ 2025-10-02 15:30:23.986831 | controller | changed: All items complete 2025-10-02 15:30:23.986893 | 2025-10-02 15:30:24.500504 | controller | changed: .d..t...... ./ 2025-10-02 15:30:25.037451 | controller | changed: .d..t...... ./ 2025-10-02 15:30:25.061277 | 2025-10-02 15:30:25.061418 | TASK [include_role : fetch-output-openshift] 2025-10-02 15:30:25.077936 | controller | skipping: Conditional result was False 2025-10-02 15:30:25.088050 | 2025-10-02 15:30:25.088165 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 15:30:25.625307 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013491 2025-10-02 15:30:25.933333 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006222 2025-10-02 15:30:25.973585 | 2025-10-02 15:30:25.973718 | PLAY [all] 2025-10-02 15:30:25.999306 | 2025-10-02 15:30:25.999528 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 15:30:26.521227 | controller | changed 2025-10-02 15:30:26.558787 | 2025-10-02 15:30:26.558924 | PLAY RECAP 2025-10-02 15:30:26.558988 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 15:30:26.559021 | 2025-10-02 15:30:26.704626 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 15:30:26.705785 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 15:30:27.342532 | 2025-10-02 15:30:27.342694 | PLAY [localhost] 2025-10-02 15:30:27.362008 | 2025-10-02 15:30:27.362146 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 15:30:27.768392 | localhost | changed 2025-10-02 15:30:27.776339 | 2025-10-02 15:30:27.776527 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 15:30:27.802067 | localhost | ok 2025-10-02 15:30:27.810485 | 2025-10-02 15:30:27.810555 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 15:30:28.157074 | localhost | changed 2025-10-02 15:30:28.162642 | 2025-10-02 15:30:28.162796 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 15:30:28.917223 | localhost | changed 2025-10-02 15:30:28.925177 | 2025-10-02 15:30:28.925292 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 15:30:29.341979 | localhost | Identity added: /var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/tmp/ansible.0xnhamyp (/var/lib/zuul/builds/a67b53b2347142e2a8e7e71b55bf1ab9/work/tmp/ansible.0xnhamyp) 2025-10-02 15:30:29.342159 | localhost | ok: Runtime: 0:00:00.012536 2025-10-02 15:30:29.346897 | 2025-10-02 15:30:29.346965 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 15:30:29.672766 | localhost | ok: Runtime: 0:00:00.007713 2025-10-02 15:30:29.677599 | 2025-10-02 15:30:29.679750 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 15:30:29.755416 | localhost | changed 2025-10-02 15:30:29.768247 | 2025-10-02 15:30:29.768450 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 15:30:30.211875 | localhost | changed 2025-10-02 15:30:30.232582 | 2025-10-02 15:30:30.232648 | PLAY [localhost] 2025-10-02 15:30:30.245035 | 2025-10-02 15:30:30.245095 | TASK [Generate bulk log download script] 2025-10-02 15:30:30.262495 | localhost | ok 2025-10-02 15:30:30.274144 | 2025-10-02 15:30:30.274211 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 15:30:30.302033 | localhost | ok: All assertions passed 2025-10-02 15:30:30.306441 | 2025-10-02 15:30:30.306501 | TASK [local-log-download : Create download script] 2025-10-02 15:30:30.708090 | localhost -> localhost | changed 2025-10-02 15:30:30.722414 | 2025-10-02 15:30:30.722567 | TASK [Register quick-download link] 2025-10-02 15:30:30.745065 | localhost | ok 2025-10-02 15:30:30.798186 | 2025-10-02 15:30:30.798284 | PLAY [logserver.rdoproject.org] 2025-10-02 15:30:30.808092 | 2025-10-02 15:30:30.808187 | TASK [Set zuul-log-path fact] 2025-10-02 15:30:30.824266 | logserver.rdoproject.org | ok 2025-10-02 15:30:30.833349 | 2025-10-02 15:30:30.833436 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 15:30:30.860261 | logserver.rdoproject.org | ok 2025-10-02 15:30:30.865802 | 2025-10-02 15:30:30.865907 | TASK [upload-logs : Create log directories] 2025-10-02 15:30:31.485949 | logserver.rdoproject.org | changed 2025-10-02 15:30:31.491109 | 2025-10-02 15:30:31.491199 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 15:30:31.777423 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007966 2025-10-02 15:30:31.782197 | 2025-10-02 15:30:31.782271 | TASK [upload-logs : Upload logs to log server] 2025-10-02 15:30:32.445555 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 15:30:32.452397 | 2025-10-02 15:30:32.452477 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 15:30:32.500572 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:32.510355 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:32.522814 | 2025-10-02 15:30:32.522891 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 15:30:32.565145 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:32.565420 | 2025-10-02 15:30:32.568910 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:32.583469 | 2025-10-02 15:30:32.583557 | LOOP [upload-logs : Upload console log and json output]