2025-12-05 05:32:42.592252 | Job console starting... 2025-12-05 05:32:42.601155 | Updating repositories 2025-12-05 05:32:42.628483 | Preparing job workspace 2025-12-05 05:32:47.268977 | Running Ansible setup... 2025-12-05 05:32:51.150054 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 05:32:51.737577 | 2025-12-05 05:32:51.737715 | PLAY [localhost] 2025-12-05 05:32:51.746384 | 2025-12-05 05:32:51.746459 | TASK [Gathering Facts] 2025-12-05 05:32:52.661866 | localhost | ok 2025-12-05 05:32:52.696450 | 2025-12-05 05:32:52.696749 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 05:32:53.133576 | localhost -> localhost | changed 2025-12-05 05:32:53.140943 | 2025-12-05 05:32:53.141037 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 05:32:54.118793 | localhost -> localhost | changed 2025-12-05 05:32:54.127449 | 2025-12-05 05:32:54.127515 | TASK [Setup log path fact] 2025-12-05 05:32:54.176017 | localhost | ok 2025-12-05 05:32:54.189515 | 2025-12-05 05:32:54.189592 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 05:32:54.217488 | localhost | ok 2025-12-05 05:32:54.226171 | 2025-12-05 05:32:54.226301 | TASK [emit-job-header : Print job information] 2025-12-05 05:32:54.265096 | # Job Information 2025-12-05 05:32:54.265331 | Ansible Version: 2.15.12 2025-12-05 05:32:54.265359 | Job: cifmw-molecule-cifmw_setup 2025-12-05 05:32:54.265379 | Pipeline: github-check 2025-12-05 05:32:54.265396 | Executor: ze02.softwarefactory-project.io 2025-12-05 05:32:54.265414 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3533 2025-12-05 05:32:54.265432 | Log URL (when completed): https://logserver.rdoproject.org/655/rdoproject.org/655fcf83b9d140539361cde51160895b/ 2025-12-05 05:32:54.265449 | Event ID: aba2e1c0-d19b-11f0-93fd-667d59eb2322 2025-12-05 05:32:54.269134 | 2025-12-05 05:32:54.269203 | LOOP [emit-job-header : Print node information] 2025-12-05 05:32:54.360093 | localhost | ok: 2025-12-05 05:32:54.360257 | localhost | # Node Information 2025-12-05 05:32:54.360284 | localhost | Inventory Hostname: controller 2025-12-05 05:32:54.360308 | localhost | Hostname: np0005546360 2025-12-05 05:32:54.360328 | localhost | Username: zuul 2025-12-05 05:32:54.360348 | localhost | Distro: CentOS 9 2025-12-05 05:32:54.360366 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 05:32:54.360383 | localhost | Region: RegionOne 2025-12-05 05:32:54.360399 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 05:32:54.360416 | localhost | Product Name: OpenStack Nova 2025-12-05 05:32:54.360432 | localhost | Interface IP: 38.102.83.64 2025-12-05 05:32:54.385160 | 2025-12-05 05:32:54.385261 | PLAY [all] 2025-12-05 05:32:54.391709 | 2025-12-05 05:32:54.391773 | TASK [Gather network facts] 2025-12-05 05:32:54.939932 | controller | ok 2025-12-05 05:32:54.972653 | 2025-12-05 05:32:54.972810 | TASK [include_role : start-zuul-console] 2025-12-05 05:32:54.996540 | controller | ok 2025-12-05 05:32:55.013890 | 2025-12-05 05:32:55.013999 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 05:32:55.470637 | controller | ok 2025-12-05 05:32:55.493196 | 2025-12-05 05:32:55.493332 | TASK [include_role : add-build-sshkey] 2025-12-05 05:32:55.529889 | controller | ok 2025-12-05 05:32:55.556309 | 2025-12-05 05:32:55.556401 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 05:32:55.834918 | controller -> localhost | ok 2025-12-05 05:32:55.842556 | 2025-12-05 05:32:55.842647 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 05:32:55.882656 | controller | ok 2025-12-05 05:32:55.899598 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 05:32:55.907139 | 2025-12-05 05:32:55.907220 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 05:32:56.458717 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 05:32:56.458903 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/655fcf83b9d140539361cde51160895b_id_rsa. 2025-12-05 05:32:56.458933 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/655fcf83b9d140539361cde51160895b_id_rsa.pub. 2025-12-05 05:32:56.458954 | controller -> localhost | The key fingerprint is: 2025-12-05 05:32:56.458973 | controller -> localhost | SHA256:XErfQ5CbQ3x4frcKaHNrwBpcGOtOGVLAaoOW+jdrCK4 zuul-build-sshkey 2025-12-05 05:32:56.458994 | controller -> localhost | The key's randomart image is: 2025-12-05 05:32:56.459012 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 05:32:56.459029 | controller -> localhost | | ... ..o | 2025-12-05 05:32:56.459047 | controller -> localhost | | . o =.o | 2025-12-05 05:32:56.459065 | controller -> localhost | | o . . =..*. | 2025-12-05 05:32:56.459082 | controller -> localhost | | + + . * =+o. . .| 2025-12-05 05:32:56.459100 | controller -> localhost | |o . . + S o.o. ..| 2025-12-05 05:32:56.459118 | controller -> localhost | |o * * o . . | 2025-12-05 05:32:56.459135 | controller -> localhost | |.o . o + + o . | 2025-12-05 05:32:56.459154 | controller -> localhost | | .o + o o . | 2025-12-05 05:32:56.459172 | controller -> localhost | |E o.o . | 2025-12-05 05:32:56.459189 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 05:32:56.459231 | controller -> localhost | ok: Runtime: 0:00:00.086037 2025-12-05 05:32:56.464805 | 2025-12-05 05:32:56.464869 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 05:32:56.493093 | controller | ok 2025-12-05 05:32:56.502494 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 05:32:56.510237 | 2025-12-05 05:32:56.510298 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 05:32:56.534028 | controller | skipping: Conditional result was False 2025-12-05 05:32:56.539204 | 2025-12-05 05:32:56.539275 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 05:32:57.014258 | controller | changed 2025-12-05 05:32:57.018955 | 2025-12-05 05:32:57.019018 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 05:32:57.280574 | controller | ok 2025-12-05 05:32:57.285946 | 2025-12-05 05:32:57.286010 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 05:32:58.338112 | controller | changed 2025-12-05 05:32:58.356190 | 2025-12-05 05:32:58.356317 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 05:32:59.396801 | controller | changed 2025-12-05 05:32:59.408222 | 2025-12-05 05:32:59.408365 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 05:32:59.436292 | controller | skipping: Conditional result was False 2025-12-05 05:32:59.449270 | 2025-12-05 05:32:59.449413 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 05:32:59.833195 | controller -> localhost | changed 2025-12-05 05:32:59.843364 | 2025-12-05 05:32:59.843476 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 05:33:00.163472 | controller -> localhost | Identity added: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/655fcf83b9d140539361cde51160895b_id_rsa (zuul-build-sshkey) 2025-12-05 05:33:00.163858 | controller -> localhost | ok: Runtime: 0:00:00.013747 2025-12-05 05:33:00.175546 | 2025-12-05 05:33:00.175708 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 05:33:00.595940 | controller | ok 2025-12-05 05:33:00.602168 | 2025-12-05 05:33:00.602254 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 05:33:00.639958 | controller | skipping: Conditional result was False 2025-12-05 05:33:00.661886 | 2025-12-05 05:33:00.662030 | TASK [include_role : validate-host] 2025-12-05 05:33:00.700556 | controller | ok 2025-12-05 05:33:00.725909 | 2025-12-05 05:33:00.726000 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 05:33:00.770305 | controller | ok 2025-12-05 05:33:00.779801 | 2025-12-05 05:33:00.779887 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 05:33:01.110263 | controller -> localhost | ok 2025-12-05 05:33:01.116105 | 2025-12-05 05:33:01.116171 | TASK [validate-host : Collect information about the host] 2025-12-05 05:33:01.967416 | controller | ok 2025-12-05 05:33:01.985150 | 2025-12-05 05:33:01.985279 | TASK [validate-host : Sanitize hostname] 2025-12-05 05:33:02.073509 | controller | ok 2025-12-05 05:33:02.084204 | 2025-12-05 05:33:02.084340 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 05:33:02.602248 | controller -> localhost | changed 2025-12-05 05:33:02.608048 | 2025-12-05 05:33:02.608111 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 05:33:03.083568 | controller | ok 2025-12-05 05:33:03.088324 | 2025-12-05 05:33:03.088393 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 05:33:03.526801 | controller -> localhost | changed 2025-12-05 05:33:03.536099 | 2025-12-05 05:33:03.536161 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 05:33:03.549080 | controller | skipping: Conditional result was False 2025-12-05 05:33:03.553952 | 2025-12-05 05:33:03.554023 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 05:33:03.566977 | controller | skipping: Conditional result was False 2025-12-05 05:33:03.578261 | 2025-12-05 05:33:03.578467 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 05:33:03.884220 | controller | ok: "logs" 2025-12-05 05:33:03.884444 | controller | ok: All items complete 2025-12-05 05:33:03.884471 | 2025-12-05 05:33:04.144311 | controller | ok: "artifacts" 2025-12-05 05:33:04.373549 | controller | ok: "docs" 2025-12-05 05:33:04.388764 | 2025-12-05 05:33:04.388831 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 05:33:04.688039 | controller | changed: "logs" 2025-12-05 05:33:04.945909 | controller | changed: "artifacts" 2025-12-05 05:33:05.207539 | controller | changed: "docs" 2025-12-05 05:33:05.246642 | 2025-12-05 05:33:05.246757 | PLAY RECAP 2025-12-05 05:33:05.246799 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 05:33:05.246826 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 05:33:05.246846 | 2025-12-05 05:33:05.364265 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 05:33:05.365379 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 05:33:06.044198 | 2025-12-05 05:33:06.044309 | PLAY [localhost] 2025-12-05 05:33:06.060071 | 2025-12-05 05:33:06.060139 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 05:33:06.486178 | localhost | ok 2025-12-05 05:33:06.491236 | 2025-12-05 05:33:06.491309 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 05:33:07.228039 | localhost | changed 2025-12-05 05:33:07.264947 | 2025-12-05 05:33:07.265027 | PLAY [all] 2025-12-05 05:33:07.292004 | 2025-12-05 05:33:07.292269 | TASK [include_role : prepare-workspace] 2025-12-05 05:33:07.319762 | controller | ok 2025-12-05 05:33:07.347224 | 2025-12-05 05:33:07.347310 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 05:33:07.801472 | controller | ok 2025-12-05 05:33:07.816894 | 2025-12-05 05:33:07.817036 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 05:33:09.690177 | controller | Output suppressed because no_log was given 2025-12-05 05:33:09.710555 | 2025-12-05 05:33:09.710720 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 05:33:10.020525 | controller | changed: "logs" 2025-12-05 05:33:10.259437 | controller | changed: "artifacts" 2025-12-05 05:33:10.520183 | controller | changed: "docs" 2025-12-05 05:33:10.535267 | 2025-12-05 05:33:10.535457 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 05:33:10.878308 | controller | changed: "logs" 2025-12-05 05:33:10.878762 | controller | changed: All items complete 2025-12-05 05:33:10.878823 | 2025-12-05 05:33:11.116874 | controller | changed: "artifacts" 2025-12-05 05:33:11.398588 | controller | changed: "docs" 2025-12-05 05:33:11.429078 | 2025-12-05 05:33:11.429252 | TASK [Check if worker can sudo] 2025-12-05 05:33:11.982015 | controller | ok: Runtime: 0:00:00.039323 2025-12-05 05:33:11.993547 | 2025-12-05 05:33:11.993718 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 05:33:12.062382 | controller | skipping: Conditional result was False 2025-12-05 05:33:12.075728 | 2025-12-05 05:33:12.075864 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 05:33:12.155705 | controller | ok 2025-12-05 05:33:12.168008 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 05:33:12.203879 | 2025-12-05 05:33:12.203999 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 05:33:12.532843 | controller | ok 2025-12-05 05:33:12.544429 | 2025-12-05 05:33:12.544554 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 05:33:12.640119 | controller | ok: "/var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 05:33:12.654897 | 2025-12-05 05:33:12.655035 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 05:33:13.709549 | controller | changed 2025-12-05 05:33:13.721014 | 2025-12-05 05:33:13.721146 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 05:33:13.806331 | controller | ok: "/var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 05:33:13.806554 | controller | ok: All items complete 2025-12-05 05:33:13.806610 | 2025-12-05 05:33:13.861367 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 05:33:13.867583 | 2025-12-05 05:33:13.867646 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 05:33:15.026015 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 05:33:16.053406 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 05:33:16.076628 | 2025-12-05 05:33:16.076906 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 05:33:16.625615 | controller | changed: section and option added 2025-12-05 05:33:16.658593 | 2025-12-05 05:33:16.658705 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 05:33:17.372975 | controller | 29 files removed 2025-12-05 05:33:17.373396 | controller | ok: Item: dnf clean all Runtime: 0:00:00.327884 2025-12-05 05:33:17.373510 | controller | changed: All items complete 2025-12-05 05:33:17.373559 | 2025-12-05 05:33:28.026069 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-05 05:33:28.026430 | controller | DNF version: 4.14.0 2025-12-05 05:33:28.026498 | controller | cachedir: /var/cache/dnf 2025-12-05 05:33:28.026543 | controller | Making cache files for all metadata files. 2025-12-05 05:33:28.026583 | controller | baseos: has expired and will be refreshed. 2025-12-05 05:33:28.026620 | controller | appstream: has expired and will be refreshed. 2025-12-05 05:33:28.026656 | controller | crb: has expired and will be refreshed. 2025-12-05 05:33:28.026751 | controller | extras-common: has expired and will be refreshed. 2025-12-05 05:33:28.026792 | controller | repo: downloading from remote: baseos 2025-12-05 05:33:28.026827 | controller | CentOS Stream 9 - BaseOS 72 MB/s | 8.8 MB 00:00 2025-12-05 05:33:28.026863 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 05:33:28.026898 | controller | repo: downloading from remote: appstream 2025-12-05 05:33:28.026932 | controller | CentOS Stream 9 - AppStream 89 MB/s | 25 MB 00:00 2025-12-05 05:33:28.026966 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 05:33:28.027000 | controller | repo: downloading from remote: crb 2025-12-05 05:33:28.027034 | controller | CentOS Stream 9 - CRB 74 MB/s | 7.3 MB 00:00 2025-12-05 05:33:28.027070 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 05:33:28.027105 | controller | repo: downloading from remote: extras-common 2025-12-05 05:33:28.027140 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-12-05 05:33:28.027175 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 05:33:28.027210 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 05:33:28.027245 | controller | Completion plugin: Generating completion cache... 2025-12-05 05:33:28.027280 | controller | Metadata cache created. 2025-12-05 05:33:28.027334 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.327688 2025-12-05 05:33:28.059226 | 2025-12-05 05:33:28.059384 | PLAY RECAP 2025-12-05 05:33:28.059469 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 05:33:28.059525 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 05:33:28.059564 | 2025-12-05 05:33:28.164642 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 05:33:28.165494 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 05:33:28.727727 | 2025-12-05 05:33:28.727834 | PLAY [all] 2025-12-05 05:33:28.748796 | 2025-12-05 05:33:28.748952 | TASK [Install binary dependencies] 2025-12-05 05:33:28.818605 | controller | ok 2025-12-05 05:33:28.838993 | 2025-12-05 05:33:28.839109 | TASK [bindep : Include find tasks] 2025-12-05 05:33:28.869113 | controller | ok 2025-12-05 05:33:28.876537 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 05:33:28.882219 | 2025-12-05 05:33:28.882281 | TASK [bindep : Look for bindep.txt] 2025-12-05 05:33:29.379162 | controller | ok 2025-12-05 05:33:29.393948 | 2025-12-05 05:33:29.394121 | TASK [bindep : Define bindep_file fact] 2025-12-05 05:33:29.443820 | controller | ok 2025-12-05 05:33:29.456070 | 2025-12-05 05:33:29.456265 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 05:33:29.485019 | controller | skipping: Conditional result was False 2025-12-05 05:33:29.498057 | 2025-12-05 05:33:29.498207 | TASK [bindep : Define bindep_file fact] 2025-12-05 05:33:29.536097 | controller | skipping: Conditional result was False 2025-12-05 05:33:29.548062 | 2025-12-05 05:33:29.548577 | TASK [bindep : Look for bindep fallback file] 2025-12-05 05:33:29.576495 | controller | skipping: Conditional result was False 2025-12-05 05:33:29.588826 | 2025-12-05 05:33:29.588967 | TASK [bindep : Define bindep_file fact] 2025-12-05 05:33:29.616013 | controller | skipping: Conditional result was False 2025-12-05 05:33:29.628021 | 2025-12-05 05:33:29.628150 | TASK [bindep : Include bindep tasks] 2025-12-05 05:33:29.668322 | controller | ok 2025-12-05 05:33:29.682466 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 05:33:29.695736 | 2025-12-05 05:33:29.695819 | TASK [bindep : Look for bindep command] 2025-12-05 05:33:29.721142 | controller | skipping: Conditional result was False 2025-12-05 05:33:29.729904 | 2025-12-05 05:33:29.729991 | TASK [bindep : Check for system bindep] 2025-12-05 05:33:30.269108 | controller | ok: Runtime: 0:00:00.007208 2025-12-05 05:33:30.281640 | 2025-12-05 05:33:30.281805 | TASK [bindep : Define bindep_command fact] 2025-12-05 05:33:30.310846 | controller | skipping: Conditional result was False 2025-12-05 05:33:30.322835 | 2025-12-05 05:33:30.322973 | TASK [bindep : Include install tasks] 2025-12-05 05:33:30.360502 | controller | ok 2025-12-05 05:33:30.377195 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 05:33:30.391114 | 2025-12-05 05:33:30.391278 | TASK [bindep : Create temp dir for bindep] 2025-12-05 05:33:30.783071 | controller | changed 2025-12-05 05:33:30.794771 | 2025-12-05 05:33:30.794898 | TASK [Ensure we have pip dependencies] 2025-12-05 05:33:30.822650 | controller | ok 2025-12-05 05:33:30.877291 | 2025-12-05 05:33:30.877395 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 00:33:31.178560 | controller | /usr/bin/pip3 2025-12-05 00:33:31.227506 | controller | /usr/bin/python3: No module named wheel 2025-12-05 05:33:31.412967 | controller | ok: Runtime: 0:00:00.062118 2025-12-05 05:33:31.424984 | 2025-12-05 05:33:31.425109 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 05:33:31.452890 | controller | ok: "/var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 05:33:31.480234 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 05:33:31.502449 | 2025-12-05 05:33:31.502573 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 05:33:33.305043 | controller | changed 2025-12-05 05:33:33.310385 | 2025-12-05 05:33:33.310446 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 05:33:33.354238 | controller | skipping: Conditional result was False 2025-12-05 05:33:33.362572 | 2025-12-05 05:33:33.362660 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 05:33:33.408276 | controller | skipping: Conditional result was False 2025-12-05 05:33:33.421808 | 2025-12-05 05:33:33.421945 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 05:33:33.458877 | controller | skipping: Conditional result was False 2025-12-05 05:33:33.474449 | 2025-12-05 05:33:33.474586 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 05:33:33.501952 | controller | skipping: Conditional result was False 2025-12-05 05:33:33.515254 | 2025-12-05 05:33:33.515390 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 05:33:34.061075 | controller | skipping: Conditional result was False 2025-12-05 05:33:34.073912 | 2025-12-05 05:33:34.074050 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 05:33:34.101184 | controller | skipping: Conditional result was False 2025-12-05 05:33:34.109705 | 2025-12-05 05:33:34.109795 | TASK [ensure-pip : Install pip from source] 2025-12-05 05:33:34.136008 | controller | skipping: Conditional result was False 2025-12-05 05:33:34.144060 | 2025-12-05 05:33:34.144149 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 00:33:34.443890 | controller | /usr/bin/python3 2025-12-05 05:33:34.679101 | controller | ok: Runtime: 0:00:00.006020 2025-12-05 05:33:34.691062 | 2025-12-05 05:33:34.691193 | TASK [ensure-pip : Set host default] 2025-12-05 05:33:34.770089 | controller | ok 2025-12-05 05:33:34.781321 | 2025-12-05 05:33:34.781453 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 05:33:34.842338 | controller | ok 2025-12-05 05:33:34.864830 | 2025-12-05 05:33:34.864967 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 05:33:39.311951 | controller | changed 2025-12-05 05:33:39.324463 | 2025-12-05 05:33:39.324656 | TASK [bindep : Define bindep_command] 2025-12-05 05:33:39.364114 | controller | ok 2025-12-05 05:33:39.378417 | 2025-12-05 05:33:39.378581 | LOOP [bindep : Include package tasks] 2025-12-05 05:33:39.466773 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 05:33:39.467202 | controller | ok: All items complete 2025-12-05 05:33:39.467339 | 2025-12-05 05:33:39.499333 | controller | included: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 05:33:39.516957 | 2025-12-05 05:33:39.517039 | TASK [bindep : Define bindep_run fact] 2025-12-05 05:33:39.552598 | controller | ok 2025-12-05 05:33:39.563250 | 2025-12-05 05:33:39.563377 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 00:33:40.965467 | controller | podman 2025-12-05 00:33:41.010597 | controller | python3-jmespath 2025-12-05 00:33:41.010821 | controller | python3-libvirt 2025-12-05 00:33:41.010835 | controller | python3-lxml 2025-12-05 00:33:41.010849 | controller | python3-netaddr 2025-12-05 05:33:41.105108 | controller | ok: Runtime: 0:00:01.158131 2025-12-05 05:33:41.116638 | 2025-12-05 05:33:41.116800 | TASK [bindep : Install distro packages from bindep] 2025-12-05 05:34:43.487800 | controller | changed 2025-12-05 05:34:43.499335 | 2025-12-05 05:34:43.499467 | TASK [bindep : Check that packages are installed] 2025-12-05 05:34:45.550900 | controller | ok: Runtime: 0:00:01.217730 2025-12-05 05:34:45.562827 | 2025-12-05 05:34:45.562961 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 05:34:45.600623 | controller | skipping: Conditional result was False 2025-12-05 05:34:45.622273 | 2025-12-05 05:34:45.622404 | TASK [Run test-setup role] 2025-12-05 05:34:45.651812 | controller | ok 2025-12-05 05:34:45.687962 | 2025-12-05 05:34:45.688141 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 05:34:45.979020 | controller | ok 2025-12-05 05:34:45.990123 | 2025-12-05 05:34:45.990255 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 05:34:46.541004 | controller | skipping: Conditional result was False 2025-12-05 05:34:46.585386 | 2025-12-05 05:34:46.585610 | TASK [bindep : Remove bindep temp dir] 2025-12-05 05:34:46.975005 | controller | ok 2025-12-05 05:34:46.986578 | 2025-12-05 05:34:46.986652 | PLAY RECAP 2025-12-05 05:34:46.986712 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 05:34:46.986735 | 2025-12-05 05:34:47.079485 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 05:34:47.081213 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 05:34:47.638081 | 2025-12-05 05:34:47.638213 | PLAY [all] 2025-12-05 05:34:47.657455 | 2025-12-05 05:34:47.657527 | TASK [Abort when test_command variable is undefined] 2025-12-05 05:34:47.712217 | controller | skipping: Conditional result was False 2025-12-05 05:34:47.717432 | 2025-12-05 05:34:47.717501 | TASK [Convert test_command to list] 2025-12-05 05:34:47.771938 | controller | skipping: Conditional result was False 2025-12-05 05:34:47.793578 | 2025-12-05 05:34:47.793721 | TASK [Use test_command list] 2025-12-05 05:34:47.843548 | controller | ok 2025-12-05 05:34:47.848796 | 2025-12-05 05:34:47.848855 | LOOP [Run test_command] 2025-12-05 05:34:48.272934 | controller | no check to run 2025-12-05 05:34:48.273215 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006090 2025-12-05 05:34:48.316228 | 2025-12-05 05:34:48.316364 | PLAY RECAP 2025-12-05 05:34:48.316445 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 05:34:48.316487 | 2025-12-05 05:34:48.413755 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 05:34:48.415598 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 05:34:48.988591 | 2025-12-05 05:34:48.988711 | PLAY [all] 2025-12-05 05:34:49.008141 | 2025-12-05 05:34:49.008215 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 05:34:49.431866 | controller | changed: non-zero return code 2025-12-05 05:34:49.443430 | 2025-12-05 05:34:49.443583 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 05:34:49.470758 | controller | skipping: Conditional result was False 2025-12-05 05:34:49.482862 | 2025-12-05 05:34:49.483006 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 05:34:49.516558 | 2025-12-05 05:34:49.516726 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 05:34:49.552263 | 2025-12-05 05:34:49.552493 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 05:34:49.569088 | controller | skipping: Conditional result was False 2025-12-05 05:34:49.582076 | 2025-12-05 05:34:49.582217 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 05:34:49.621793 | 2025-12-05 05:34:49.622056 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 05:34:49.638347 | controller | skipping: Conditional result was False 2025-12-05 05:34:49.644214 | 2025-12-05 05:34:49.644276 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 05:34:49.658100 | controller | skipping: Conditional result was False 2025-12-05 05:34:49.663867 | 2025-12-05 05:34:49.663928 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 05:34:49.687347 | controller | skipping: Conditional result was False 2025-12-05 05:34:49.710636 | 2025-12-05 05:34:49.710702 | PLAY RECAP 2025-12-05 05:34:49.710742 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 05:34:49.710761 | 2025-12-05 05:34:49.790881 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 05:34:49.791986 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 05:34:50.330355 | 2025-12-05 05:34:50.330462 | PLAY [all] 2025-12-05 05:34:50.349039 | 2025-12-05 05:34:50.349111 | TASK [include_role : fetch-output] 2025-12-05 05:34:50.394878 | controller | ok 2025-12-05 05:34:50.411103 | 2025-12-05 05:34:50.411183 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 05:34:50.475353 | controller | skipping: Conditional result was False 2025-12-05 05:34:50.481200 | 2025-12-05 05:34:50.481267 | TASK [fetch-output : Set log path for single node] 2025-12-05 05:34:50.519917 | controller | ok 2025-12-05 05:34:50.534905 | 2025-12-05 05:34:50.534985 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 05:34:50.936765 | controller -> localhost | ok: "/var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/logs" 2025-12-05 05:34:51.182853 | controller -> localhost | changed: "/var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/artifacts" 2025-12-05 05:34:51.417268 | controller -> localhost | changed: "/var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/docs" 2025-12-05 05:34:51.431639 | 2025-12-05 05:34:51.431794 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 05:34:52.152466 | controller | changed: .d..t...... ./ 2025-12-05 05:34:52.153100 | controller | changed: All items complete 2025-12-05 05:34:52.153172 | 2025-12-05 05:34:52.715984 | controller | changed: .d..t...... ./ 2025-12-05 05:34:53.300296 | controller | changed: .d..t...... ./ 2025-12-05 05:34:53.330646 | 2025-12-05 05:34:53.330807 | TASK [include_role : fetch-output-openshift] 2025-12-05 05:34:53.349281 | controller | skipping: Conditional result was False 2025-12-05 05:34:53.362973 | 2025-12-05 05:34:53.363132 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 05:34:53.842832 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013505 2025-12-05 05:34:54.107316 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012493 2025-12-05 05:34:54.139836 | 2025-12-05 05:34:54.139969 | PLAY [all] 2025-12-05 05:34:54.153843 | 2025-12-05 05:34:54.153909 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 05:34:54.681070 | controller | changed 2025-12-05 05:34:54.725640 | 2025-12-05 05:34:54.725729 | PLAY RECAP 2025-12-05 05:34:54.725784 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 05:34:54.725812 | 2025-12-05 05:34:54.822155 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 05:34:54.823205 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 05:34:55.400108 | 2025-12-05 05:34:55.400213 | PLAY [localhost] 2025-12-05 05:34:55.418023 | 2025-12-05 05:34:55.418100 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 05:34:55.837293 | localhost | changed 2025-12-05 05:34:55.847164 | 2025-12-05 05:34:55.847325 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 05:34:55.893121 | localhost | ok 2025-12-05 05:34:55.910544 | 2025-12-05 05:34:55.910718 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 05:34:56.332892 | localhost | changed 2025-12-05 05:34:56.344755 | 2025-12-05 05:34:56.344899 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 05:34:57.021632 | localhost | changed 2025-12-05 05:34:57.032648 | 2025-12-05 05:34:57.032811 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 05:34:57.445568 | localhost | Identity added: /var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/tmp/ansible.cvot42q9 (/var/lib/zuul/builds/655fcf83b9d140539361cde51160895b/work/tmp/ansible.cvot42q9) 2025-12-05 05:34:57.445892 | localhost | ok: Runtime: 0:00:00.013048 2025-12-05 05:34:57.455562 | 2025-12-05 05:34:57.455729 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 05:34:57.739462 | localhost | ok: Runtime: 0:00:00.005003 2025-12-05 05:34:57.750534 | 2025-12-05 05:34:57.750706 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 05:34:57.808307 | localhost | changed 2025-12-05 05:34:57.817943 | 2025-12-05 05:34:57.818078 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 05:34:58.251540 | localhost | changed 2025-12-05 05:34:58.292238 | 2025-12-05 05:34:58.292315 | PLAY [localhost] 2025-12-05 05:34:58.309118 | 2025-12-05 05:34:58.309212 | TASK [Generate bulk log download script] 2025-12-05 05:34:58.329206 | localhost | ok 2025-12-05 05:34:58.345055 | 2025-12-05 05:34:58.345157 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 05:34:58.375396 | localhost | ok: All assertions passed 2025-12-05 05:34:58.382086 | 2025-12-05 05:34:58.382167 | TASK [local-log-download : Create download script] 2025-12-05 05:34:58.793539 | localhost -> localhost | changed 2025-12-05 05:34:58.812614 | 2025-12-05 05:34:58.812790 | TASK [Register quick-download link] 2025-12-05 05:34:58.847828 | localhost | ok 2025-12-05 05:34:58.907791 | 2025-12-05 05:34:58.907916 | PLAY [logserver.rdoproject.org] 2025-12-05 05:34:58.920720 | 2025-12-05 05:34:58.920800 | TASK [Set zuul-log-path fact] 2025-12-05 05:34:58.939612 | logserver.rdoproject.org | ok 2025-12-05 05:34:58.951552 | 2025-12-05 05:34:58.951637 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 05:34:58.989973 | logserver.rdoproject.org | ok 2025-12-05 05:34:58.997703 | 2025-12-05 05:34:58.997786 | TASK [upload-logs : Create log directories] 2025-12-05 05:34:59.957302 | logserver.rdoproject.org | changed 2025-12-05 05:34:59.963956 | 2025-12-05 05:34:59.964088 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 05:35:00.296994 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008709 2025-12-05 05:35:00.306798 | 2025-12-05 05:35:00.306933 | TASK [upload-logs : Upload logs to log server] 2025-12-05 05:35:01.050110 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 05:35:01.056284 | 2025-12-05 05:35:01.056419 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 05:35:01.099431 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 05:35:01.105858 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 05:35:01.120503 | 2025-12-05 05:35:01.120707 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 05:35:01.157503 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 05:35:01.157834 | 2025-12-05 05:35:01.161132 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 05:35:01.175885 | 2025-12-05 05:35:01.176071 | LOOP [upload-logs : Upload console log and json output]