2025-10-02 14:13:04.818931 | Job console starting... 2025-10-02 14:13:04.840660 | Updating repositories 2025-10-02 14:13:04.870898 | Preparing job workspace 2025-10-02 14:13:09.285029 | Running Ansible setup... 2025-10-02 14:13:15.161877 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 14:13:15.854785 | 2025-10-02 14:13:15.854884 | PLAY [localhost] 2025-10-02 14:13:15.863045 | 2025-10-02 14:13:15.863111 | TASK [Gathering Facts] 2025-10-02 14:13:17.256788 | localhost | ok 2025-10-02 14:13:17.273200 | 2025-10-02 14:13:17.273288 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 14:13:17.940207 | localhost -> localhost | changed 2025-10-02 14:13:17.945693 | 2025-10-02 14:13:17.945761 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 14:13:20.175435 | localhost -> localhost | changed 2025-10-02 14:13:20.186467 | 2025-10-02 14:13:20.186558 | TASK [Setup log path fact] 2025-10-02 14:13:20.223885 | localhost | ok 2025-10-02 14:13:20.247554 | 2025-10-02 14:13:20.247673 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 14:13:20.301580 | localhost | ok 2025-10-02 14:13:20.310744 | 2025-10-02 14:13:20.310823 | TASK [emit-job-header : Print job information] 2025-10-02 14:13:20.339886 | # Job Information 2025-10-02 14:13:20.340112 | Ansible Version: 2.15.12 2025-10-02 14:13:20.340176 | Job: cifmw-molecule-recognize_ssh_keypair 2025-10-02 14:13:20.340204 | Pipeline: github-check 2025-10-02 14:13:20.340229 | Executor: ze04.softwarefactory-project.io 2025-10-02 14:13:20.340254 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 14:13:20.340276 | Log URL (when completed): https://logserver.rdoproject.org/aff/rdoproject.org/affbc449b43542e686a680b9d943834f/ 2025-10-02 14:13:20.340295 | Event ID: be9565c0-9f99-11f0-9e8d-1085adf9bc04 2025-10-02 14:13:20.344879 | 2025-10-02 14:13:20.344958 | LOOP [emit-job-header : Print node information] 2025-10-02 14:13:20.564354 | localhost | ok: 2025-10-02 14:13:20.564550 | localhost | # Node Information 2025-10-02 14:13:20.564578 | localhost | Inventory Hostname: controller 2025-10-02 14:13:20.564600 | localhost | Hostname: np0005466334 2025-10-02 14:13:20.564620 | localhost | Username: zuul 2025-10-02 14:13:20.564640 | localhost | Distro: CentOS 9 2025-10-02 14:13:20.564658 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 14:13:20.564702 | localhost | Region: RegionOne 2025-10-02 14:13:20.564725 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 14:13:20.564742 | localhost | Product Name: OpenStack Nova 2025-10-02 14:13:20.564759 | localhost | Interface IP: 38.102.83.182 2025-10-02 14:13:20.599806 | 2025-10-02 14:13:20.599905 | PLAY [all] 2025-10-02 14:13:20.609882 | 2025-10-02 14:13:20.609955 | TASK [Gather network facts] 2025-10-02 14:13:21.083654 | controller | ok 2025-10-02 14:13:21.099106 | 2025-10-02 14:13:21.099165 | TASK [include_role : start-zuul-console] 2025-10-02 14:13:21.117910 | controller | ok 2025-10-02 14:13:21.131592 | 2025-10-02 14:13:21.131672 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 14:13:21.572867 | controller | ok 2025-10-02 14:13:21.582517 | 2025-10-02 14:13:21.582585 | TASK [include_role : add-build-sshkey] 2025-10-02 14:13:21.613511 | controller | ok 2025-10-02 14:13:21.626399 | 2025-10-02 14:13:21.626461 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 14:13:21.854651 | controller -> localhost | ok 2025-10-02 14:13:21.861148 | 2025-10-02 14:13:21.861210 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 14:13:21.893035 | controller | ok 2025-10-02 14:13:21.906062 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 14:13:21.911605 | 2025-10-02 14:13:21.911663 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 14:13:23.062859 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 14:13:23.063057 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/affbc449b43542e686a680b9d943834f_id_rsa. 2025-10-02 14:13:23.063086 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/affbc449b43542e686a680b9d943834f_id_rsa.pub. 2025-10-02 14:13:23.063108 | controller -> localhost | The key fingerprint is: 2025-10-02 14:13:23.063126 | controller -> localhost | SHA256:4SZJJH3R2Aa17yCbfy+xmbNTz7NbxmklptVqeTecmmI zuul-build-sshkey 2025-10-02 14:13:23.063145 | controller -> localhost | The key's randomart image is: 2025-10-02 14:13:23.063163 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 14:13:23.063180 | controller -> localhost | | ... oB. | 2025-10-02 14:13:23.063198 | controller -> localhost | | o. o +. | 2025-10-02 14:13:23.063215 | controller -> localhost | | ..... | 2025-10-02 14:13:23.063233 | controller -> localhost | | . o . . . | 2025-10-02 14:13:23.063251 | controller -> localhost | | o S . . + o| 2025-10-02 14:13:23.063268 | controller -> localhost | | o + o.+o=+| 2025-10-02 14:13:23.063285 | controller -> localhost | | o o*+O*| 2025-10-02 14:13:23.063301 | controller -> localhost | | . EO.++*| 2025-10-02 14:13:23.063318 | controller -> localhost | | o.oO.o+| 2025-10-02 14:13:23.063335 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 14:13:23.063396 | controller -> localhost | ok: Runtime: 0:00:00.684594 2025-10-02 14:13:23.069213 | 2025-10-02 14:13:23.069284 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 14:13:23.112411 | controller | ok 2025-10-02 14:13:23.123389 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 14:13:23.132116 | 2025-10-02 14:13:23.132237 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 14:13:23.157051 | controller | skipping: Conditional result was False 2025-10-02 14:13:23.162707 | 2025-10-02 14:13:23.162773 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 14:13:24.073880 | controller | changed 2025-10-02 14:13:24.085225 | 2025-10-02 14:13:24.085330 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 14:13:24.390845 | controller | ok 2025-10-02 14:13:24.396041 | 2025-10-02 14:13:24.396110 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 14:13:25.613146 | controller | changed 2025-10-02 14:13:25.622609 | 2025-10-02 14:13:25.622725 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 14:13:26.707006 | controller | changed 2025-10-02 14:13:26.719402 | 2025-10-02 14:13:26.719765 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 14:13:26.776538 | controller | skipping: Conditional result was False 2025-10-02 14:13:26.782608 | 2025-10-02 14:13:26.782689 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 14:13:27.147991 | controller -> localhost | changed 2025-10-02 14:13:27.159435 | 2025-10-02 14:13:27.159625 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 14:13:27.453062 | controller -> localhost | Identity added: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/affbc449b43542e686a680b9d943834f_id_rsa (zuul-build-sshkey) 2025-10-02 14:13:27.453265 | controller -> localhost | ok: Runtime: 0:00:00.016378 2025-10-02 14:13:27.473620 | 2025-10-02 14:13:27.474498 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 14:13:28.366923 | controller | ok 2025-10-02 14:13:28.381608 | 2025-10-02 14:13:28.381739 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 14:13:28.406029 | controller | skipping: Conditional result was False 2025-10-02 14:13:28.442750 | 2025-10-02 14:13:28.442851 | TASK [include_role : validate-host] 2025-10-02 14:13:28.462010 | controller | ok 2025-10-02 14:13:28.484895 | 2025-10-02 14:13:28.485018 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 14:13:28.516654 | controller | ok 2025-10-02 14:13:28.522254 | 2025-10-02 14:13:28.522322 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 14:13:28.825091 | controller -> localhost | ok 2025-10-02 14:13:28.835554 | 2025-10-02 14:13:28.835695 | TASK [validate-host : Collect information about the host] 2025-10-02 14:13:29.654830 | controller | ok 2025-10-02 14:13:29.667256 | 2025-10-02 14:13:29.667321 | TASK [validate-host : Sanitize hostname] 2025-10-02 14:13:29.746544 | controller | ok 2025-10-02 14:13:29.751724 | 2025-10-02 14:13:29.751787 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 14:13:30.288162 | controller -> localhost | changed 2025-10-02 14:13:30.294155 | 2025-10-02 14:13:30.294223 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 14:13:30.774359 | controller | ok 2025-10-02 14:13:30.780040 | 2025-10-02 14:13:30.780108 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 14:13:31.626061 | controller -> localhost | changed 2025-10-02 14:13:31.637128 | 2025-10-02 14:13:31.637220 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 14:13:31.692861 | controller | skipping: Conditional result was False 2025-10-02 14:13:31.698385 | 2025-10-02 14:13:31.698446 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 14:13:31.736170 | controller | skipping: Conditional result was False 2025-10-02 14:13:31.741869 | 2025-10-02 14:13:31.741934 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 14:13:32.034183 | controller | ok: "logs" 2025-10-02 14:13:32.034413 | controller | ok: All items complete 2025-10-02 14:13:32.034440 | 2025-10-02 14:13:32.248030 | controller | ok: "artifacts" 2025-10-02 14:13:32.484248 | controller | ok: "docs" 2025-10-02 14:13:32.494422 | 2025-10-02 14:13:32.494527 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 14:13:32.782608 | controller | changed: "logs" 2025-10-02 14:13:33.014529 | controller | changed: "artifacts" 2025-10-02 14:13:33.248261 | controller | changed: "docs" 2025-10-02 14:13:33.283608 | 2025-10-02 14:13:33.283737 | PLAY RECAP 2025-10-02 14:13:33.283781 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 14:13:33.283806 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 14:13:33.283824 | 2025-10-02 14:13:33.389288 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 14:13:33.392184 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 14:13:34.065847 | 2025-10-02 14:13:34.065964 | PLAY [localhost] 2025-10-02 14:13:34.082103 | 2025-10-02 14:13:34.082181 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 14:13:34.537945 | localhost | ok 2025-10-02 14:13:34.544843 | 2025-10-02 14:13:34.544943 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 14:13:35.400263 | localhost | changed 2025-10-02 14:13:35.444511 | 2025-10-02 14:13:35.444621 | PLAY [all] 2025-10-02 14:13:35.463740 | 2025-10-02 14:13:35.463834 | TASK [include_role : prepare-workspace] 2025-10-02 14:13:35.493741 | controller | ok 2025-10-02 14:13:35.508705 | 2025-10-02 14:13:35.508795 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 14:13:35.922790 | controller | ok 2025-10-02 14:13:35.932188 | 2025-10-02 14:13:35.932341 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 14:13:38.267277 | controller | Output suppressed because no_log was given 2025-10-02 14:13:38.287174 | 2025-10-02 14:13:38.287357 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 14:13:38.622929 | controller | changed: "logs" 2025-10-02 14:13:38.823193 | controller | changed: "artifacts" 2025-10-02 14:13:39.036958 | controller | changed: "docs" 2025-10-02 14:13:39.048611 | 2025-10-02 14:13:39.048951 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 14:13:39.363426 | controller | changed: "logs" 2025-10-02 14:13:39.363647 | controller | changed: All items complete 2025-10-02 14:13:39.363674 | 2025-10-02 14:13:39.570111 | controller | changed: "artifacts" 2025-10-02 14:13:39.797212 | controller | changed: "docs" 2025-10-02 14:13:39.820850 | 2025-10-02 14:13:39.820952 | TASK [Check if worker can sudo] 2025-10-02 14:13:40.888728 | controller | ok: Runtime: 0:00:00.130474 2025-10-02 14:13:40.897167 | 2025-10-02 14:13:40.897290 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 14:13:40.968740 | controller | skipping: Conditional result was False 2025-10-02 14:13:40.974542 | 2025-10-02 14:13:40.974610 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 14:13:41.172784 | controller | ok 2025-10-02 14:13:41.260385 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 14:13:41.278168 | 2025-10-02 14:13:41.278278 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 14:13:41.627156 | controller | ok 2025-10-02 14:13:41.634185 | 2025-10-02 14:13:41.634265 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 14:13:41.756988 | controller | ok: "/var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 14:13:41.771272 | 2025-10-02 14:13:41.771367 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 14:13:42.749444 | controller | changed 2025-10-02 14:13:42.755395 | 2025-10-02 14:13:42.755463 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 14:13:42.870703 | controller | ok: "/var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 14:13:42.870977 | controller | ok: All items complete 2025-10-02 14:13:42.871014 | 2025-10-02 14:13:42.939808 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 14:13:42.954352 | 2025-10-02 14:13:42.954433 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 14:13:43.977887 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 14:13:45.017903 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 14:13:45.033909 | 2025-10-02 14:13:45.034015 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 14:13:45.624197 | controller | changed: section and option added 2025-10-02 14:13:45.662702 | 2025-10-02 14:13:45.662828 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 14:13:46.679261 | controller | 29 files removed 2025-10-02 14:13:46.679479 | controller | ok: Item: dnf clean all Runtime: 0:00:00.572827 2025-10-02 14:13:46.679520 | controller | changed: All items complete 2025-10-02 14:13:46.679541 | 2025-10-02 14:13:57.268454 | 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 14:13:57.268658 | controller | DNF version: 4.14.0 2025-10-02 14:13:57.268728 | controller | cachedir: /var/cache/dnf 2025-10-02 14:13:57.268751 | controller | Making cache files for all metadata files. 2025-10-02 14:13:57.268771 | controller | baseos: has expired and will be refreshed. 2025-10-02 14:13:57.268789 | controller | appstream: has expired and will be refreshed. 2025-10-02 14:13:57.268805 | controller | crb: has expired and will be refreshed. 2025-10-02 14:13:57.268829 | controller | extras-common: has expired and will be refreshed. 2025-10-02 14:13:57.268846 | controller | repo: downloading from remote: baseos 2025-10-02 14:13:57.268863 | controller | CentOS Stream 9 - BaseOS 86 MB/s | 8.8 MB 00:00 2025-10-02 14:13:57.268880 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 14:13:57.268897 | controller | repo: downloading from remote: appstream 2025-10-02 14:13:57.268913 | controller | CentOS Stream 9 - AppStream 89 MB/s | 25 MB 00:00 2025-10-02 14:13:57.268929 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 14:13:57.268946 | controller | repo: downloading from remote: crb 2025-10-02 14:13:57.268962 | controller | CentOS Stream 9 - CRB 88 MB/s | 7.1 MB 00:00 2025-10-02 14:13:57.268979 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 14:13:57.268996 | controller | repo: downloading from remote: extras-common 2025-10-02 14:13:57.269012 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-10-02 14:13:57.269029 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 14:13:57.269045 | controller | Last metadata expiration check: 0:00:01 ago on Thu 02 Oct 2025 10:13:55 AM EDT. 2025-10-02 14:13:57.269062 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 14:13:57.269077 | controller | Completion plugin: Generating completion cache... 2025-10-02 14:13:57.269094 | controller | Metadata cache created. 2025-10-02 14:13:57.269119 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.318593 2025-10-02 14:13:57.290890 | 2025-10-02 14:13:57.290995 | PLAY RECAP 2025-10-02 14:13:57.291038 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 14:13:57.291090 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 14:13:57.291249 | 2025-10-02 14:13:57.415753 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 14:13:57.416625 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 14:13:58.122449 | 2025-10-02 14:13:58.122556 | PLAY [all] 2025-10-02 14:13:58.173394 | 2025-10-02 14:13:58.173582 | TASK [Install binary dependencies] 2025-10-02 14:13:58.254614 | controller | ok 2025-10-02 14:13:58.297990 | 2025-10-02 14:13:58.298126 | TASK [bindep : Include find tasks] 2025-10-02 14:13:58.347600 | controller | ok 2025-10-02 14:13:58.355412 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 14:13:58.361242 | 2025-10-02 14:13:58.361309 | TASK [bindep : Look for bindep.txt] 2025-10-02 14:13:58.834851 | controller | ok 2025-10-02 14:13:58.842983 | 2025-10-02 14:13:58.843060 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:58.883908 | controller | ok 2025-10-02 14:13:58.889112 | 2025-10-02 14:13:58.889177 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 14:13:58.903323 | controller | skipping: Conditional result was False 2025-10-02 14:13:58.909619 | 2025-10-02 14:13:58.909704 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:58.935140 | controller | skipping: Conditional result was False 2025-10-02 14:13:58.941078 | 2025-10-02 14:13:58.941146 | TASK [bindep : Look for bindep fallback file] 2025-10-02 14:13:58.966106 | controller | skipping: Conditional result was False 2025-10-02 14:13:58.973516 | 2025-10-02 14:13:58.973596 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:58.997851 | controller | skipping: Conditional result was False 2025-10-02 14:13:59.005403 | 2025-10-02 14:13:59.005522 | TASK [bindep : Include bindep tasks] 2025-10-02 14:13:59.047375 | controller | ok 2025-10-02 14:13:59.065625 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 14:13:59.081766 | 2025-10-02 14:13:59.081850 | TASK [bindep : Look for bindep command] 2025-10-02 14:13:59.147474 | controller | skipping: Conditional result was False 2025-10-02 14:13:59.154040 | 2025-10-02 14:13:59.154104 | TASK [bindep : Check for system bindep] 2025-10-02 14:14:00.231786 | controller | ok: Runtime: 0:00:00.004879 2025-10-02 14:14:00.238003 | 2025-10-02 14:14:00.238069 | TASK [bindep : Define bindep_command fact] 2025-10-02 14:14:00.256205 | controller | skipping: Conditional result was False 2025-10-02 14:14:00.263176 | 2025-10-02 14:14:00.263246 | TASK [bindep : Include install tasks] 2025-10-02 14:14:00.295325 | controller | ok 2025-10-02 14:14:00.306022 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 14:14:00.317171 | 2025-10-02 14:14:00.317252 | TASK [bindep : Create temp dir for bindep] 2025-10-02 14:14:00.903317 | controller | changed 2025-10-02 14:14:00.908868 | 2025-10-02 14:14:00.908930 | TASK [Ensure we have pip dependencies] 2025-10-02 14:14:00.928842 | controller | ok 2025-10-02 14:14:00.955290 | 2025-10-02 14:14:00.955380 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 10:14:01.225017 | controller | /usr/bin/pip3 2025-10-02 10:14:01.247401 | controller | /usr/bin/python3: No module named wheel 2025-10-02 14:14:01.489571 | controller | ok: Runtime: 0:00:00.032819 2025-10-02 14:14:01.498025 | 2025-10-02 14:14:01.498111 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 14:14:01.562909 | controller | ok: "/var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 14:14:01.575289 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 14:14:01.603168 | 2025-10-02 14:14:01.603291 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 14:14:04.193529 | controller | changed 2025-10-02 14:14:04.199256 | 2025-10-02 14:14:04.199321 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 14:14:04.239427 | controller | skipping: Conditional result was False 2025-10-02 14:14:04.246842 | 2025-10-02 14:14:04.246910 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 14:14:04.303231 | controller | skipping: Conditional result was False 2025-10-02 14:14:04.311070 | 2025-10-02 14:14:04.311156 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 14:14:04.348522 | controller | skipping: Conditional result was False 2025-10-02 14:14:04.355515 | 2025-10-02 14:14:04.355585 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 14:14:04.370330 | controller | skipping: Conditional result was False 2025-10-02 14:14:04.377437 | 2025-10-02 14:14:04.377505 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 14:14:04.912809 | controller | skipping: Conditional result was False 2025-10-02 14:14:04.919566 | 2025-10-02 14:14:04.919653 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 14:14:04.956144 | controller | skipping: Conditional result was False 2025-10-02 14:14:04.965950 | 2025-10-02 14:14:04.966033 | TASK [ensure-pip : Install pip from source] 2025-10-02 14:14:04.990703 | controller | skipping: Conditional result was False 2025-10-02 14:14:04.997617 | 2025-10-02 14:14:04.997730 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 10:14:05.356006 | controller | /usr/bin/python3 2025-10-02 14:14:05.543618 | controller | ok: Runtime: 0:00:00.008094 2025-10-02 14:14:05.550575 | 2025-10-02 14:14:05.550650 | TASK [ensure-pip : Set host default] 2025-10-02 14:14:05.610555 | controller | ok 2025-10-02 14:14:05.616340 | 2025-10-02 14:14:05.616407 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 14:14:05.734375 | controller | ok 2025-10-02 14:14:05.750194 | 2025-10-02 14:14:05.750462 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 14:14:09.914790 | controller | changed 2025-10-02 14:14:09.924960 | 2025-10-02 14:14:09.925034 | TASK [bindep : Define bindep_command] 2025-10-02 14:14:09.975916 | controller | ok 2025-10-02 14:14:09.986670 | 2025-10-02 14:14:09.986765 | LOOP [bindep : Include package tasks] 2025-10-02 14:14:10.047739 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 14:14:10.047902 | controller | ok: All items complete 2025-10-02 14:14:10.047926 | 2025-10-02 14:14:10.068650 | controller | included: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 14:14:10.095302 | 2025-10-02 14:14:10.095397 | TASK [bindep : Define bindep_run fact] 2025-10-02 14:14:10.142495 | controller | ok 2025-10-02 14:14:10.158823 | 2025-10-02 14:14:10.158904 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 10:14:11.554137 | controller | podman 2025-10-02 10:14:11.585841 | controller | python3-jmespath 2025-10-02 10:14:11.586048 | controller | python3-libvirt 2025-10-02 10:14:11.586066 | controller | python3-lxml 2025-10-02 10:14:11.586080 | controller | python3-netaddr 2025-10-02 14:14:11.721478 | controller | ok: Runtime: 0:00:01.087937 2025-10-02 14:14:11.727412 | 2025-10-02 14:14:11.727477 | TASK [bindep : Install distro packages from bindep] 2025-10-02 14:15:15.860040 | controller | changed 2025-10-02 14:15:15.874017 | 2025-10-02 14:15:15.874114 | TASK [bindep : Check that packages are installed] 2025-10-02 14:15:17.417383 | controller | ok: Runtime: 0:00:01.161408 2025-10-02 14:15:17.423243 | 2025-10-02 14:15:17.423315 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 14:15:17.449294 | controller | skipping: Conditional result was False 2025-10-02 14:15:17.460276 | 2025-10-02 14:15:17.460354 | TASK [Run test-setup role] 2025-10-02 14:15:17.483103 | controller | ok 2025-10-02 14:15:17.521465 | 2025-10-02 14:15:17.521593 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 14:15:17.777341 | controller | ok 2025-10-02 14:15:17.785198 | 2025-10-02 14:15:17.785318 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 14:15:18.313580 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.339348 | 2025-10-02 14:15:18.339490 | TASK [bindep : Remove bindep temp dir] 2025-10-02 14:15:18.776465 | controller | ok 2025-10-02 14:15:18.808274 | 2025-10-02 14:15:18.808365 | PLAY RECAP 2025-10-02 14:15:18.808406 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 14:15:18.808426 | 2025-10-02 14:15:18.942586 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 14:15:18.948155 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 14:15:19.572894 | 2025-10-02 14:15:19.573034 | PLAY [all] 2025-10-02 14:15:19.592700 | 2025-10-02 14:15:19.592787 | TASK [Abort when test_command variable is undefined] 2025-10-02 14:15:19.634152 | controller | skipping: Conditional result was False 2025-10-02 14:15:19.640997 | 2025-10-02 14:15:19.641073 | TASK [Convert test_command to list] 2025-10-02 14:15:19.687621 | controller | skipping: Conditional result was False 2025-10-02 14:15:19.694223 | 2025-10-02 14:15:19.694288 | TASK [Use test_command list] 2025-10-02 14:15:19.764339 | controller | ok 2025-10-02 14:15:19.770119 | 2025-10-02 14:15:19.770185 | LOOP [Run test_command] 2025-10-02 14:15:20.345976 | controller | no check to run 2025-10-02 14:15:20.346155 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007367 2025-10-02 14:15:20.410202 | 2025-10-02 14:15:20.410310 | PLAY RECAP 2025-10-02 14:15:20.410351 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 14:15:20.410381 | 2025-10-02 14:15:20.627167 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 14:15:20.629221 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 14:15:21.418013 | 2025-10-02 14:15:21.418129 | PLAY [all] 2025-10-02 14:15:21.442197 | 2025-10-02 14:15:21.442302 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 14:15:21.781577 | controller | changed: non-zero return code 2025-10-02 14:15:21.788256 | 2025-10-02 14:15:21.788336 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 14:15:21.803120 | controller | skipping: Conditional result was False 2025-10-02 14:15:21.810843 | 2025-10-02 14:15:21.810936 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 14:15:21.837102 | 2025-10-02 14:15:21.837275 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 14:15:21.881083 | 2025-10-02 14:15:21.881419 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 14:15:21.906014 | controller | skipping: Conditional result was False 2025-10-02 14:15:21.913732 | 2025-10-02 14:15:21.913805 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 14:15:21.951349 | 2025-10-02 14:15:21.951541 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 14:15:21.979328 | controller | skipping: Conditional result was False 2025-10-02 14:15:21.986338 | 2025-10-02 14:15:21.986407 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 14:15:22.011585 | controller | skipping: Conditional result was False 2025-10-02 14:15:22.020432 | 2025-10-02 14:15:22.020500 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 14:15:22.055166 | controller | skipping: Conditional result was False 2025-10-02 14:15:22.084493 | 2025-10-02 14:15:22.084577 | PLAY RECAP 2025-10-02 14:15:22.084621 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 14:15:22.084641 | 2025-10-02 14:15:22.201730 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 14:15:22.211270 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 14:15:22.882021 | 2025-10-02 14:15:22.882153 | PLAY [all] 2025-10-02 14:15:22.902120 | 2025-10-02 14:15:22.902243 | TASK [include_role : fetch-output] 2025-10-02 14:15:22.942592 | controller | ok 2025-10-02 14:15:23.012107 | 2025-10-02 14:15:23.012224 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 14:15:23.112306 | controller | skipping: Conditional result was False 2025-10-02 14:15:23.119097 | 2025-10-02 14:15:23.119193 | TASK [fetch-output : Set log path for single node] 2025-10-02 14:15:23.184837 | controller | ok 2025-10-02 14:15:23.197089 | 2025-10-02 14:15:23.197238 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 14:15:23.667480 | controller -> localhost | ok: "/var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/logs" 2025-10-02 14:15:23.877943 | controller -> localhost | changed: "/var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/artifacts" 2025-10-02 14:15:24.196066 | controller -> localhost | changed: "/var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/docs" 2025-10-02 14:15:24.211207 | 2025-10-02 14:15:24.211306 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 14:15:24.989188 | controller | changed: .d..t...... ./ 2025-10-02 14:15:24.989389 | controller | changed: All items complete 2025-10-02 14:15:24.989417 | 2025-10-02 14:15:25.432035 | controller | changed: .d..t...... ./ 2025-10-02 14:15:25.930772 | controller | changed: .d..t...... ./ 2025-10-02 14:15:25.950643 | 2025-10-02 14:15:25.950779 | TASK [include_role : fetch-output-openshift] 2025-10-02 14:15:25.975534 | controller | skipping: Conditional result was False 2025-10-02 14:15:25.984574 | 2025-10-02 14:15:25.984847 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 14:15:26.455694 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010436 2025-10-02 14:15:26.713577 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008486 2025-10-02 14:15:26.749021 | 2025-10-02 14:15:26.749145 | PLAY [all] 2025-10-02 14:15:26.764993 | 2025-10-02 14:15:26.765173 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 14:15:27.266015 | controller | changed 2025-10-02 14:15:27.318881 | 2025-10-02 14:15:27.318981 | PLAY RECAP 2025-10-02 14:15:27.319023 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 14:15:27.319044 | 2025-10-02 14:15:27.488818 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 14:15:27.489646 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 14:15:28.228729 | 2025-10-02 14:15:28.228839 | PLAY [localhost] 2025-10-02 14:15:28.247231 | 2025-10-02 14:15:28.247324 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 14:15:28.636287 | localhost | changed 2025-10-02 14:15:28.641396 | 2025-10-02 14:15:28.641468 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 14:15:28.703395 | localhost | ok 2025-10-02 14:15:28.711501 | 2025-10-02 14:15:28.711567 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 14:15:29.075323 | localhost | changed 2025-10-02 14:15:29.080847 | 2025-10-02 14:15:29.080920 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 14:15:29.758057 | localhost | changed 2025-10-02 14:15:29.762992 | 2025-10-02 14:15:29.763052 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 14:15:30.167835 | localhost | Identity added: /var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/tmp/ansible.46fnyt36 (/var/lib/zuul/builds/affbc449b43542e686a680b9d943834f/work/tmp/ansible.46fnyt36) 2025-10-02 14:15:30.167996 | localhost | ok: Runtime: 0:00:00.008819 2025-10-02 14:15:30.172440 | 2025-10-02 14:15:30.172504 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 14:15:30.445239 | localhost | ok: Runtime: 0:00:00.005858 2025-10-02 14:15:30.453006 | 2025-10-02 14:15:30.453084 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 14:15:30.512370 | localhost | changed 2025-10-02 14:15:30.516770 | 2025-10-02 14:15:30.516859 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 14:15:30.971978 | localhost | changed 2025-10-02 14:15:30.996191 | 2025-10-02 14:15:30.996334 | PLAY [localhost] 2025-10-02 14:15:31.009397 | 2025-10-02 14:15:31.009464 | TASK [Generate bulk log download script] 2025-10-02 14:15:31.037062 | localhost | ok 2025-10-02 14:15:31.063268 | 2025-10-02 14:15:31.063386 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 14:15:31.114411 | localhost | ok: All assertions passed 2025-10-02 14:15:31.119101 | 2025-10-02 14:15:31.119163 | TASK [local-log-download : Create download script] 2025-10-02 14:15:31.560668 | localhost -> localhost | changed 2025-10-02 14:15:31.569312 | 2025-10-02 14:15:31.569373 | TASK [Register quick-download link] 2025-10-02 14:15:31.587294 | localhost | ok 2025-10-02 14:15:31.632522 | 2025-10-02 14:15:31.632619 | PLAY [logserver.rdoproject.org] 2025-10-02 14:15:31.642364 | 2025-10-02 14:15:31.642421 | TASK [Set zuul-log-path fact] 2025-10-02 14:15:31.658008 | logserver.rdoproject.org | ok 2025-10-02 14:15:31.667159 | 2025-10-02 14:15:31.667227 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 14:15:31.692949 | logserver.rdoproject.org | ok 2025-10-02 14:15:31.698945 | 2025-10-02 14:15:31.699008 | TASK [upload-logs : Create log directories] 2025-10-02 14:15:32.346862 | logserver.rdoproject.org | changed 2025-10-02 14:15:32.359118 | 2025-10-02 14:15:32.359258 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 14:15:32.672544 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009185 2025-10-02 14:15:32.679369 | 2025-10-02 14:15:32.679588 | TASK [upload-logs : Upload logs to log server] 2025-10-02 14:15:33.369302 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 14:15:33.372159 | 2025-10-02 14:15:33.372220 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 14:15:33.433730 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:33.442638 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:33.455100 | 2025-10-02 14:15:33.455291 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 14:15:33.496460 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:33.496974 | 2025-10-02 14:15:33.500283 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:33.512604 | 2025-10-02 14:15:33.512824 | LOOP [upload-logs : Upload console log and json output]