2026-02-03 08:18:05.203326 | Job console starting... 2026-02-03 08:18:05.214704 | Updating repositories 2026-02-03 08:18:05.243222 | Preparing job workspace 2026-02-03 08:18:09.249105 | Running Ansible setup... 2026-02-03 08:18:12.999644 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2026-02-03 08:18:13.610810 | 2026-02-03 08:18:13.610946 | PLAY [localhost] 2026-02-03 08:18:13.620340 | 2026-02-03 08:18:13.620423 | TASK [Gathering Facts] 2026-02-03 08:18:14.660514 | localhost | ok 2026-02-03 08:18:14.687675 | 2026-02-03 08:18:14.687916 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-03 08:18:15.090493 | localhost -> localhost | changed 2026-02-03 08:18:15.096311 | 2026-02-03 08:18:15.096411 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-03 08:18:16.029463 | localhost -> localhost | changed 2026-02-03 08:18:16.038337 | 2026-02-03 08:18:16.038434 | TASK [Setup log path fact] 2026-02-03 08:18:16.057741 | localhost | ok 2026-02-03 08:18:16.068792 | 2026-02-03 08:18:16.068866 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-03 08:18:16.096628 | localhost | ok 2026-02-03 08:18:16.104549 | 2026-02-03 08:18:16.104658 | TASK [emit-job-header : Print job information] 2026-02-03 08:18:16.142673 | # Job Information 2026-02-03 08:18:16.142827 | Ansible Version: 2.15.12 2026-02-03 08:18:16.142853 | Job: cifmw-molecule-edpm_ssh_info 2026-02-03 08:18:16.142873 | Pipeline: github-check 2026-02-03 08:18:16.142892 | Executor: ze01.softwarefactory-project.io 2026-02-03 08:18:16.142910 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3650 2026-02-03 08:18:16.142928 | Log URL (when completed): https://logserver.rdoproject.org/1e6/rdoproject.org/1e667ad72983470d8eb1febc349a1329/ 2026-02-03 08:18:16.142947 | Event ID: aa641e20-00d8-11f1-983d-df89e0ae7296 2026-02-03 08:18:16.146916 | 2026-02-03 08:18:16.146983 | LOOP [emit-job-header : Print node information] 2026-02-03 08:18:16.256314 | localhost | ok: 2026-02-03 08:18:16.256485 | localhost | # Node Information 2026-02-03 08:18:16.256512 | localhost | Inventory Hostname: controller 2026-02-03 08:18:16.256533 | localhost | Hostname: np0005606382 2026-02-03 08:18:16.256554 | localhost | Username: zuul 2026-02-03 08:18:16.256574 | localhost | Distro: CentOS 9 2026-02-03 08:18:16.256592 | localhost | Provider: vexxhost-nodepool-tripleo 2026-02-03 08:18:16.256610 | localhost | Region: RegionOne 2026-02-03 08:18:16.256627 | localhost | Label: cloud-centos-9-stream-tripleo 2026-02-03 08:18:16.256644 | localhost | Product Name: OpenStack Nova 2026-02-03 08:18:16.256660 | localhost | Interface IP: 38.102.83.18 2026-02-03 08:18:16.280676 | 2026-02-03 08:18:16.280762 | PLAY [all] 2026-02-03 08:18:16.287097 | 2026-02-03 08:18:16.287157 | TASK [Gather network facts] 2026-02-03 08:18:16.735682 | controller | ok 2026-02-03 08:18:16.771538 | 2026-02-03 08:18:16.771734 | TASK [include_role : start-zuul-console] 2026-02-03 08:18:16.794562 | controller | ok 2026-02-03 08:18:16.811853 | 2026-02-03 08:18:16.811998 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-03 08:18:17.227835 | controller | ok 2026-02-03 08:18:17.249632 | 2026-02-03 08:18:17.249818 | TASK [include_role : add-build-sshkey] 2026-02-03 08:18:17.288324 | controller | ok 2026-02-03 08:18:17.318147 | 2026-02-03 08:18:17.318353 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-03 08:18:17.610002 | controller -> localhost | ok 2026-02-03 08:18:17.616384 | 2026-02-03 08:18:17.616474 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-03 08:18:17.648356 | controller | ok 2026-02-03 08:18:17.663255 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-03 08:18:17.670298 | 2026-02-03 08:18:17.670440 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-03 08:18:18.754150 | controller -> localhost | Generating public/private rsa key pair. 2026-02-03 08:18:18.754515 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/1e667ad72983470d8eb1febc349a1329_id_rsa. 2026-02-03 08:18:18.754549 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/1e667ad72983470d8eb1febc349a1329_id_rsa.pub. 2026-02-03 08:18:18.754572 | controller -> localhost | The key fingerprint is: 2026-02-03 08:18:18.754592 | controller -> localhost | SHA256:KzkDuR4rSsp84ONceg9xyMCysH/VCrASOCOTMvvQmoE zuul-build-sshkey 2026-02-03 08:18:18.754612 | controller -> localhost | The key's randomart image is: 2026-02-03 08:18:18.754631 | controller -> localhost | +---[RSA 3072]----+ 2026-02-03 08:18:18.754648 | controller -> localhost | | | 2026-02-03 08:18:18.754667 | controller -> localhost | |o. | 2026-02-03 08:18:18.754686 | controller -> localhost | |&o. | 2026-02-03 08:18:18.754704 | controller -> localhost | |*@oo.. . | 2026-02-03 08:18:18.754722 | controller -> localhost | |E o++.. S | 2026-02-03 08:18:18.754739 | controller -> localhost | | X o= o . | 2026-02-03 08:18:18.754756 | controller -> localhost | |+.+o+ * . | 2026-02-03 08:18:18.754785 | controller -> localhost | |*o+=.o + | 2026-02-03 08:18:18.754804 | controller -> localhost | |+B+.+. | 2026-02-03 08:18:18.754821 | controller -> localhost | +----[SHA256]-----+ 2026-02-03 08:18:18.754870 | controller -> localhost | ok: Runtime: 0:00:00.586622 2026-02-03 08:18:18.761209 | 2026-02-03 08:18:18.761330 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-03 08:18:18.802652 | controller | ok 2026-02-03 08:18:18.827250 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-03 08:18:18.843777 | 2026-02-03 08:18:18.843946 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-03 08:18:18.861876 | controller | skipping: Conditional result was False 2026-02-03 08:18:18.881694 | 2026-02-03 08:18:18.881898 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-03 08:18:19.400962 | controller | changed 2026-02-03 08:18:19.406058 | 2026-02-03 08:18:19.406139 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-03 08:18:19.649599 | controller | ok 2026-02-03 08:18:19.662935 | 2026-02-03 08:18:19.663177 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-03 08:18:20.444580 | controller | changed 2026-02-03 08:18:20.451987 | 2026-02-03 08:18:20.452109 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-03 08:18:21.252180 | controller | changed 2026-02-03 08:18:21.263923 | 2026-02-03 08:18:21.264125 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-03 08:18:21.290604 | controller | skipping: Conditional result was False 2026-02-03 08:18:21.299500 | 2026-02-03 08:18:21.299614 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-03 08:18:21.722987 | controller -> localhost | changed 2026-02-03 08:18:21.733234 | 2026-02-03 08:18:21.733355 | TASK [add-build-sshkey : Add back temp key] 2026-02-03 08:18:22.021307 | controller -> localhost | Identity added: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/1e667ad72983470d8eb1febc349a1329_id_rsa (zuul-build-sshkey) 2026-02-03 08:18:22.021534 | controller -> localhost | ok: Runtime: 0:00:00.008088 2026-02-03 08:18:22.028784 | 2026-02-03 08:18:22.028883 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-03 08:18:22.410614 | controller | ok 2026-02-03 08:18:22.418170 | 2026-02-03 08:18:22.418366 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-03 08:18:22.443408 | controller | skipping: Conditional result was False 2026-02-03 08:18:22.453967 | 2026-02-03 08:18:22.454180 | TASK [include_role : validate-host] 2026-02-03 08:18:22.487172 | controller | ok 2026-02-03 08:18:22.509425 | 2026-02-03 08:18:22.509577 | TASK [validate-host : Define zuul_info_dir fact] 2026-02-03 08:18:22.541479 | controller | ok 2026-02-03 08:18:22.546968 | 2026-02-03 08:18:22.547073 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2026-02-03 08:18:22.818907 | controller -> localhost | ok 2026-02-03 08:18:22.825618 | 2026-02-03 08:18:22.825742 | TASK [validate-host : Collect information about the host] 2026-02-03 08:18:23.618188 | controller | ok 2026-02-03 08:18:23.628250 | 2026-02-03 08:18:23.628351 | TASK [validate-host : Sanitize hostname] 2026-02-03 08:18:23.694805 | controller | ok 2026-02-03 08:18:23.703207 | 2026-02-03 08:18:23.703382 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2026-02-03 08:18:24.285825 | controller -> localhost | changed 2026-02-03 08:18:24.292145 | 2026-02-03 08:18:24.292222 | TASK [validate-host : Collect information about zuul worker] 2026-02-03 08:18:24.700084 | controller | ok 2026-02-03 08:18:24.706202 | 2026-02-03 08:18:24.706345 | TASK [validate-host : Write out all zuul information for each host] 2026-02-03 08:18:25.289540 | controller -> localhost | changed 2026-02-03 08:18:25.302192 | 2026-02-03 08:18:25.302271 | TASK [include_role : prepare-workspace-openshift] 2026-02-03 08:18:25.326569 | controller | skipping: Conditional result was False 2026-02-03 08:18:25.333563 | 2026-02-03 08:18:25.333920 | TASK [include_role : remove-zuul-sshkey] 2026-02-03 08:18:25.363344 | controller | skipping: Conditional result was False 2026-02-03 08:18:25.368874 | 2026-02-03 08:18:25.368942 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-03 08:18:25.659137 | controller | ok: "logs" 2026-02-03 08:18:25.659501 | controller | ok: All items complete 2026-02-03 08:18:25.659540 | 2026-02-03 08:18:25.877251 | controller | ok: "artifacts" 2026-02-03 08:18:26.093586 | controller | ok: "docs" 2026-02-03 08:18:26.110824 | 2026-02-03 08:18:26.110958 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-03 08:18:26.334621 | controller | changed: "logs" 2026-02-03 08:18:26.515857 | controller | changed: "artifacts" 2026-02-03 08:18:26.764107 | controller | changed: "docs" 2026-02-03 08:18:26.795311 | 2026-02-03 08:18:26.795454 | PLAY RECAP 2026-02-03 08:18:26.795514 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2026-02-03 08:18:26.795551 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-03 08:18:26.795577 | 2026-02-03 08:18:26.922815 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2026-02-03 08:18:26.924718 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2026-02-03 08:18:27.627161 | 2026-02-03 08:18:27.627378 | PLAY [localhost] 2026-02-03 08:18:27.648292 | 2026-02-03 08:18:27.648486 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2026-02-03 08:18:28.114252 | localhost | ok 2026-02-03 08:18:28.126602 | 2026-02-03 08:18:28.126807 | TASK [configure-ssh-config-fips : Setup ssh config] 2026-02-03 08:18:28.952456 | localhost | changed 2026-02-03 08:18:28.982791 | 2026-02-03 08:18:28.983047 | PLAY [all] 2026-02-03 08:18:29.006675 | 2026-02-03 08:18:29.007110 | TASK [include_role : prepare-workspace] 2026-02-03 08:18:29.050809 | controller | ok 2026-02-03 08:18:29.072400 | 2026-02-03 08:18:29.072526 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-03 08:18:29.501607 | controller | ok 2026-02-03 08:18:29.523465 | 2026-02-03 08:18:29.523911 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-03 08:18:31.233885 | controller | Output suppressed because no_log was given 2026-02-03 08:18:31.249690 | 2026-02-03 08:18:31.249815 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-03 08:18:31.472006 | controller | changed: "logs" 2026-02-03 08:18:31.657531 | controller | changed: "artifacts" 2026-02-03 08:18:31.854874 | controller | changed: "docs" 2026-02-03 08:18:31.874340 | 2026-02-03 08:18:31.874549 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-03 08:18:32.173880 | controller | changed: "logs" 2026-02-03 08:18:32.174233 | controller | changed: All items complete 2026-02-03 08:18:32.174273 | 2026-02-03 08:18:32.387323 | controller | changed: "artifacts" 2026-02-03 08:18:32.649127 | controller | changed: "docs" 2026-02-03 08:18:32.673094 | 2026-02-03 08:18:32.673312 | TASK [Check if worker can sudo] 2026-02-03 08:18:33.724436 | controller | ok: Runtime: 0:00:00.054537 2026-02-03 08:18:33.740332 | 2026-02-03 08:18:33.740601 | TASK [configure-mirrors : Gather needed facts] 2026-02-03 08:18:33.817396 | controller | skipping: Conditional result was False 2026-02-03 08:18:33.830891 | 2026-02-03 08:18:33.831075 | TASK [configure-mirrors : Set up infrastructure mirrors] 2026-02-03 08:18:33.930920 | controller | ok 2026-02-03 08:18:33.942220 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2026-02-03 08:18:33.949460 | 2026-02-03 08:18:33.949531 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2026-02-03 08:18:34.364417 | controller | ok 2026-02-03 08:18:34.383511 | 2026-02-03 08:18:34.383713 | LOOP [configure-mirrors : Include OS-specific variables] 2026-02-03 08:18:34.459627 | controller | ok: "/var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2026-02-03 08:18:34.468881 | 2026-02-03 08:18:34.468981 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2026-02-03 08:18:35.254286 | controller | changed 2026-02-03 08:18:35.264732 | 2026-02-03 08:18:35.264933 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2026-02-03 08:18:35.323664 | controller | ok: "/var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2026-02-03 08:18:35.323892 | controller | ok: All items complete 2026-02-03 08:18:35.323922 | 2026-02-03 08:18:35.374357 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2026-02-03 08:18:35.382579 | 2026-02-03 08:18:35.382662 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2026-02-03 08:18:36.256252 | controller | changed: "etc/yum.repos.d/centos.repo" 2026-02-03 08:18:37.044383 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2026-02-03 08:18:37.063309 | 2026-02-03 08:18:37.063566 | TASK [configure-mirrors : Disable deltrarpm] 2026-02-03 08:18:37.555814 | controller | changed: section and option added 2026-02-03 08:18:37.578712 | 2026-02-03 08:18:37.578916 | LOOP [configure-mirrors : Update yum/dnf cache] 2026-02-03 08:18:38.381727 | controller | 29 files removed 2026-02-03 08:18:38.382119 | controller | ok: Item: dnf clean all Runtime: 0:00:00.457540 2026-02-03 08:18:38.382203 | controller | changed: All items complete 2026-02-03 08:18:38.382237 | 2026-02-03 08:18:49.980747 | 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 2026-02-03 08:18:49.980881 | controller | DNF version: 4.14.0 2026-02-03 08:18:49.980905 | controller | cachedir: /var/cache/dnf 2026-02-03 08:18:49.980925 | controller | Making cache files for all metadata files. 2026-02-03 08:18:49.980943 | controller | baseos: has expired and will be refreshed. 2026-02-03 08:18:49.980959 | controller | appstream: has expired and will be refreshed. 2026-02-03 08:18:49.980975 | controller | crb: has expired and will be refreshed. 2026-02-03 08:18:49.981002 | controller | extras-common: has expired and will be refreshed. 2026-02-03 08:18:49.981042 | controller | repo: downloading from remote: baseos 2026-02-03 08:18:49.981060 | controller | CentOS Stream 9 - BaseOS 62 MB/s | 8.9 MB 00:00 2026-02-03 08:18:49.981076 | controller | baseos: using metadata from Mon 02 Feb 2026 10:49:57 AM EST. 2026-02-03 08:18:49.981092 | controller | repo: downloading from remote: appstream 2026-02-03 08:18:49.981107 | controller | CentOS Stream 9 - AppStream 72 MB/s | 27 MB 00:00 2026-02-03 08:18:49.981122 | controller | appstream: using metadata from Mon 02 Feb 2026 10:53:25 AM EST. 2026-02-03 08:18:49.981137 | controller | repo: downloading from remote: crb 2026-02-03 08:18:49.981152 | controller | CentOS Stream 9 - CRB 83 MB/s | 7.8 MB 00:00 2026-02-03 08:18:49.981167 | controller | crb: using metadata from Mon 02 Feb 2026 10:57:49 AM EST. 2026-02-03 08:18:49.981183 | controller | repo: downloading from remote: extras-common 2026-02-03 08:18:49.981198 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2026-02-03 08:18:49.981214 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2026-02-03 08:18:49.981228 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2026-02-03 08:18:49.981244 | controller | Completion plugin: Generating completion cache... 2026-02-03 08:18:49.981258 | controller | Metadata cache created. 2026-02-03 08:18:49.981283 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.313627 2026-02-03 08:18:49.998552 | 2026-02-03 08:18:49.999069 | PLAY RECAP 2026-02-03 08:18:49.999180 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-02-03 08:18:49.999239 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-03 08:18:49.999279 | 2026-02-03 08:18:50.187932 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2026-02-03 08:18:50.188859 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-03 08:18:50.815360 | 2026-02-03 08:18:50.815482 | PLAY [all] 2026-02-03 08:18:50.838339 | 2026-02-03 08:18:50.838495 | TASK [Install binary dependencies] 2026-02-03 08:18:50.889921 | controller | ok 2026-02-03 08:18:50.912527 | 2026-02-03 08:18:50.912738 | TASK [bindep : Include find tasks] 2026-02-03 08:18:50.954092 | controller | ok 2026-02-03 08:18:50.967281 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-03 08:18:50.975987 | 2026-02-03 08:18:50.976159 | TASK [bindep : Look for bindep.txt] 2026-02-03 08:18:51.384080 | controller | ok 2026-02-03 08:18:51.392386 | 2026-02-03 08:18:51.392521 | TASK [bindep : Define bindep_file fact] 2026-02-03 08:18:51.425787 | controller | ok 2026-02-03 08:18:51.434126 | 2026-02-03 08:18:51.434240 | TASK [bindep : Look for other-requirements.txt] 2026-02-03 08:18:51.448828 | controller | skipping: Conditional result was False 2026-02-03 08:18:51.454960 | 2026-02-03 08:18:51.455062 | TASK [bindep : Define bindep_file fact] 2026-02-03 08:18:51.488957 | controller | skipping: Conditional result was False 2026-02-03 08:18:51.495525 | 2026-02-03 08:18:51.495627 | TASK [bindep : Look for bindep fallback file] 2026-02-03 08:18:51.519347 | controller | skipping: Conditional result was False 2026-02-03 08:18:51.526623 | 2026-02-03 08:18:51.526731 | TASK [bindep : Define bindep_file fact] 2026-02-03 08:18:51.542978 | controller | skipping: Conditional result was False 2026-02-03 08:18:51.550028 | 2026-02-03 08:18:51.550114 | TASK [bindep : Include bindep tasks] 2026-02-03 08:18:51.599701 | controller | ok 2026-02-03 08:18:51.606139 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2026-02-03 08:18:51.614337 | 2026-02-03 08:18:51.614400 | TASK [bindep : Look for bindep command] 2026-02-03 08:18:51.648497 | controller | skipping: Conditional result was False 2026-02-03 08:18:51.655554 | 2026-02-03 08:18:51.655624 | TASK [bindep : Check for system bindep] 2026-02-03 08:18:52.186905 | controller | ok: Runtime: 0:00:00.005392 2026-02-03 08:18:52.206143 | 2026-02-03 08:18:52.206471 | TASK [bindep : Define bindep_command fact] 2026-02-03 08:18:52.245264 | controller | skipping: Conditional result was False 2026-02-03 08:18:52.251980 | 2026-02-03 08:18:52.252089 | TASK [bindep : Include install tasks] 2026-02-03 08:18:52.304349 | controller | ok 2026-02-03 08:18:52.313035 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2026-02-03 08:18:52.323114 | 2026-02-03 08:18:52.323213 | TASK [bindep : Create temp dir for bindep] 2026-02-03 08:18:52.702684 | controller | changed 2026-02-03 08:18:52.717090 | 2026-02-03 08:18:52.717606 | TASK [Ensure we have pip dependencies] 2026-02-03 08:18:52.744634 | controller | ok 2026-02-03 08:18:52.782047 | 2026-02-03 08:18:52.782266 | TASK [ensure-pip : Check if pip is installed] 2026-02-03 03:18:53.057072 | controller | /usr/bin/pip3 2026-02-03 03:18:53.079205 | controller | /usr/bin/python3: No module named wheel 2026-02-03 08:18:53.317437 | controller | ok: Runtime: 0:00:00.029514 2026-02-03 08:18:53.329178 | 2026-02-03 08:18:53.329391 | LOOP [ensure-pip : Install pip from packages] 2026-02-03 08:18:53.379655 | controller | ok: "/var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2026-02-03 08:18:53.394388 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2026-02-03 08:18:53.428148 | 2026-02-03 08:18:53.428606 | TASK [ensure-pip : Install Python 3 pip] 2026-02-03 08:18:55.596172 | controller | changed 2026-02-03 08:18:55.607840 | 2026-02-03 08:18:55.607926 | TASK [ensure-pip : Check for EPEL repository] 2026-02-03 08:18:55.664382 | controller | skipping: Conditional result was False 2026-02-03 08:18:55.676490 | 2026-02-03 08:18:55.676635 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2026-02-03 08:18:55.723332 | controller | skipping: Conditional result was False 2026-02-03 08:18:55.732573 | 2026-02-03 08:18:55.732668 | TASK [ensure-pip : Install Python 2 pip] 2026-02-03 08:18:55.769630 | controller | skipping: Conditional result was False 2026-02-03 08:18:55.782976 | 2026-02-03 08:18:55.783168 | TASK [ensure-pip : Ensure setuptools] 2026-02-03 08:18:55.810827 | controller | skipping: Conditional result was False 2026-02-03 08:18:55.825118 | 2026-02-03 08:18:55.825268 | TASK [ensure-pip : Check for ensurepip module] 2026-02-03 08:18:56.370110 | controller | skipping: Conditional result was False 2026-02-03 08:18:56.377274 | 2026-02-03 08:18:56.377375 | TASK [ensure-pip : Ensure python3-venv] 2026-02-03 08:18:56.405954 | controller | skipping: Conditional result was False 2026-02-03 08:18:56.426969 | 2026-02-03 08:18:56.427175 | TASK [ensure-pip : Install pip from source] 2026-02-03 08:18:56.458131 | controller | skipping: Conditional result was False 2026-02-03 08:18:56.468286 | 2026-02-03 08:18:56.468409 | TASK [ensure-pip : Probe for venv python full path] 2026-02-03 03:18:56.749317 | controller | /usr/bin/python3 2026-02-03 08:18:57.011006 | controller | ok: Runtime: 0:00:00.004275 2026-02-03 08:18:57.025797 | 2026-02-03 08:18:57.025991 | TASK [ensure-pip : Set host default] 2026-02-03 08:18:57.108845 | controller | ok 2026-02-03 08:18:57.122537 | 2026-02-03 08:18:57.122700 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2026-02-03 08:18:57.217908 | controller | ok 2026-02-03 08:18:57.243510 | 2026-02-03 08:18:57.243705 | TASK [bindep : Install bindep into temporary venv] 2026-02-03 08:19:02.107373 | controller | changed 2026-02-03 08:19:02.114449 | 2026-02-03 08:19:02.114564 | TASK [bindep : Define bindep_command] 2026-02-03 08:19:02.155866 | controller | ok 2026-02-03 08:19:02.169148 | 2026-02-03 08:19:02.169288 | LOOP [bindep : Include package tasks] 2026-02-03 08:19:02.261980 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2026-02-03 08:19:02.262277 | controller | ok: All items complete 2026-02-03 08:19:02.262318 | 2026-02-03 08:19:02.284083 | controller | included: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2026-02-03 08:19:02.304932 | 2026-02-03 08:19:02.305267 | TASK [bindep : Define bindep_run fact] 2026-02-03 08:19:02.339629 | controller | ok 2026-02-03 08:19:02.348596 | 2026-02-03 08:19:02.348756 | TASK [bindep : Get list of packages to install from bindep] 2026-02-03 03:19:03.765499 | controller | podman 2026-02-03 03:19:03.806722 | controller | python3-jmespath 2026-02-03 03:19:03.806922 | controller | python3-libvirt 2026-02-03 03:19:03.806934 | controller | python3-lxml 2026-02-03 03:19:03.806942 | controller | python3-netaddr 2026-02-03 08:19:03.891482 | controller | ok: Runtime: 0:00:01.191001 2026-02-03 08:19:03.909328 | 2026-02-03 08:19:03.909546 | TASK [bindep : Install distro packages from bindep] 2026-02-03 08:19:53.327622 | controller | changed 2026-02-03 08:19:53.340158 | 2026-02-03 08:19:53.340335 | TASK [bindep : Check that packages are installed] 2026-02-03 08:19:54.890815 | controller | ok: Runtime: 0:00:01.134248 2026-02-03 08:19:54.905715 | 2026-02-03 08:19:54.905965 | TASK [bindep : Fail if we cannot install all packages] 2026-02-03 08:19:54.937145 | controller | skipping: Conditional result was False 2026-02-03 08:19:54.954286 | 2026-02-03 08:19:54.954466 | TASK [Run test-setup role] 2026-02-03 08:19:54.981166 | controller | ok 2026-02-03 08:19:55.039892 | 2026-02-03 08:19:55.040040 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-03 08:19:55.289828 | controller | ok 2026-02-03 08:19:55.301664 | 2026-02-03 08:19:55.301874 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-03 08:19:55.858947 | controller | skipping: Conditional result was False 2026-02-03 08:19:55.894051 | 2026-02-03 08:19:55.894244 | TASK [bindep : Remove bindep temp dir] 2026-02-03 08:19:56.304771 | controller | ok 2026-02-03 08:19:56.333177 | 2026-02-03 08:19:56.333403 | PLAY RECAP 2026-02-03 08:19:56.333478 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2026-02-03 08:19:56.333514 | 2026-02-03 08:19:56.511084 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-03 08:19:56.512121 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2026-02-03 08:19:57.137071 | 2026-02-03 08:19:57.137216 | PLAY [all] 2026-02-03 08:19:57.161530 | 2026-02-03 08:19:57.161699 | TASK [Abort when test_command variable is undefined] 2026-02-03 08:19:57.208793 | controller | skipping: Conditional result was False 2026-02-03 08:19:57.217867 | 2026-02-03 08:19:57.218000 | TASK [Convert test_command to list] 2026-02-03 08:19:57.285682 | controller | skipping: Conditional result was False 2026-02-03 08:19:57.295513 | 2026-02-03 08:19:57.295651 | TASK [Use test_command list] 2026-02-03 08:19:57.350135 | controller | ok 2026-02-03 08:19:57.361273 | 2026-02-03 08:19:57.361419 | LOOP [Run test_command] 2026-02-03 08:19:57.821733 | controller | no check to run 2026-02-03 08:19:57.822052 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006520 2026-02-03 08:19:57.861102 | 2026-02-03 08:19:57.861274 | PLAY RECAP 2026-02-03 08:19:57.861335 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2026-02-03 08:19:57.861365 | 2026-02-03 08:19:57.984868 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2026-02-03 08:19:57.986252 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-03 08:19:58.660502 | 2026-02-03 08:19:58.660649 | PLAY [all] 2026-02-03 08:19:58.685378 | 2026-02-03 08:19:58.685542 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-03 08:19:59.023829 | controller | changed: non-zero return code 2026-02-03 08:19:59.037704 | 2026-02-03 08:19:59.037982 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-03 08:19:59.066741 | controller | skipping: Conditional result was False 2026-02-03 08:19:59.081634 | 2026-02-03 08:19:59.081864 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-03 08:19:59.126229 | 2026-02-03 08:19:59.126579 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-03 08:19:59.163790 | 2026-02-03 08:19:59.164049 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-03 08:19:59.189188 | controller | skipping: Conditional result was False 2026-02-03 08:19:59.197074 | 2026-02-03 08:19:59.197183 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-03 08:19:59.219781 | 2026-02-03 08:19:59.219997 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-03 08:19:59.244528 | controller | skipping: Conditional result was False 2026-02-03 08:19:59.254786 | 2026-02-03 08:19:59.254950 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-03 08:19:59.271367 | controller | skipping: Conditional result was False 2026-02-03 08:19:59.281392 | 2026-02-03 08:19:59.281568 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-03 08:19:59.296545 | controller | skipping: Conditional result was False 2026-02-03 08:19:59.334615 | 2026-02-03 08:19:59.334751 | PLAY RECAP 2026-02-03 08:19:59.334811 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-03 08:19:59.334840 | 2026-02-03 08:19:59.447242 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-03 08:19:59.448355 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2026-02-03 08:20:00.048358 | 2026-02-03 08:20:00.048496 | PLAY [all] 2026-02-03 08:20:00.067217 | 2026-02-03 08:20:00.067352 | TASK [include_role : fetch-output] 2026-02-03 08:20:00.120143 | controller | ok 2026-02-03 08:20:00.144595 | 2026-02-03 08:20:00.144772 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-03 08:20:00.201253 | controller | skipping: Conditional result was False 2026-02-03 08:20:00.208783 | 2026-02-03 08:20:00.208916 | TASK [fetch-output : Set log path for single node] 2026-02-03 08:20:00.254883 | controller | ok 2026-02-03 08:20:00.265621 | 2026-02-03 08:20:00.265810 | LOOP [fetch-output : Ensure local output dirs] 2026-02-03 08:20:00.709070 | controller -> localhost | ok: "/var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/logs" 2026-02-03 08:20:00.956658 | controller -> localhost | changed: "/var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/artifacts" 2026-02-03 08:20:01.220331 | controller -> localhost | changed: "/var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/docs" 2026-02-03 08:20:01.241705 | 2026-02-03 08:20:01.242240 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-03 08:20:01.961280 | controller | changed: .d..t...... ./ 2026-02-03 08:20:01.961591 | controller | changed: All items complete 2026-02-03 08:20:01.961632 | 2026-02-03 08:20:02.494754 | controller | changed: .d..t...... ./ 2026-02-03 08:20:03.063895 | controller | changed: .d..t...... ./ 2026-02-03 08:20:03.098970 | 2026-02-03 08:20:03.099177 | TASK [include_role : fetch-output-openshift] 2026-02-03 08:20:03.114955 | controller | skipping: Conditional result was False 2026-02-03 08:20:03.123942 | 2026-02-03 08:20:03.124130 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-03 08:20:03.562481 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013086 2026-02-03 08:20:03.851624 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014214 2026-02-03 08:20:03.881231 | 2026-02-03 08:20:03.881355 | PLAY [all] 2026-02-03 08:20:03.896968 | 2026-02-03 08:20:03.897127 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-02-03 08:20:04.389480 | controller | changed 2026-02-03 08:20:04.413333 | 2026-02-03 08:20:04.413522 | PLAY RECAP 2026-02-03 08:20:04.413614 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2026-02-03 08:20:04.413657 | 2026-02-03 08:20:04.569380 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2026-02-03 08:20:04.571011 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2026-02-03 08:20:05.192532 | 2026-02-03 08:20:05.192720 | PLAY [localhost] 2026-02-03 08:20:05.215408 | 2026-02-03 08:20:05.215582 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-03 08:20:05.687137 | localhost | changed 2026-02-03 08:20:05.694637 | 2026-02-03 08:20:05.694750 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-03 08:20:05.726992 | localhost | ok 2026-02-03 08:20:05.739230 | 2026-02-03 08:20:05.739353 | TASK [add-fileserver : Create SSH private key tempfile] 2026-02-03 08:20:06.214238 | localhost | changed 2026-02-03 08:20:06.233140 | 2026-02-03 08:20:06.233367 | TASK [add-fileserver : Create SSH private key from secret] 2026-02-03 08:20:06.945512 | localhost | changed 2026-02-03 08:20:06.957314 | 2026-02-03 08:20:06.957742 | TASK [add-fileserver : Add fileserver ssh key] 2026-02-03 08:20:07.442236 | localhost | Identity added: /var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/tmp/ansible.pieiv26s (/var/lib/zuul/builds/1e667ad72983470d8eb1febc349a1329/work/tmp/ansible.pieiv26s) 2026-02-03 08:20:07.442429 | localhost | ok: Runtime: 0:00:00.014913 2026-02-03 08:20:07.447286 | 2026-02-03 08:20:07.447353 | TASK [add-fileserver : Remove SSH private key from disk] 2026-02-03 08:20:07.768580 | localhost | ok: Runtime: 0:00:00.009716 2026-02-03 08:20:07.777876 | 2026-02-03 08:20:07.778052 | TASK [add-fileserver : Add fileserver to inventory] 2026-02-03 08:20:07.862430 | localhost | changed 2026-02-03 08:20:07.869686 | 2026-02-03 08:20:07.869794 | TASK [add-fileserver : Add fileserver server to known hosts] 2026-02-03 08:20:08.349792 | localhost | changed 2026-02-03 08:20:08.371756 | 2026-02-03 08:20:08.371876 | PLAY [localhost] 2026-02-03 08:20:08.386928 | 2026-02-03 08:20:08.387098 | TASK [Generate bulk log download script] 2026-02-03 08:20:08.406688 | localhost | ok 2026-02-03 08:20:08.419714 | 2026-02-03 08:20:08.419828 | TASK [local-log-download : Check API endpoint is defined] 2026-02-03 08:20:08.459211 | localhost | ok: All assertions passed 2026-02-03 08:20:08.464062 | 2026-02-03 08:20:08.464139 | TASK [local-log-download : Create download script] 2026-02-03 08:20:08.864325 | localhost -> localhost | changed 2026-02-03 08:20:08.873667 | 2026-02-03 08:20:08.873765 | TASK [Register quick-download link] 2026-02-03 08:20:08.894633 | localhost | ok 2026-02-03 08:20:08.945948 | 2026-02-03 08:20:08.946118 | PLAY [logserver.rdoproject.org] 2026-02-03 08:20:08.956582 | 2026-02-03 08:20:08.956675 | TASK [Set zuul-log-path fact] 2026-02-03 08:20:08.973295 | logserver.rdoproject.org | ok 2026-02-03 08:20:08.982346 | 2026-02-03 08:20:08.982410 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-03 08:20:09.009829 | logserver.rdoproject.org | ok 2026-02-03 08:20:09.015752 | 2026-02-03 08:20:09.015831 | TASK [upload-logs : Create log directories] 2026-02-03 08:20:09.816501 | logserver.rdoproject.org | changed 2026-02-03 08:20:09.819902 | 2026-02-03 08:20:09.819980 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-02-03 08:20:10.140475 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006575 2026-02-03 08:20:10.145156 | 2026-02-03 08:20:10.145220 | TASK [upload-logs : Upload logs to log server] 2026-02-03 08:20:10.834759 | logserver.rdoproject.org | Output suppressed because no_log was given 2026-02-03 08:20:10.841554 | 2026-02-03 08:20:10.841688 | LOOP [upload-logs : Compress console log and json output] 2026-02-03 08:20:10.909624 | logserver.rdoproject.org | skipping: Conditional result was False 2026-02-03 08:20:10.935998 | logserver.rdoproject.org | skipping: Conditional result was False 2026-02-03 08:20:10.946546 | 2026-02-03 08:20:10.946664 | LOOP [upload-logs : Upload compressed console log and json output] 2026-02-03 08:20:11.020829 | logserver.rdoproject.org | skipping: Conditional result was False 2026-02-03 08:20:11.021292 | 2026-02-03 08:20:11.023998 | logserver.rdoproject.org | skipping: Conditional result was False 2026-02-03 08:20:11.038327 | 2026-02-03 08:20:11.038483 | LOOP [upload-logs : Upload console log and json output]