2025-10-02 19:52:14.967729 | Job console starting... 2025-10-02 19:52:14.977545 | Updating repositories 2025-10-02 19:52:14.994566 | Preparing job workspace 2025-10-02 19:52:18.415290 | Running Ansible setup... 2025-10-02 19:52:22.778453 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 19:52:23.427817 | 2025-10-02 19:52:23.427938 | PLAY [localhost] 2025-10-02 19:52:23.456097 | 2025-10-02 19:52:23.456217 | TASK [Gathering Facts] 2025-10-02 19:52:25.579182 | localhost | ok 2025-10-02 19:52:25.594365 | 2025-10-02 19:52:25.594522 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 19:52:26.010370 | localhost -> localhost | changed 2025-10-02 19:52:26.019186 | 2025-10-02 19:52:26.019285 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 19:52:27.022444 | localhost -> localhost | changed 2025-10-02 19:52:27.030938 | 2025-10-02 19:52:27.031032 | TASK [Setup log path fact] 2025-10-02 19:52:27.048654 | localhost | ok 2025-10-02 19:52:27.061214 | 2025-10-02 19:52:27.061286 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 19:52:27.088641 | localhost | ok 2025-10-02 19:52:27.097144 | 2025-10-02 19:52:27.097211 | TASK [emit-job-header : Print job information] 2025-10-02 19:52:27.124547 | # Job Information 2025-10-02 19:52:27.124688 | Ansible Version: 2.15.12 2025-10-02 19:52:27.124714 | Job: cifmw-molecule-recognize_ssh_keypair 2025-10-02 19:52:27.124734 | Pipeline: github-check 2025-10-02 19:52:27.124752 | Executor: ze01.softwarefactory-project.io 2025-10-02 19:52:27.124769 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 19:52:27.124788 | Log URL (when completed): https://logserver.rdoproject.org/5ed/rdoproject.org/5ed1c9032492465c9768c615dd5ca1d8/ 2025-10-02 19:52:27.124805 | Event ID: 1aeabe40-9fc9-11f0-9f57-122990aafcb1 2025-10-02 19:52:27.128526 | 2025-10-02 19:52:27.128586 | LOOP [emit-job-header : Print node information] 2025-10-02 19:52:27.223723 | localhost | ok: 2025-10-02 19:52:27.224101 | localhost | # Node Information 2025-10-02 19:52:27.224165 | localhost | Inventory Hostname: controller 2025-10-02 19:52:27.224217 | localhost | Hostname: np0005467264 2025-10-02 19:52:27.224262 | localhost | Username: zuul 2025-10-02 19:52:27.224308 | localhost | Distro: CentOS 9 2025-10-02 19:52:27.224349 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 19:52:27.224389 | localhost | Region: RegionOne 2025-10-02 19:52:27.224428 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 19:52:27.224467 | localhost | Product Name: OpenStack Nova 2025-10-02 19:52:27.224505 | localhost | Interface IP: 38.102.83.146 2025-10-02 19:52:27.259233 | 2025-10-02 19:52:27.259385 | PLAY [all] 2025-10-02 19:52:27.289703 | 2025-10-02 19:52:27.289876 | TASK [Gather network facts] 2025-10-02 19:52:27.827952 | controller | ok 2025-10-02 19:52:27.849296 | 2025-10-02 19:52:27.849405 | TASK [include_role : start-zuul-console] 2025-10-02 19:52:27.877202 | controller | ok 2025-10-02 19:52:27.889759 | 2025-10-02 19:52:27.889862 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 19:52:28.335211 | controller | ok 2025-10-02 19:52:28.355782 | 2025-10-02 19:52:28.355908 | TASK [include_role : add-build-sshkey] 2025-10-02 19:52:28.386194 | controller | ok 2025-10-02 19:52:28.409740 | 2025-10-02 19:52:28.409875 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 19:52:28.679763 | controller -> localhost | ok 2025-10-02 19:52:28.687844 | 2025-10-02 19:52:28.687937 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 19:52:28.717201 | controller | ok 2025-10-02 19:52:28.733003 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 19:52:28.739405 | 2025-10-02 19:52:28.739480 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 19:52:29.469471 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 19:52:29.469676 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/5ed1c9032492465c9768c615dd5ca1d8_id_rsa. 2025-10-02 19:52:29.469708 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/5ed1c9032492465c9768c615dd5ca1d8_id_rsa.pub. 2025-10-02 19:52:29.469731 | controller -> localhost | The key fingerprint is: 2025-10-02 19:52:29.469752 | controller -> localhost | SHA256:TFhtgPEhS2bTqrDSJJfsI/WVkmCK6hwuUgYPcoPPc5M zuul-build-sshkey 2025-10-02 19:52:29.469772 | controller -> localhost | The key's randomart image is: 2025-10-02 19:52:29.469791 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 19:52:29.469810 | controller -> localhost | | B++o | 2025-10-02 19:52:29.469829 | controller -> localhost | | o +.B..o | 2025-10-02 19:52:29.469847 | controller -> localhost | |.= o .ooo. | 2025-10-02 19:52:29.469866 | controller -> localhost | |O X o +o | 2025-10-02 19:52:29.469885 | controller -> localhost | |o# = = S | 2025-10-02 19:52:29.469903 | controller -> localhost | |+.% E | 2025-10-02 19:52:29.469921 | controller -> localhost | |+=.+ . | 2025-10-02 19:52:29.469942 | controller -> localhost | |o+ | 2025-10-02 19:52:29.469960 | controller -> localhost | |o | 2025-10-02 19:52:29.469978 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 19:52:29.470050 | controller -> localhost | ok: Runtime: 0:00:00.305947 2025-10-02 19:52:29.475794 | 2025-10-02 19:52:29.475856 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 19:52:29.495533 | controller | ok 2025-10-02 19:52:29.505284 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 19:52:29.513230 | 2025-10-02 19:52:29.513295 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 19:52:29.527413 | controller | skipping: Conditional result was False 2025-10-02 19:52:29.533446 | 2025-10-02 19:52:29.533518 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 19:52:30.051957 | controller | changed 2025-10-02 19:52:30.064689 | 2025-10-02 19:52:30.064852 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 19:52:30.349876 | controller | ok 2025-10-02 19:52:30.354851 | 2025-10-02 19:52:30.354918 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 19:52:31.377955 | controller | changed 2025-10-02 19:52:31.383280 | 2025-10-02 19:52:31.384750 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 19:52:32.467999 | controller | changed 2025-10-02 19:52:32.475645 | 2025-10-02 19:52:32.475753 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 19:52:32.501784 | controller | skipping: Conditional result was False 2025-10-02 19:52:32.510809 | 2025-10-02 19:52:32.510928 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 19:52:32.885012 | controller -> localhost | changed 2025-10-02 19:52:32.899368 | 2025-10-02 19:52:32.899480 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 19:52:33.179008 | controller -> localhost | Identity added: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/5ed1c9032492465c9768c615dd5ca1d8_id_rsa (zuul-build-sshkey) 2025-10-02 19:52:33.179236 | controller -> localhost | ok: Runtime: 0:00:00.015729 2025-10-02 19:52:33.185057 | 2025-10-02 19:52:33.185131 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 19:52:33.583665 | controller | ok 2025-10-02 19:52:33.590565 | 2025-10-02 19:52:33.590652 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 19:52:33.626066 | controller | skipping: Conditional result was False 2025-10-02 19:52:33.639989 | 2025-10-02 19:52:33.640102 | TASK [include_role : validate-host] 2025-10-02 19:52:33.671531 | controller | ok 2025-10-02 19:52:33.698207 | 2025-10-02 19:52:33.698303 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 19:52:33.754913 | controller | ok 2025-10-02 19:52:33.794853 | 2025-10-02 19:52:33.794994 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 19:52:34.128236 | controller -> localhost | ok 2025-10-02 19:52:34.136992 | 2025-10-02 19:52:34.137123 | TASK [validate-host : Collect information about the host] 2025-10-02 19:52:35.005570 | controller | ok 2025-10-02 19:52:35.027617 | 2025-10-02 19:52:35.027811 | TASK [validate-host : Sanitize hostname] 2025-10-02 19:52:35.129617 | controller | ok 2025-10-02 19:52:35.140229 | 2025-10-02 19:52:35.140368 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 19:52:35.671671 | controller -> localhost | changed 2025-10-02 19:52:35.677423 | 2025-10-02 19:52:35.677484 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 19:52:36.138462 | controller | ok 2025-10-02 19:52:36.143987 | 2025-10-02 19:52:36.144082 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 19:52:36.611822 | controller -> localhost | changed 2025-10-02 19:52:36.627431 | 2025-10-02 19:52:36.627521 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 19:52:36.651502 | controller | skipping: Conditional result was False 2025-10-02 19:52:36.656578 | 2025-10-02 19:52:36.656666 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 19:52:36.680344 | controller | skipping: Conditional result was False 2025-10-02 19:52:36.686053 | 2025-10-02 19:52:36.686120 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 19:52:36.960728 | controller | ok: "logs" 2025-10-02 19:52:36.960952 | controller | ok: All items complete 2025-10-02 19:52:36.960978 | 2025-10-02 19:52:37.254333 | controller | ok: "artifacts" 2025-10-02 19:52:37.493786 | controller | ok: "docs" 2025-10-02 19:52:37.506078 | 2025-10-02 19:52:37.506306 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 19:52:37.843610 | controller | changed: "logs" 2025-10-02 19:52:38.101688 | controller | changed: "artifacts" 2025-10-02 19:52:38.389531 | controller | changed: "docs" 2025-10-02 19:52:38.444138 | 2025-10-02 19:52:38.444264 | PLAY RECAP 2025-10-02 19:52:38.444313 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 19:52:38.444341 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 19:52:38.444360 | 2025-10-02 19:52:38.555535 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 19:52:38.556753 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 19:52:39.254358 | 2025-10-02 19:52:39.254460 | PLAY [localhost] 2025-10-02 19:52:39.270588 | 2025-10-02 19:52:39.270664 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 19:52:39.637524 | localhost | ok 2025-10-02 19:52:39.644109 | 2025-10-02 19:52:39.644184 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 19:52:40.303175 | localhost | changed 2025-10-02 19:52:40.326996 | 2025-10-02 19:52:40.327122 | PLAY [all] 2025-10-02 19:52:40.342312 | 2025-10-02 19:52:40.342372 | TASK [include_role : prepare-workspace] 2025-10-02 19:52:40.360729 | controller | ok 2025-10-02 19:52:40.375217 | 2025-10-02 19:52:40.375293 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 19:52:40.851430 | controller | ok 2025-10-02 19:52:40.858942 | 2025-10-02 19:52:40.859051 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 19:52:42.641691 | controller | Output suppressed because no_log was given 2025-10-02 19:52:42.651385 | 2025-10-02 19:52:42.651457 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 19:52:42.946843 | controller | changed: "logs" 2025-10-02 19:52:43.217949 | controller | changed: "artifacts" 2025-10-02 19:52:43.471125 | controller | changed: "docs" 2025-10-02 19:52:43.485756 | 2025-10-02 19:52:43.485880 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 19:52:43.771167 | controller | changed: "logs" 2025-10-02 19:52:43.771373 | controller | changed: All items complete 2025-10-02 19:52:43.771400 | 2025-10-02 19:52:43.995288 | controller | changed: "artifacts" 2025-10-02 19:52:44.256937 | controller | changed: "docs" 2025-10-02 19:52:44.279610 | 2025-10-02 19:52:44.279730 | TASK [Check if worker can sudo] 2025-10-02 19:52:45.339353 | controller | ok: Runtime: 0:00:00.063983 2025-10-02 19:52:45.344959 | 2025-10-02 19:52:45.345041 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 19:52:45.423411 | controller | skipping: Conditional result was False 2025-10-02 19:52:45.429360 | 2025-10-02 19:52:45.429429 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 19:52:45.519187 | controller | ok 2025-10-02 19:52:45.526710 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 19:52:45.535587 | 2025-10-02 19:52:45.535717 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 19:52:45.877430 | controller | ok 2025-10-02 19:52:45.894993 | 2025-10-02 19:52:45.895140 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 19:52:45.966406 | controller | ok: "/var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 19:52:45.977558 | 2025-10-02 19:52:45.977678 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 19:52:47.033670 | controller | changed 2025-10-02 19:52:47.039091 | 2025-10-02 19:52:47.039154 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 19:52:47.087172 | controller | ok: "/var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 19:52:47.087374 | controller | ok: All items complete 2025-10-02 19:52:47.087401 | 2025-10-02 19:52:47.147257 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 19:52:47.155351 | 2025-10-02 19:52:47.155486 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 19:52:48.241652 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 19:52:49.209970 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 19:52:49.225599 | 2025-10-02 19:52:49.225827 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 19:52:49.777139 | controller | changed: section and option added 2025-10-02 19:52:49.809125 | 2025-10-02 19:52:49.809231 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 19:52:50.824087 | controller | 29 files removed 2025-10-02 19:52:50.824452 | controller | ok: Item: dnf clean all Runtime: 0:00:00.615473 2025-10-02 19:52:50.824519 | controller | changed: All items complete 2025-10-02 19:52:50.824551 | 2025-10-02 19:53:01.333766 | 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 19:53:01.333875 | controller | DNF version: 4.14.0 2025-10-02 19:53:01.333899 | controller | cachedir: /var/cache/dnf 2025-10-02 19:53:01.333919 | controller | Making cache files for all metadata files. 2025-10-02 19:53:01.333936 | controller | baseos: has expired and will be refreshed. 2025-10-02 19:53:01.333953 | controller | appstream: has expired and will be refreshed. 2025-10-02 19:53:01.333969 | controller | crb: has expired and will be refreshed. 2025-10-02 19:53:01.333994 | controller | extras-common: has expired and will be refreshed. 2025-10-02 19:53:01.334011 | controller | repo: downloading from remote: baseos 2025-10-02 19:53:01.334049 | controller | CentOS Stream 9 - BaseOS 75 MB/s | 8.8 MB 00:00 2025-10-02 19:53:01.334066 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 19:53:01.334082 | controller | repo: downloading from remote: appstream 2025-10-02 19:53:01.334097 | controller | CentOS Stream 9 - AppStream 88 MB/s | 25 MB 00:00 2025-10-02 19:53:01.334113 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 19:53:01.334128 | controller | repo: downloading from remote: crb 2025-10-02 19:53:01.334144 | controller | CentOS Stream 9 - CRB 84 MB/s | 7.1 MB 00:00 2025-10-02 19:53:01.334159 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 19:53:01.334175 | controller | repo: downloading from remote: extras-common 2025-10-02 19:53:01.334192 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-02 19:53:01.334207 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 19:53:01.334222 | controller | Last metadata expiration check: 0:00:01 ago on Thu 02 Oct 2025 03:52:59 PM EDT. 2025-10-02 19:53:01.334237 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 19:53:01.334253 | controller | Completion plugin: Generating completion cache... 2025-10-02 19:53:01.334269 | controller | Metadata cache created. 2025-10-02 19:53:01.334292 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.249043 2025-10-02 19:53:01.366292 | 2025-10-02 19:53:01.366527 | PLAY RECAP 2025-10-02 19:53:01.366647 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 19:53:01.366730 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 19:53:01.366785 | 2025-10-02 19:53:01.521525 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 19:53:01.522456 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 19:53:02.162419 | 2025-10-02 19:53:02.162567 | PLAY [all] 2025-10-02 19:53:02.187588 | 2025-10-02 19:53:02.187746 | TASK [Install binary dependencies] 2025-10-02 19:53:02.268249 | controller | ok 2025-10-02 19:53:02.287970 | 2025-10-02 19:53:02.288143 | TASK [bindep : Include find tasks] 2025-10-02 19:53:02.329384 | controller | ok 2025-10-02 19:53:02.336961 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 19:53:02.342940 | 2025-10-02 19:53:02.343060 | TASK [bindep : Look for bindep.txt] 2025-10-02 19:53:02.825588 | controller | ok 2025-10-02 19:53:02.837141 | 2025-10-02 19:53:02.837371 | TASK [bindep : Define bindep_file fact] 2025-10-02 19:53:02.871518 | controller | ok 2025-10-02 19:53:02.878546 | 2025-10-02 19:53:02.878715 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 19:53:02.906164 | controller | skipping: Conditional result was False 2025-10-02 19:53:02.915361 | 2025-10-02 19:53:02.915437 | TASK [bindep : Define bindep_file fact] 2025-10-02 19:53:02.940567 | controller | skipping: Conditional result was False 2025-10-02 19:53:02.948674 | 2025-10-02 19:53:02.948746 | TASK [bindep : Look for bindep fallback file] 2025-10-02 19:53:02.972806 | controller | skipping: Conditional result was False 2025-10-02 19:53:02.981244 | 2025-10-02 19:53:02.981316 | TASK [bindep : Define bindep_file fact] 2025-10-02 19:53:03.026220 | controller | skipping: Conditional result was False 2025-10-02 19:53:03.035104 | 2025-10-02 19:53:03.035195 | TASK [bindep : Include bindep tasks] 2025-10-02 19:53:03.070369 | controller | ok 2025-10-02 19:53:03.077668 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 19:53:03.085845 | 2025-10-02 19:53:03.085912 | TASK [bindep : Look for bindep command] 2025-10-02 19:53:03.109215 | controller | skipping: Conditional result was False 2025-10-02 19:53:03.115754 | 2025-10-02 19:53:03.115822 | TASK [bindep : Check for system bindep] 2025-10-02 19:53:03.648234 | controller | ok: Runtime: 0:00:00.009307 2025-10-02 19:53:03.654634 | 2025-10-02 19:53:03.654710 | TASK [bindep : Define bindep_command fact] 2025-10-02 19:53:03.682337 | controller | skipping: Conditional result was False 2025-10-02 19:53:03.688738 | 2025-10-02 19:53:03.688811 | TASK [bindep : Include install tasks] 2025-10-02 19:53:03.729453 | controller | ok 2025-10-02 19:53:03.741191 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 19:53:03.750626 | 2025-10-02 19:53:03.750687 | TASK [bindep : Create temp dir for bindep] 2025-10-02 19:53:04.185063 | controller | changed 2025-10-02 19:53:04.190921 | 2025-10-02 19:53:04.190993 | TASK [Ensure we have pip dependencies] 2025-10-02 19:53:04.211030 | controller | ok 2025-10-02 19:53:04.236903 | 2025-10-02 19:53:04.237112 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 15:53:04.536975 | controller | /usr/bin/pip3 2025-10-02 15:53:04.574451 | controller | /usr/bin/python3: No module named wheel 2025-10-02 19:53:04.776992 | controller | ok: Runtime: 0:00:00.050399 2025-10-02 19:53:04.783670 | 2025-10-02 19:53:04.783733 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 19:53:04.808219 | controller | ok: "/var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 19:53:04.825794 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 19:53:04.836178 | 2025-10-02 19:53:04.836279 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 19:53:07.443101 | controller | changed 2025-10-02 19:53:07.449431 | 2025-10-02 19:53:07.449624 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 19:53:07.483600 | controller | skipping: Conditional result was False 2025-10-02 19:53:07.490546 | 2025-10-02 19:53:07.490628 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 19:53:07.557160 | controller | skipping: Conditional result was False 2025-10-02 19:53:07.563905 | 2025-10-02 19:53:07.563980 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 19:53:07.649500 | controller | skipping: Conditional result was False 2025-10-02 19:53:07.655898 | 2025-10-02 19:53:07.655980 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 19:53:07.675887 | controller | skipping: Conditional result was False 2025-10-02 19:53:07.682828 | 2025-10-02 19:53:07.682911 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 19:53:08.214620 | controller | skipping: Conditional result was False 2025-10-02 19:53:08.220622 | 2025-10-02 19:53:08.220704 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 19:53:08.245078 | controller | skipping: Conditional result was False 2025-10-02 19:53:08.251043 | 2025-10-02 19:53:08.251116 | TASK [ensure-pip : Install pip from source] 2025-10-02 19:53:08.275771 | controller | skipping: Conditional result was False 2025-10-02 19:53:08.283873 | 2025-10-02 19:53:08.284154 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 15:53:08.583395 | controller | /usr/bin/python3 2025-10-02 19:53:08.826844 | controller | ok: Runtime: 0:00:00.007145 2025-10-02 19:53:08.836456 | 2025-10-02 19:53:08.836707 | TASK [ensure-pip : Set host default] 2025-10-02 19:53:08.915142 | controller | ok 2025-10-02 19:53:08.922082 | 2025-10-02 19:53:08.922241 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 19:53:08.983228 | controller | ok 2025-10-02 19:53:09.006173 | 2025-10-02 19:53:09.006371 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 19:53:13.429436 | controller | changed 2025-10-02 19:53:13.437341 | 2025-10-02 19:53:13.437499 | TASK [bindep : Define bindep_command] 2025-10-02 19:53:13.460565 | controller | ok 2025-10-02 19:53:13.468508 | 2025-10-02 19:53:13.468800 | LOOP [bindep : Include package tasks] 2025-10-02 19:53:13.511423 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 19:53:13.511579 | controller | ok: All items complete 2025-10-02 19:53:13.511612 | 2025-10-02 19:53:13.522811 | controller | included: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 19:53:13.534156 | 2025-10-02 19:53:13.534223 | TASK [bindep : Define bindep_run fact] 2025-10-02 19:53:13.562916 | controller | ok 2025-10-02 19:53:13.568090 | 2025-10-02 19:53:13.568156 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 15:53:15.053581 | controller | podman 2025-10-02 15:53:15.101461 | controller | python3-jmespath 2025-10-02 15:53:15.101582 | controller | python3-libvirt 2025-10-02 15:53:15.101600 | controller | python3-lxml 2025-10-02 15:53:15.101621 | controller | python3-netaddr 2025-10-02 19:53:15.604155 | controller | ok: Runtime: 0:00:01.287890 2025-10-02 19:53:15.612178 | 2025-10-02 19:53:15.612282 | TASK [bindep : Install distro packages from bindep] 2025-10-02 19:54:21.276274 | controller | changed 2025-10-02 19:54:21.286613 | 2025-10-02 19:54:21.286749 | TASK [bindep : Check that packages are installed] 2025-10-02 19:54:23.329495 | controller | ok: Runtime: 0:00:01.264312 2025-10-02 19:54:23.341289 | 2025-10-02 19:54:23.341462 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 19:54:23.378427 | controller | skipping: Conditional result was False 2025-10-02 19:54:23.401195 | 2025-10-02 19:54:23.401382 | TASK [Run test-setup role] 2025-10-02 19:54:23.430368 | controller | ok 2025-10-02 19:54:23.460350 | 2025-10-02 19:54:23.460499 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 19:54:23.761776 | controller | ok 2025-10-02 19:54:23.775186 | 2025-10-02 19:54:23.775462 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 19:54:24.322303 | controller | skipping: Conditional result was False 2025-10-02 19:54:24.351515 | 2025-10-02 19:54:24.351679 | TASK [bindep : Remove bindep temp dir] 2025-10-02 19:54:24.758497 | controller | ok 2025-10-02 19:54:24.768815 | 2025-10-02 19:54:24.768870 | PLAY RECAP 2025-10-02 19:54:24.768910 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 19:54:24.768930 | 2025-10-02 19:54:24.865921 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 19:54:24.867625 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 19:54:25.431725 | 2025-10-02 19:54:25.431828 | PLAY [all] 2025-10-02 19:54:25.450544 | 2025-10-02 19:54:25.450614 | TASK [Abort when test_command variable is undefined] 2025-10-02 19:54:25.484574 | controller | skipping: Conditional result was False 2025-10-02 19:54:25.489925 | 2025-10-02 19:54:25.489995 | TASK [Convert test_command to list] 2025-10-02 19:54:25.544663 | controller | skipping: Conditional result was False 2025-10-02 19:54:25.559309 | 2025-10-02 19:54:25.559452 | TASK [Use test_command list] 2025-10-02 19:54:25.626095 | controller | ok 2025-10-02 19:54:25.639370 | 2025-10-02 19:54:25.639458 | LOOP [Run test_command] 2025-10-02 19:54:26.116466 | controller | no check to run 2025-10-02 19:54:26.116744 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006739 2025-10-02 19:54:26.143487 | 2025-10-02 19:54:26.143607 | PLAY RECAP 2025-10-02 19:54:26.143653 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 19:54:26.143731 | 2025-10-02 19:54:26.233331 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 19:54:26.235000 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 19:54:26.905300 | 2025-10-02 19:54:26.905404 | PLAY [all] 2025-10-02 19:54:26.929711 | 2025-10-02 19:54:26.929825 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 19:54:27.352979 | controller | changed: non-zero return code 2025-10-02 19:54:27.364844 | 2025-10-02 19:54:27.365005 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 19:54:27.392327 | controller | skipping: Conditional result was False 2025-10-02 19:54:27.403923 | 2025-10-02 19:54:27.404113 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 19:54:27.443277 | 2025-10-02 19:54:27.443543 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 19:54:27.473146 | 2025-10-02 19:54:27.473402 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 19:54:27.489523 | controller | skipping: Conditional result was False 2025-10-02 19:54:27.501866 | 2025-10-02 19:54:27.502049 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 19:54:27.532877 | 2025-10-02 19:54:27.533166 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 19:54:27.559660 | controller | skipping: Conditional result was False 2025-10-02 19:54:27.572559 | 2025-10-02 19:54:27.572696 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 19:54:27.599989 | controller | skipping: Conditional result was False 2025-10-02 19:54:27.611969 | 2025-10-02 19:54:27.612137 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 19:54:27.629325 | controller | skipping: Conditional result was False 2025-10-02 19:54:27.670235 | 2025-10-02 19:54:27.670322 | PLAY RECAP 2025-10-02 19:54:27.670382 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 19:54:27.670418 | 2025-10-02 19:54:27.768110 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 19:54:27.768899 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 19:54:28.446193 | 2025-10-02 19:54:28.446300 | PLAY [all] 2025-10-02 19:54:28.469996 | 2025-10-02 19:54:28.470086 | TASK [include_role : fetch-output] 2025-10-02 19:54:28.508794 | controller | ok 2025-10-02 19:54:28.526728 | 2025-10-02 19:54:28.526811 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 19:54:28.570563 | controller | skipping: Conditional result was False 2025-10-02 19:54:28.576118 | 2025-10-02 19:54:28.576186 | TASK [fetch-output : Set log path for single node] 2025-10-02 19:54:28.603856 | controller | ok 2025-10-02 19:54:28.608728 | 2025-10-02 19:54:28.608794 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 19:54:28.982501 | controller -> localhost | ok: "/var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/logs" 2025-10-02 19:54:29.216230 | controller -> localhost | changed: "/var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/artifacts" 2025-10-02 19:54:29.411296 | controller -> localhost | changed: "/var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/docs" 2025-10-02 19:54:29.430287 | 2025-10-02 19:54:29.430471 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 19:54:30.073615 | controller | changed: .d..t...... ./ 2025-10-02 19:54:30.073843 | controller | changed: All items complete 2025-10-02 19:54:30.073881 | 2025-10-02 19:54:30.543730 | controller | changed: .d..t...... ./ 2025-10-02 19:54:31.087036 | controller | changed: .d..t...... ./ 2025-10-02 19:54:31.118559 | 2025-10-02 19:54:31.118742 | TASK [include_role : fetch-output-openshift] 2025-10-02 19:54:31.135284 | controller | skipping: Conditional result was False 2025-10-02 19:54:31.145007 | 2025-10-02 19:54:31.145175 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 19:54:31.581674 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007815 2025-10-02 19:54:31.844997 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009729 2025-10-02 19:54:31.873918 | 2025-10-02 19:54:31.874042 | PLAY [all] 2025-10-02 19:54:31.888764 | 2025-10-02 19:54:31.888880 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 19:54:32.347391 | controller | changed 2025-10-02 19:54:32.375905 | 2025-10-02 19:54:32.375975 | PLAY RECAP 2025-10-02 19:54:32.376048 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 19:54:32.376083 | 2025-10-02 19:54:32.467312 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 19:54:32.468144 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 19:54:33.130893 | 2025-10-02 19:54:33.131107 | PLAY [localhost] 2025-10-02 19:54:33.148497 | 2025-10-02 19:54:33.148575 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 19:54:33.519782 | localhost | changed 2025-10-02 19:54:33.528325 | 2025-10-02 19:54:33.528450 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 19:54:33.550828 | localhost | ok 2025-10-02 19:54:33.562163 | 2025-10-02 19:54:33.562252 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 19:54:33.936870 | localhost | changed 2025-10-02 19:54:33.941855 | 2025-10-02 19:54:33.941922 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 19:54:34.545267 | localhost | changed 2025-10-02 19:54:34.550396 | 2025-10-02 19:54:34.550457 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 19:54:34.946273 | localhost | Identity added: /var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/tmp/ansible.io02iwn6 (/var/lib/zuul/builds/5ed1c9032492465c9768c615dd5ca1d8/work/tmp/ansible.io02iwn6) 2025-10-02 19:54:34.946452 | localhost | ok: Runtime: 0:00:00.007462 2025-10-02 19:54:34.954252 | 2025-10-02 19:54:34.954317 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 19:54:35.205662 | localhost | ok: Runtime: 0:00:00.022364 2025-10-02 19:54:35.210785 | 2025-10-02 19:54:35.210852 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 19:54:35.259351 | localhost | changed 2025-10-02 19:54:35.264303 | 2025-10-02 19:54:35.264367 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 19:54:35.626749 | localhost | changed 2025-10-02 19:54:35.647833 | 2025-10-02 19:54:35.647893 | PLAY [localhost] 2025-10-02 19:54:35.659790 | 2025-10-02 19:54:35.659847 | TASK [Generate bulk log download script] 2025-10-02 19:54:35.678003 | localhost | ok 2025-10-02 19:54:35.695968 | 2025-10-02 19:54:35.696120 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 19:54:35.734992 | localhost | ok: All assertions passed 2025-10-02 19:54:35.745260 | 2025-10-02 19:54:35.745345 | TASK [local-log-download : Create download script] 2025-10-02 19:54:36.148630 | localhost -> localhost | changed 2025-10-02 19:54:36.169745 | 2025-10-02 19:54:36.169839 | TASK [Register quick-download link] 2025-10-02 19:54:36.191705 | localhost | ok 2025-10-02 19:54:36.234826 | 2025-10-02 19:54:36.234929 | PLAY [logserver.rdoproject.org] 2025-10-02 19:54:36.244225 | 2025-10-02 19:54:36.244283 | TASK [Set zuul-log-path fact] 2025-10-02 19:54:36.281614 | logserver.rdoproject.org | ok 2025-10-02 19:54:36.294840 | 2025-10-02 19:54:36.294928 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 19:54:36.322959 | logserver.rdoproject.org | ok 2025-10-02 19:54:36.328943 | 2025-10-02 19:54:36.329042 | TASK [upload-logs : Create log directories] 2025-10-02 19:54:36.984563 | logserver.rdoproject.org | changed 2025-10-02 19:54:37.001989 | 2025-10-02 19:54:37.002155 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 19:54:37.281613 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008406 2025-10-02 19:54:37.286373 | 2025-10-02 19:54:37.286441 | TASK [upload-logs : Upload logs to log server] 2025-10-02 19:54:37.969547 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 19:54:37.972597 | 2025-10-02 19:54:37.972660 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 19:54:38.029093 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:54:38.031520 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:54:38.043544 | 2025-10-02 19:54:38.043676 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 19:54:38.086004 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:54:38.086265 | 2025-10-02 19:54:38.089344 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:54:38.096173 | 2025-10-02 19:54:38.096306 | LOOP [upload-logs : Upload console log and json output]