2025-10-02 15:27:50.030858 | Job console starting... 2025-10-02 15:27:50.040144 | Updating repositories 2025-10-02 15:27:50.126114 | Preparing job workspace 2025-10-02 15:27:53.429753 | Running Ansible setup... 2025-10-02 15:27:57.706540 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 15:27:58.306295 | 2025-10-02 15:27:58.306428 | PLAY [localhost] 2025-10-02 15:27:58.330127 | 2025-10-02 15:27:58.330251 | TASK [Gathering Facts] 2025-10-02 15:27:59.339595 | localhost | ok 2025-10-02 15:27:59.356202 | 2025-10-02 15:27:59.356289 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 15:27:59.771811 | localhost -> localhost | changed 2025-10-02 15:27:59.777205 | 2025-10-02 15:27:59.777272 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 15:28:00.727134 | localhost -> localhost | changed 2025-10-02 15:28:00.747428 | 2025-10-02 15:28:00.747552 | TASK [Setup log path fact] 2025-10-02 15:28:00.765953 | localhost | ok 2025-10-02 15:28:00.777562 | 2025-10-02 15:28:00.777638 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 15:28:00.805349 | localhost | ok 2025-10-02 15:28:00.813612 | 2025-10-02 15:28:00.813731 | TASK [emit-job-header : Print job information] 2025-10-02 15:28:00.842198 | # Job Information 2025-10-02 15:28:00.842416 | Ansible Version: 2.15.12 2025-10-02 15:28:00.842445 | Job: cifmw-molecule-ovirt 2025-10-02 15:28:00.842466 | Pipeline: github-check 2025-10-02 15:28:00.842484 | Executor: ze02.softwarefactory-project.io 2025-10-02 15:28:00.842502 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 15:28:00.842521 | Log URL (when completed): https://logserver.rdoproject.org/80b/rdoproject.org/80b2aee2296d42adbc8e704fe5a14d4c/ 2025-10-02 15:28:00.842540 | Event ID: 31e612e0-9fa4-11f0-8bb8-66cf2469bdc9 2025-10-02 15:28:00.846630 | 2025-10-02 15:28:00.846728 | LOOP [emit-job-header : Print node information] 2025-10-02 15:28:00.972130 | localhost | ok: 2025-10-02 15:28:00.972289 | localhost | # Node Information 2025-10-02 15:28:00.972316 | localhost | Inventory Hostname: controller 2025-10-02 15:28:00.972341 | localhost | Hostname: np0005466627 2025-10-02 15:28:00.972360 | localhost | Username: zuul 2025-10-02 15:28:00.972381 | localhost | Distro: CentOS 9 2025-10-02 15:28:00.972400 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 15:28:00.972418 | localhost | Region: RegionOne 2025-10-02 15:28:00.972435 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 15:28:00.972451 | localhost | Product Name: OpenStack Nova 2025-10-02 15:28:00.972468 | localhost | Interface IP: 38.129.56.212 2025-10-02 15:28:00.992272 | 2025-10-02 15:28:00.992371 | PLAY [all] 2025-10-02 15:28:00.998631 | 2025-10-02 15:28:00.998709 | TASK [Gather network facts] 2025-10-02 15:28:01.491363 | controller | ok 2025-10-02 15:28:01.508142 | 2025-10-02 15:28:01.508254 | TASK [include_role : start-zuul-console] 2025-10-02 15:28:01.527615 | controller | ok 2025-10-02 15:28:01.539474 | 2025-10-02 15:28:01.539573 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 15:28:01.962737 | controller | ok 2025-10-02 15:28:01.976715 | 2025-10-02 15:28:01.976875 | TASK [include_role : add-build-sshkey] 2025-10-02 15:28:02.009238 | controller | ok 2025-10-02 15:28:02.031856 | 2025-10-02 15:28:02.031983 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 15:28:02.258967 | controller -> localhost | ok 2025-10-02 15:28:02.265032 | 2025-10-02 15:28:02.265103 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 15:28:02.294525 | controller | ok 2025-10-02 15:28:02.311295 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 15:28:02.320742 | 2025-10-02 15:28:02.320810 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 15:28:03.022594 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 15:28:03.022823 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/80b2aee2296d42adbc8e704fe5a14d4c_id_rsa. 2025-10-02 15:28:03.022855 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/80b2aee2296d42adbc8e704fe5a14d4c_id_rsa.pub. 2025-10-02 15:28:03.022877 | controller -> localhost | The key fingerprint is: 2025-10-02 15:28:03.022896 | controller -> localhost | SHA256:pJ1yo2LKyJn07yCaGK8qtVcHGhLWjFh0aTCx+Zrp4Jg zuul-build-sshkey 2025-10-02 15:28:03.022915 | controller -> localhost | The key's randomart image is: 2025-10-02 15:28:03.022934 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 15:28:03.022952 | controller -> localhost | | +**.. | 2025-10-02 15:28:03.022970 | controller -> localhost | |. +== | 2025-10-02 15:28:03.022987 | controller -> localhost | | .oo . | 2025-10-02 15:28:03.023005 | controller -> localhost | | ... .+ . | 2025-10-02 15:28:03.023022 | controller -> localhost | | ..oo.S | 2025-10-02 15:28:03.023039 | controller -> localhost | | .+. .+.. | 2025-10-02 15:28:03.023056 | controller -> localhost | |o++oo... | 2025-10-02 15:28:03.023076 | controller -> localhost | |OX*oo. | 2025-10-02 15:28:03.023098 | controller -> localhost | |E*=ooo | 2025-10-02 15:28:03.023120 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 15:28:03.023171 | controller -> localhost | ok: Runtime: 0:00:00.244189 2025-10-02 15:28:03.029128 | 2025-10-02 15:28:03.029192 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 15:28:03.064068 | controller | ok 2025-10-02 15:28:03.074259 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 15:28:03.083547 | 2025-10-02 15:28:03.083647 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 15:28:03.108245 | controller | skipping: Conditional result was False 2025-10-02 15:28:03.118289 | 2025-10-02 15:28:03.118376 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 15:28:03.656530 | controller | changed 2025-10-02 15:28:03.664532 | 2025-10-02 15:28:03.664628 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 15:28:03.956379 | controller | ok 2025-10-02 15:28:03.969392 | 2025-10-02 15:28:03.969568 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 15:28:04.933144 | controller | changed 2025-10-02 15:28:04.937999 | 2025-10-02 15:28:04.938062 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 15:28:05.925725 | controller | changed 2025-10-02 15:28:05.931032 | 2025-10-02 15:28:05.931116 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 15:28:05.956473 | controller | skipping: Conditional result was False 2025-10-02 15:28:05.968274 | 2025-10-02 15:28:05.968417 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 15:28:06.340445 | controller -> localhost | changed 2025-10-02 15:28:06.352458 | 2025-10-02 15:28:06.352537 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 15:28:06.644293 | controller -> localhost | Identity added: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/80b2aee2296d42adbc8e704fe5a14d4c_id_rsa (zuul-build-sshkey) 2025-10-02 15:28:06.644479 | controller -> localhost | ok: Runtime: 0:00:00.021360 2025-10-02 15:28:06.650348 | 2025-10-02 15:28:06.650424 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 15:28:07.250644 | controller | ok 2025-10-02 15:28:07.267798 | 2025-10-02 15:28:07.267925 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 15:28:07.327041 | controller | skipping: Conditional result was False 2025-10-02 15:28:07.337115 | 2025-10-02 15:28:07.337208 | TASK [include_role : validate-host] 2025-10-02 15:28:07.386763 | controller | ok 2025-10-02 15:28:07.419052 | 2025-10-02 15:28:07.419126 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 15:28:07.457765 | controller | ok 2025-10-02 15:28:07.462427 | 2025-10-02 15:28:07.462487 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 15:28:07.693193 | controller -> localhost | ok 2025-10-02 15:28:07.706033 | 2025-10-02 15:28:07.706120 | TASK [validate-host : Collect information about the host] 2025-10-02 15:28:08.496454 | controller | ok 2025-10-02 15:28:08.504499 | 2025-10-02 15:28:08.504560 | TASK [validate-host : Sanitize hostname] 2025-10-02 15:28:08.553230 | controller | ok 2025-10-02 15:28:08.558637 | 2025-10-02 15:28:08.558741 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 15:28:09.020071 | controller -> localhost | changed 2025-10-02 15:28:09.026268 | 2025-10-02 15:28:09.026332 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 15:28:09.501463 | controller | ok 2025-10-02 15:28:09.506834 | 2025-10-02 15:28:09.506906 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 15:28:10.088702 | controller -> localhost | changed 2025-10-02 15:28:10.104189 | 2025-10-02 15:28:10.104299 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 15:28:10.145255 | controller | skipping: Conditional result was False 2025-10-02 15:28:10.152139 | 2025-10-02 15:28:10.152246 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 15:28:10.234884 | controller | skipping: Conditional result was False 2025-10-02 15:28:10.240209 | 2025-10-02 15:28:10.240277 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 15:28:10.578696 | controller | ok: "logs" 2025-10-02 15:28:10.578985 | controller | ok: All items complete 2025-10-02 15:28:10.579018 | 2025-10-02 15:28:10.885748 | controller | ok: "artifacts" 2025-10-02 15:28:11.151603 | controller | ok: "docs" 2025-10-02 15:28:11.165059 | 2025-10-02 15:28:11.165181 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 15:28:11.450532 | controller | changed: "logs" 2025-10-02 15:28:11.688509 | controller | changed: "artifacts" 2025-10-02 15:28:11.941232 | controller | changed: "docs" 2025-10-02 15:28:11.982802 | 2025-10-02 15:28:11.982888 | PLAY RECAP 2025-10-02 15:28:11.982930 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 15:28:11.982956 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 15:28:11.982976 | 2025-10-02 15:28:12.124067 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 15:28:12.124862 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 15:28:12.911398 | 2025-10-02 15:28:12.911503 | PLAY [localhost] 2025-10-02 15:28:12.930915 | 2025-10-02 15:28:12.931005 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 15:28:13.387648 | localhost | ok 2025-10-02 15:28:13.393320 | 2025-10-02 15:28:13.393394 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 15:28:14.222460 | localhost | changed 2025-10-02 15:28:14.250294 | 2025-10-02 15:28:14.250387 | PLAY [all] 2025-10-02 15:28:14.265602 | 2025-10-02 15:28:14.265682 | TASK [include_role : prepare-workspace] 2025-10-02 15:28:14.284640 | controller | ok 2025-10-02 15:28:14.298697 | 2025-10-02 15:28:14.298771 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 15:28:14.722439 | controller | ok 2025-10-02 15:28:14.752622 | 2025-10-02 15:28:14.752748 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 15:28:16.576762 | controller | Output suppressed because no_log was given 2025-10-02 15:28:16.586236 | 2025-10-02 15:28:16.586310 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 15:28:16.903839 | controller | changed: "logs" 2025-10-02 15:28:17.268884 | controller | changed: "artifacts" 2025-10-02 15:28:17.546487 | controller | changed: "docs" 2025-10-02 15:28:17.556163 | 2025-10-02 15:28:17.556287 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 15:28:17.890269 | controller | changed: "logs" 2025-10-02 15:28:17.890514 | controller | changed: All items complete 2025-10-02 15:28:17.890542 | 2025-10-02 15:28:18.127081 | controller | changed: "artifacts" 2025-10-02 15:28:18.338398 | controller | changed: "docs" 2025-10-02 15:28:18.354061 | 2025-10-02 15:28:18.354181 | TASK [Check if worker can sudo] 2025-10-02 15:28:18.887248 | controller | ok: Runtime: 0:00:00.075608 2025-10-02 15:28:18.893240 | 2025-10-02 15:28:18.893303 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 15:28:18.969426 | controller | skipping: Conditional result was False 2025-10-02 15:28:18.978517 | 2025-10-02 15:28:18.978724 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 15:28:19.070142 | controller | ok 2025-10-02 15:28:19.078289 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 15:28:19.116110 | 2025-10-02 15:28:19.116234 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 15:28:19.390716 | controller | ok 2025-10-02 15:28:19.402878 | 2025-10-02 15:28:19.403030 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 15:28:19.456847 | controller | ok: "/var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 15:28:19.467381 | 2025-10-02 15:28:19.467519 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 15:28:20.382240 | controller | changed 2025-10-02 15:28:20.394435 | 2025-10-02 15:28:20.394583 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 15:28:20.453461 | controller | ok: "/var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 15:28:20.453927 | controller | ok: All items complete 2025-10-02 15:28:20.453996 | 2025-10-02 15:28:20.524388 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 15:28:20.532141 | 2025-10-02 15:28:20.532274 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 15:28:21.758309 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 15:28:22.658651 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 15:28:22.686975 | 2025-10-02 15:28:22.687098 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 15:28:23.135526 | controller | changed: section and option added 2025-10-02 15:28:23.183000 | 2025-10-02 15:28:23.183160 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 15:28:24.121312 | controller | 29 files removed 2025-10-02 15:28:24.121702 | controller | ok: Item: dnf clean all Runtime: 0:00:00.608157 2025-10-02 15:28:24.121764 | controller | changed: All items complete 2025-10-02 15:28:24.121803 | 2025-10-02 15:28:35.881501 | 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:35.881699 | controller | DNF version: 4.14.0 2025-10-02 15:28:35.881764 | controller | cachedir: /var/cache/dnf 2025-10-02 15:28:35.881809 | controller | Making cache files for all metadata files. 2025-10-02 15:28:35.881850 | controller | baseos: has expired and will be refreshed. 2025-10-02 15:28:35.881889 | controller | appstream: has expired and will be refreshed. 2025-10-02 15:28:35.881926 | controller | crb: has expired and will be refreshed. 2025-10-02 15:28:35.881980 | controller | extras-common: has expired and will be refreshed. 2025-10-02 15:28:35.882018 | controller | repo: downloading from remote: baseos 2025-10-02 15:28:35.882055 | controller | CentOS Stream 9 - BaseOS 64 MB/s | 8.8 MB 00:00 2025-10-02 15:28:35.882091 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 15:28:35.882127 | controller | repo: downloading from remote: appstream 2025-10-02 15:28:35.882162 | controller | CentOS Stream 9 - AppStream 70 MB/s | 25 MB 00:00 2025-10-02 15:28:35.882197 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 15:28:35.882246 | controller | repo: downloading from remote: crb 2025-10-02 15:28:35.882291 | controller | CentOS Stream 9 - CRB 35 MB/s | 7.1 MB 00:00 2025-10-02 15:28:35.882336 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 15:28:35.882382 | controller | repo: downloading from remote: extras-common 2025-10-02 15:28:35.882428 | controller | CentOS Stream 9 - Extras packages 399 kB/s | 20 kB 00:00 2025-10-02 15:28:35.882473 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 15:28:35.882517 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 15:28:35.882562 | controller | Completion plugin: Generating completion cache... 2025-10-02 15:28:35.882607 | controller | Metadata cache created. 2025-10-02 15:28:35.882717 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.459847 2025-10-02 15:28:35.911702 | 2025-10-02 15:28:35.911860 | PLAY RECAP 2025-10-02 15:28:35.911955 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 15:28:35.912019 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 15:28:35.912062 | 2025-10-02 15:28:36.043455 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 15:28:36.044352 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 15:28:36.624825 | 2025-10-02 15:28:36.624927 | PLAY [all] 2025-10-02 15:28:36.645259 | 2025-10-02 15:28:36.645350 | TASK [Install binary dependencies] 2025-10-02 15:28:36.694425 | controller | ok 2025-10-02 15:28:36.713008 | 2025-10-02 15:28:36.713091 | TASK [bindep : Include find tasks] 2025-10-02 15:28:36.741779 | controller | ok 2025-10-02 15:28:36.749304 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 15:28:36.756657 | 2025-10-02 15:28:36.756742 | TASK [bindep : Look for bindep.txt] 2025-10-02 15:28:37.216239 | controller | ok 2025-10-02 15:28:37.227414 | 2025-10-02 15:28:37.227556 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:37.257552 | controller | ok 2025-10-02 15:28:37.262591 | 2025-10-02 15:28:37.262653 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 15:28:37.286394 | controller | skipping: Conditional result was False 2025-10-02 15:28:37.292278 | 2025-10-02 15:28:37.292346 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:37.316762 | controller | skipping: Conditional result was False 2025-10-02 15:28:37.322180 | 2025-10-02 15:28:37.322244 | TASK [bindep : Look for bindep fallback file] 2025-10-02 15:28:37.354255 | controller | skipping: Conditional result was False 2025-10-02 15:28:37.363724 | 2025-10-02 15:28:37.363836 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:37.399261 | controller | skipping: Conditional result was False 2025-10-02 15:28:37.406935 | 2025-10-02 15:28:37.407022 | TASK [bindep : Include bindep tasks] 2025-10-02 15:28:37.461080 | controller | ok 2025-10-02 15:28:37.470698 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 15:28:37.481631 | 2025-10-02 15:28:37.481738 | TASK [bindep : Look for bindep command] 2025-10-02 15:28:37.517066 | controller | skipping: Conditional result was False 2025-10-02 15:28:37.525142 | 2025-10-02 15:28:37.525235 | TASK [bindep : Check for system bindep] 2025-10-02 15:28:38.063315 | controller | ok: Runtime: 0:00:00.007409 2025-10-02 15:28:38.075922 | 2025-10-02 15:28:38.076064 | TASK [bindep : Define bindep_command fact] 2025-10-02 15:28:38.124617 | controller | skipping: Conditional result was False 2025-10-02 15:28:38.131329 | 2025-10-02 15:28:38.131400 | TASK [bindep : Include install tasks] 2025-10-02 15:28:38.184237 | controller | ok 2025-10-02 15:28:38.196720 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 15:28:38.214871 | 2025-10-02 15:28:38.214936 | TASK [bindep : Create temp dir for bindep] 2025-10-02 15:28:38.618414 | controller | changed 2025-10-02 15:28:38.626123 | 2025-10-02 15:28:38.626480 | TASK [Ensure we have pip dependencies] 2025-10-02 15:28:38.653282 | controller | ok 2025-10-02 15:28:38.688167 | 2025-10-02 15:28:38.688244 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 11:28:38.962168 | controller | /usr/bin/pip3 2025-10-02 11:28:38.986576 | controller | /usr/bin/python3: No module named wheel 2025-10-02 15:28:39.214434 | controller | ok: Runtime: 0:00:00.036777 2025-10-02 15:28:39.220428 | 2025-10-02 15:28:39.220499 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 15:28:39.246726 | controller | ok: "/var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 15:28:39.265387 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 15:28:39.277529 | 2025-10-02 15:28:39.277634 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 15:28:42.467540 | controller | changed 2025-10-02 15:28:42.480817 | 2025-10-02 15:28:42.480997 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 15:28:42.565012 | controller | skipping: Conditional result was False 2025-10-02 15:28:42.575481 | 2025-10-02 15:28:42.575596 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 15:28:42.627988 | controller | skipping: Conditional result was False 2025-10-02 15:28:42.639499 | 2025-10-02 15:28:42.639592 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 15:28:42.684398 | controller | skipping: Conditional result was False 2025-10-02 15:28:42.694402 | 2025-10-02 15:28:42.694498 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 15:28:42.721632 | controller | skipping: Conditional result was False 2025-10-02 15:28:42.734931 | 2025-10-02 15:28:42.735087 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 15:28:43.280868 | controller | skipping: Conditional result was False 2025-10-02 15:28:43.305382 | 2025-10-02 15:28:43.305762 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 15:28:43.340187 | controller | skipping: Conditional result was False 2025-10-02 15:28:43.355322 | 2025-10-02 15:28:43.355507 | TASK [ensure-pip : Install pip from source] 2025-10-02 15:28:43.386073 | controller | skipping: Conditional result was False 2025-10-02 15:28:43.398393 | 2025-10-02 15:28:43.399150 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 11:28:43.721969 | controller | /usr/bin/python3 2025-10-02 15:28:43.958559 | controller | ok: Runtime: 0:00:00.008324 2025-10-02 15:28:43.970971 | 2025-10-02 15:28:43.971147 | TASK [ensure-pip : Set host default] 2025-10-02 15:28:44.059171 | controller | ok 2025-10-02 15:28:44.067920 | 2025-10-02 15:28:44.068049 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 15:28:44.134973 | controller | ok 2025-10-02 15:28:44.149628 | 2025-10-02 15:28:44.149763 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 15:28:50.266397 | controller | changed 2025-10-02 15:28:50.273500 | 2025-10-02 15:28:50.273571 | TASK [bindep : Define bindep_command] 2025-10-02 15:28:50.318792 | controller | ok 2025-10-02 15:28:50.325829 | 2025-10-02 15:28:50.325913 | LOOP [bindep : Include package tasks] 2025-10-02 15:28:50.391977 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 15:28:50.392254 | controller | ok: All items complete 2025-10-02 15:28:50.392291 | 2025-10-02 15:28:50.419227 | controller | included: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 15:28:50.451810 | 2025-10-02 15:28:50.451972 | TASK [bindep : Define bindep_run fact] 2025-10-02 15:28:50.501795 | controller | ok 2025-10-02 15:28:50.514057 | 2025-10-02 15:28:50.514256 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 11:28:52.270602 | controller | podman 2025-10-02 11:28:52.315079 | controller | python3-jmespath 2025-10-02 11:28:52.315341 | controller | python3-libvirt 2025-10-02 11:28:52.315393 | controller | python3-lxml 2025-10-02 11:28:52.315408 | controller | python3-netaddr 2025-10-02 15:28:52.561977 | controller | ok: Runtime: 0:00:01.453781 2025-10-02 15:28:52.574228 | 2025-10-02 15:28:52.574373 | TASK [bindep : Install distro packages from bindep] 2025-10-02 15:30:00.430360 | controller | changed 2025-10-02 15:30:00.438167 | 2025-10-02 15:30:00.438253 | TASK [bindep : Check that packages are installed] 2025-10-02 15:30:01.977096 | controller | ok: Runtime: 0:00:01.165181 2025-10-02 15:30:01.983319 | 2025-10-02 15:30:01.983385 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 15:30:02.017263 | controller | skipping: Conditional result was False 2025-10-02 15:30:02.028646 | 2025-10-02 15:30:02.028818 | TASK [Run test-setup role] 2025-10-02 15:30:02.048827 | controller | ok 2025-10-02 15:30:02.067802 | 2025-10-02 15:30:02.067927 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 15:30:02.285457 | controller | ok 2025-10-02 15:30:02.307137 | 2025-10-02 15:30:02.307254 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 15:30:02.837760 | controller | skipping: Conditional result was False 2025-10-02 15:30:02.858691 | 2025-10-02 15:30:02.858764 | TASK [bindep : Remove bindep temp dir] 2025-10-02 15:30:03.224823 | controller | ok 2025-10-02 15:30:03.246917 | 2025-10-02 15:30:03.247027 | PLAY RECAP 2025-10-02 15:30:03.247083 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 15:30:03.247111 | 2025-10-02 15:30:03.483848 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 15:30:03.484685 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 15:30:04.238198 | 2025-10-02 15:30:04.238316 | PLAY [all] 2025-10-02 15:30:04.257223 | 2025-10-02 15:30:04.257295 | TASK [Abort when test_command variable is undefined] 2025-10-02 15:30:04.302785 | controller | skipping: Conditional result was False 2025-10-02 15:30:04.308416 | 2025-10-02 15:30:04.308488 | TASK [Convert test_command to list] 2025-10-02 15:30:04.433530 | controller | skipping: Conditional result was False 2025-10-02 15:30:04.439879 | 2025-10-02 15:30:04.439954 | TASK [Use test_command list] 2025-10-02 15:30:04.500520 | controller | ok 2025-10-02 15:30:04.506128 | 2025-10-02 15:30:04.506194 | LOOP [Run test_command] 2025-10-02 15:30:05.041162 | controller | no check to run 2025-10-02 15:30:05.041564 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005895 2025-10-02 15:30:05.088641 | 2025-10-02 15:30:05.088793 | PLAY RECAP 2025-10-02 15:30:05.088877 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 15:30:05.088922 | 2025-10-02 15:30:05.217095 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 15:30:05.217902 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 15:30:05.823756 | 2025-10-02 15:30:05.823864 | PLAY [all] 2025-10-02 15:30:05.843878 | 2025-10-02 15:30:05.843967 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 15:30:06.231736 | controller | changed: non-zero return code 2025-10-02 15:30:06.241034 | 2025-10-02 15:30:06.242506 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 15:30:06.279341 | controller | skipping: Conditional result was False 2025-10-02 15:30:06.285038 | 2025-10-02 15:30:06.285122 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 15:30:06.325381 | 2025-10-02 15:30:06.325537 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 15:30:06.361574 | 2025-10-02 15:30:06.361786 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 15:30:06.396828 | controller | skipping: Conditional result was False 2025-10-02 15:30:06.403332 | 2025-10-02 15:30:06.403400 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 15:30:06.448862 | 2025-10-02 15:30:06.449019 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 15:30:06.493039 | controller | skipping: Conditional result was False 2025-10-02 15:30:06.499256 | 2025-10-02 15:30:06.499327 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 15:30:06.523263 | controller | skipping: Conditional result was False 2025-10-02 15:30:06.529001 | 2025-10-02 15:30:06.529067 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 15:30:06.572483 | controller | skipping: Conditional result was False 2025-10-02 15:30:06.613978 | 2025-10-02 15:30:06.614087 | PLAY RECAP 2025-10-02 15:30:06.614130 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 15:30:06.614150 | 2025-10-02 15:30:06.719722 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 15:30:06.720529 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 15:30:07.305171 | 2025-10-02 15:30:07.305284 | PLAY [all] 2025-10-02 15:30:07.326526 | 2025-10-02 15:30:07.326614 | TASK [include_role : fetch-output] 2025-10-02 15:30:07.355533 | controller | ok 2025-10-02 15:30:07.372514 | 2025-10-02 15:30:07.372640 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 15:30:07.417079 | controller | skipping: Conditional result was False 2025-10-02 15:30:07.423076 | 2025-10-02 15:30:07.423143 | TASK [fetch-output : Set log path for single node] 2025-10-02 15:30:07.472031 | controller | ok 2025-10-02 15:30:07.477019 | 2025-10-02 15:30:07.477091 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 15:30:07.937997 | controller -> localhost | ok: "/var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/logs" 2025-10-02 15:30:08.187315 | controller -> localhost | changed: "/var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/artifacts" 2025-10-02 15:30:08.541640 | controller -> localhost | changed: "/var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/docs" 2025-10-02 15:30:08.550913 | 2025-10-02 15:30:08.551024 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 15:30:09.211304 | controller | changed: .d..t...... ./ 2025-10-02 15:30:09.211497 | controller | changed: All items complete 2025-10-02 15:30:09.211525 | 2025-10-02 15:30:09.666842 | controller | changed: .d..t...... ./ 2025-10-02 15:30:10.151813 | controller | changed: .d..t...... ./ 2025-10-02 15:30:10.169019 | 2025-10-02 15:30:10.169123 | TASK [include_role : fetch-output-openshift] 2025-10-02 15:30:10.192559 | controller | skipping: Conditional result was False 2025-10-02 15:30:10.199319 | 2025-10-02 15:30:10.199388 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 15:30:10.645912 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.011517 2025-10-02 15:30:10.911281 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.016783 2025-10-02 15:30:10.961419 | 2025-10-02 15:30:10.961509 | PLAY [all] 2025-10-02 15:30:10.976322 | 2025-10-02 15:30:10.976396 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 15:30:11.413820 | controller | changed 2025-10-02 15:30:11.450753 | 2025-10-02 15:30:11.450978 | PLAY RECAP 2025-10-02 15:30:11.451026 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 15:30:11.451048 | 2025-10-02 15:30:11.588092 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 15:30:11.588938 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 15:30:12.199935 | 2025-10-02 15:30:12.200047 | PLAY [localhost] 2025-10-02 15:30:12.218776 | 2025-10-02 15:30:12.218873 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 15:30:12.612689 | localhost | changed 2025-10-02 15:30:12.617333 | 2025-10-02 15:30:12.617410 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 15:30:12.646523 | localhost | ok 2025-10-02 15:30:12.654633 | 2025-10-02 15:30:12.654715 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 15:30:13.009857 | localhost | changed 2025-10-02 15:30:13.014789 | 2025-10-02 15:30:13.014856 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 15:30:13.655529 | localhost | changed 2025-10-02 15:30:13.660598 | 2025-10-02 15:30:13.660660 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 15:30:14.060874 | localhost | Identity added: /var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/tmp/ansible.m90ogzbk (/var/lib/zuul/builds/80b2aee2296d42adbc8e704fe5a14d4c/work/tmp/ansible.m90ogzbk) 2025-10-02 15:30:14.061075 | localhost | ok: Runtime: 0:00:00.009759 2025-10-02 15:30:14.066415 | 2025-10-02 15:30:14.066492 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 15:30:14.308558 | localhost | ok: Runtime: 0:00:00.006304 2025-10-02 15:30:14.313320 | 2025-10-02 15:30:14.313381 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 15:30:14.362546 | localhost | changed 2025-10-02 15:30:14.367696 | 2025-10-02 15:30:14.367765 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 15:30:14.744251 | localhost | changed 2025-10-02 15:30:14.772947 | 2025-10-02 15:30:14.773031 | PLAY [localhost] 2025-10-02 15:30:14.787456 | 2025-10-02 15:30:14.787518 | TASK [Generate bulk log download script] 2025-10-02 15:30:14.816421 | localhost | ok 2025-10-02 15:30:14.828272 | 2025-10-02 15:30:14.828337 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 15:30:14.855780 | localhost | ok: All assertions passed 2025-10-02 15:30:14.861331 | 2025-10-02 15:30:14.861418 | TASK [local-log-download : Create download script] 2025-10-02 15:30:15.252897 | localhost -> localhost | changed 2025-10-02 15:30:15.261996 | 2025-10-02 15:30:15.262061 | TASK [Register quick-download link] 2025-10-02 15:30:15.280693 | localhost | ok 2025-10-02 15:30:15.323442 | 2025-10-02 15:30:15.323535 | PLAY [logserver.rdoproject.org] 2025-10-02 15:30:15.334179 | 2025-10-02 15:30:15.334239 | TASK [Set zuul-log-path fact] 2025-10-02 15:30:15.360611 | logserver.rdoproject.org | ok 2025-10-02 15:30:15.378022 | 2025-10-02 15:30:15.378118 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 15:30:15.424990 | logserver.rdoproject.org | ok 2025-10-02 15:30:15.431188 | 2025-10-02 15:30:15.431256 | TASK [upload-logs : Create log directories] 2025-10-02 15:30:16.081190 | logserver.rdoproject.org | changed 2025-10-02 15:30:16.085646 | 2025-10-02 15:30:16.085759 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 15:30:16.397764 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009030 2025-10-02 15:30:16.416597 | 2025-10-02 15:30:16.416772 | TASK [upload-logs : Upload logs to log server] 2025-10-02 15:30:17.118157 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 15:30:17.121598 | 2025-10-02 15:30:17.121693 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 15:30:17.182782 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:17.192337 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:17.204601 | 2025-10-02 15:30:17.204791 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 15:30:17.245377 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:17.245799 | 2025-10-02 15:30:17.248615 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:17.258424 | 2025-10-02 15:30:17.258559 | LOOP [upload-logs : Upload console log and json output]