2025-12-10 02:11:02.014305 | Job console starting... 2025-12-10 02:11:02.025844 | Updating repositories 2025-12-10 02:11:02.064909 | Preparing job workspace 2025-12-10 02:11:05.493836 | Running Ansible setup... 2025-12-10 02:11:09.128302 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-10 02:11:09.685482 | 2025-12-10 02:11:09.685588 | PLAY [localhost] 2025-12-10 02:11:09.693962 | 2025-12-10 02:11:09.694029 | TASK [Gathering Facts] 2025-12-10 02:11:10.750473 | localhost | ok 2025-12-10 02:11:10.780845 | 2025-12-10 02:11:10.781021 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-10 02:11:11.251642 | localhost -> localhost | changed 2025-12-10 02:11:11.270574 | 2025-12-10 02:11:11.270745 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-10 02:11:12.144994 | localhost -> localhost | changed 2025-12-10 02:11:12.165367 | 2025-12-10 02:11:12.165506 | TASK [Setup log path fact] 2025-12-10 02:11:12.186824 | localhost | ok 2025-12-10 02:11:12.201408 | 2025-12-10 02:11:12.201495 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-10 02:11:12.233814 | localhost | ok 2025-12-10 02:11:12.246061 | 2025-12-10 02:11:12.246151 | TASK [emit-job-header : Print job information] 2025-12-10 02:11:12.286182 | # Job Information 2025-12-10 02:11:12.286359 | Ansible Version: 2.15.12 2025-12-10 02:11:12.286394 | Job: cifmw-molecule-cifmw_setup 2025-12-10 02:11:12.286422 | Pipeline: github-check 2025-12-10 02:11:12.286448 | Executor: ze03.softwarefactory-project.io 2025-12-10 02:11:12.286473 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3533 2025-12-10 02:11:12.286518 | Log URL (when completed): https://logserver.rdoproject.org/ee5/rdoproject.org/ee5329e3093540989108ff57bdda2de8/ 2025-12-10 02:11:12.286545 | Event ID: 506d3050-d56d-11f0-95ee-bbb7c76ff6d7 2025-12-10 02:11:12.293153 | 2025-12-10 02:11:12.293244 | LOOP [emit-job-header : Print node information] 2025-12-10 02:11:12.454585 | localhost | ok: 2025-12-10 02:11:12.454878 | localhost | # Node Information 2025-12-10 02:11:12.454937 | localhost | Inventory Hostname: controller 2025-12-10 02:11:12.454987 | localhost | Hostname: np0005552623 2025-12-10 02:11:12.455029 | localhost | Username: zuul 2025-12-10 02:11:12.455073 | localhost | Distro: CentOS 9 2025-12-10 02:11:12.455111 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-10 02:11:12.455149 | localhost | Region: RegionOne 2025-12-10 02:11:12.455185 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-10 02:11:12.455222 | localhost | Product Name: OpenStack Nova 2025-12-10 02:11:12.455258 | localhost | Interface IP: 38.102.83.97 2025-12-10 02:11:12.494067 | 2025-12-10 02:11:12.494140 | PLAY [all] 2025-12-10 02:11:12.502632 | 2025-12-10 02:11:12.502713 | TASK [Gather network facts] 2025-12-10 02:11:12.995620 | controller | ok 2025-12-10 02:11:13.034431 | 2025-12-10 02:11:13.034554 | TASK [include_role : start-zuul-console] 2025-12-10 02:11:13.062609 | controller | ok 2025-12-10 02:11:13.078051 | 2025-12-10 02:11:13.078175 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-10 02:11:13.475852 | controller | ok 2025-12-10 02:11:13.490470 | 2025-12-10 02:11:13.490676 | TASK [include_role : add-build-sshkey] 2025-12-10 02:11:13.523348 | controller | ok 2025-12-10 02:11:13.544850 | 2025-12-10 02:11:13.545630 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-10 02:11:13.816927 | controller -> localhost | ok 2025-12-10 02:11:13.833657 | 2025-12-10 02:11:13.833879 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-10 02:11:13.871490 | controller | ok 2025-12-10 02:11:13.898618 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-10 02:11:13.907705 | 2025-12-10 02:11:13.907809 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-10 02:11:14.639843 | controller -> localhost | Generating public/private rsa key pair. 2025-12-10 02:11:14.640101 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/ee5329e3093540989108ff57bdda2de8_id_rsa. 2025-12-10 02:11:14.640146 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/ee5329e3093540989108ff57bdda2de8_id_rsa.pub. 2025-12-10 02:11:14.640178 | controller -> localhost | The key fingerprint is: 2025-12-10 02:11:14.640206 | controller -> localhost | SHA256:+DmnZjpnUK7nNTzmMhILR5QC0kX21+orERGiA3OAzqg zuul-build-sshkey 2025-12-10 02:11:14.640234 | controller -> localhost | The key's randomart image is: 2025-12-10 02:11:14.640261 | controller -> localhost | +---[RSA 3072]----+ 2025-12-10 02:11:14.640287 | controller -> localhost | |*oo+= .o | 2025-12-10 02:11:14.640313 | controller -> localhost | |.=.o.o+ . | 2025-12-10 02:11:14.640338 | controller -> localhost | |+ o o... . | 2025-12-10 02:11:14.640364 | controller -> localhost | |.o . oo.. | 2025-12-10 02:11:14.640389 | controller -> localhost | |. ..+S | 2025-12-10 02:11:14.640414 | controller -> localhost | |E . =o.o | 2025-12-10 02:11:14.640448 | controller -> localhost | | o *= B | 2025-12-10 02:11:14.640485 | controller -> localhost | | * OO o | 2025-12-10 02:11:14.640512 | controller -> localhost | | .%+o. | 2025-12-10 02:11:14.640537 | controller -> localhost | +----[SHA256]-----+ 2025-12-10 02:11:14.640602 | controller -> localhost | ok: Runtime: 0:00:00.220375 2025-12-10 02:11:14.648674 | 2025-12-10 02:11:14.648797 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-10 02:11:14.680237 | controller | ok 2025-12-10 02:11:14.693884 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-10 02:11:14.705234 | 2025-12-10 02:11:14.705339 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-10 02:11:14.730100 | controller | skipping: Conditional result was False 2025-12-10 02:11:14.738990 | 2025-12-10 02:11:14.739080 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-10 02:11:15.301697 | controller | changed 2025-12-10 02:11:15.318911 | 2025-12-10 02:11:15.319055 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-10 02:11:15.608601 | controller | ok 2025-12-10 02:11:15.626497 | 2025-12-10 02:11:15.626638 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-10 02:11:16.605217 | controller | changed 2025-12-10 02:11:16.620247 | 2025-12-10 02:11:16.620410 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-10 02:11:17.569879 | controller | changed 2025-12-10 02:11:17.581497 | 2025-12-10 02:11:17.581649 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-10 02:11:17.608633 | controller | skipping: Conditional result was False 2025-12-10 02:11:17.623030 | 2025-12-10 02:11:17.623207 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-10 02:11:18.037240 | controller -> localhost | changed 2025-12-10 02:11:18.055286 | 2025-12-10 02:11:18.055405 | TASK [add-build-sshkey : Add back temp key] 2025-12-10 02:11:18.354687 | controller -> localhost | Identity added: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/ee5329e3093540989108ff57bdda2de8_id_rsa (zuul-build-sshkey) 2025-12-10 02:11:18.354884 | controller -> localhost | ok: Runtime: 0:00:00.014462 2025-12-10 02:11:18.360355 | 2025-12-10 02:11:18.360415 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-10 02:11:18.771749 | controller | ok 2025-12-10 02:11:18.781789 | 2025-12-10 02:11:18.781924 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-10 02:11:18.809078 | controller | skipping: Conditional result was False 2025-12-10 02:11:18.830116 | 2025-12-10 02:11:18.830287 | TASK [include_role : validate-host] 2025-12-10 02:11:18.858447 | controller | ok 2025-12-10 02:11:18.892129 | 2025-12-10 02:11:18.892270 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-10 02:11:18.934000 | controller | ok 2025-12-10 02:11:18.947084 | 2025-12-10 02:11:18.947291 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-10 02:11:19.237604 | controller -> localhost | ok 2025-12-10 02:11:19.250852 | 2025-12-10 02:11:19.251024 | TASK [validate-host : Collect information about the host] 2025-12-10 02:11:20.106570 | controller | ok 2025-12-10 02:11:20.134611 | 2025-12-10 02:11:20.134874 | TASK [validate-host : Sanitize hostname] 2025-12-10 02:11:20.227247 | controller | ok 2025-12-10 02:11:20.242155 | 2025-12-10 02:11:20.242362 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-10 02:11:20.903781 | controller -> localhost | changed 2025-12-10 02:11:20.916515 | 2025-12-10 02:11:20.916651 | TASK [validate-host : Collect information about zuul worker] 2025-12-10 02:11:21.309828 | controller | ok 2025-12-10 02:11:21.314686 | 2025-12-10 02:11:21.314765 | TASK [validate-host : Write out all zuul information for each host] 2025-12-10 02:11:21.830440 | controller -> localhost | changed 2025-12-10 02:11:21.849994 | 2025-12-10 02:11:21.850150 | TASK [include_role : prepare-workspace-openshift] 2025-12-10 02:11:21.867137 | controller | skipping: Conditional result was False 2025-12-10 02:11:21.878264 | 2025-12-10 02:11:21.878390 | TASK [include_role : remove-zuul-sshkey] 2025-12-10 02:11:21.894787 | controller | skipping: Conditional result was False 2025-12-10 02:11:21.906341 | 2025-12-10 02:11:21.906477 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-10 02:11:22.198253 | controller | ok: "logs" 2025-12-10 02:11:22.198648 | controller | ok: All items complete 2025-12-10 02:11:22.198700 | 2025-12-10 02:11:22.427029 | controller | ok: "artifacts" 2025-12-10 02:11:22.651006 | controller | ok: "docs" 2025-12-10 02:11:22.664025 | 2025-12-10 02:11:22.664163 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-10 02:11:22.968954 | controller | changed: "logs" 2025-12-10 02:11:23.224627 | controller | changed: "artifacts" 2025-12-10 02:11:23.452156 | controller | changed: "docs" 2025-12-10 02:11:23.501301 | 2025-12-10 02:11:23.501448 | PLAY RECAP 2025-12-10 02:11:23.501534 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-10 02:11:23.501590 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-10 02:11:23.501628 | 2025-12-10 02:11:23.614132 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-10 02:11:23.615081 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-10 02:11:24.249289 | 2025-12-10 02:11:24.249416 | PLAY [localhost] 2025-12-10 02:11:24.267711 | 2025-12-10 02:11:24.267858 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-10 02:11:24.674257 | localhost | ok 2025-12-10 02:11:24.679240 | 2025-12-10 02:11:24.679311 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-10 02:11:25.305557 | localhost | changed 2025-12-10 02:11:25.337690 | 2025-12-10 02:11:25.337828 | PLAY [all] 2025-12-10 02:11:25.359657 | 2025-12-10 02:11:25.359776 | TASK [include_role : prepare-workspace] 2025-12-10 02:11:25.392256 | controller | ok 2025-12-10 02:11:25.415639 | 2025-12-10 02:11:25.415779 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-10 02:11:25.864414 | controller | ok 2025-12-10 02:11:25.870295 | 2025-12-10 02:11:25.870363 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-10 02:11:27.711602 | controller | Output suppressed because no_log was given 2025-12-10 02:11:27.721889 | 2025-12-10 02:11:27.721953 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-10 02:11:28.030960 | controller | changed: "logs" 2025-12-10 02:11:28.272224 | controller | changed: "artifacts" 2025-12-10 02:11:28.518333 | controller | changed: "docs" 2025-12-10 02:11:28.535167 | 2025-12-10 02:11:28.535414 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-10 02:11:28.870506 | controller | changed: "logs" 2025-12-10 02:11:28.870755 | controller | changed: All items complete 2025-12-10 02:11:28.870802 | 2025-12-10 02:11:29.129818 | controller | changed: "artifacts" 2025-12-10 02:11:29.342900 | controller | changed: "docs" 2025-12-10 02:11:29.373198 | 2025-12-10 02:11:29.373381 | TASK [Check if worker can sudo] 2025-12-10 02:11:29.919755 | controller | ok: Runtime: 0:00:00.049879 2025-12-10 02:11:29.925211 | 2025-12-10 02:11:29.925302 | TASK [configure-mirrors : Gather needed facts] 2025-12-10 02:11:29.969071 | controller | skipping: Conditional result was False 2025-12-10 02:11:29.974982 | 2025-12-10 02:11:29.975077 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-10 02:11:30.024398 | controller | ok 2025-12-10 02:11:30.035001 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-10 02:11:30.066888 | 2025-12-10 02:11:30.066995 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-10 02:11:30.349142 | controller | ok 2025-12-10 02:11:30.361430 | 2025-12-10 02:11:30.361575 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-10 02:11:30.420656 | controller | ok: "/var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-10 02:11:30.435403 | 2025-12-10 02:11:30.435565 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-10 02:11:31.331000 | controller | changed 2025-12-10 02:11:31.338128 | 2025-12-10 02:11:31.338209 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-10 02:11:31.403970 | controller | ok: "/var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-10 02:11:31.404221 | controller | ok: All items complete 2025-12-10 02:11:31.404273 | 2025-12-10 02:11:31.466086 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-10 02:11:31.472454 | 2025-12-10 02:11:31.472522 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-10 02:11:32.398650 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-10 02:11:33.424775 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-10 02:11:33.447795 | 2025-12-10 02:11:33.447938 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-10 02:11:33.982610 | controller | changed: section and option added 2025-12-10 02:11:34.026477 | 2025-12-10 02:11:34.026607 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-10 02:11:34.685222 | controller | 29 files removed 2025-12-10 02:11:34.685648 | controller | ok: Item: dnf clean all Runtime: 0:00:00.282623 2025-12-10 02:11:34.685765 | controller | changed: All items complete 2025-12-10 02:11:34.685819 | 2025-12-10 02:11:45.296397 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-10 02:11:45.296584 | controller | DNF version: 4.14.0 2025-12-10 02:11:45.296648 | controller | cachedir: /var/cache/dnf 2025-12-10 02:11:45.296700 | controller | Making cache files for all metadata files. 2025-12-10 02:11:45.296927 | controller | baseos: has expired and will be refreshed. 2025-12-10 02:11:45.296985 | controller | appstream: has expired and will be refreshed. 2025-12-10 02:11:45.297084 | controller | crb: has expired and will be refreshed. 2025-12-10 02:11:45.297150 | controller | extras-common: has expired and will be refreshed. 2025-12-10 02:11:45.297189 | controller | repo: downloading from remote: baseos 2025-12-10 02:11:45.297227 | controller | CentOS Stream 9 - BaseOS 71 MB/s | 8.8 MB 00:00 2025-12-10 02:11:45.297264 | controller | baseos: using metadata from Mon 08 Dec 2025 10:09:26 AM EST. 2025-12-10 02:11:45.297302 | controller | repo: downloading from remote: appstream 2025-12-10 02:11:45.297339 | controller | CentOS Stream 9 - AppStream 114 MB/s | 26 MB 00:00 2025-12-10 02:11:45.297375 | controller | appstream: using metadata from Mon 08 Dec 2025 10:12:51 AM EST. 2025-12-10 02:11:45.297411 | controller | repo: downloading from remote: crb 2025-12-10 02:11:45.297447 | controller | CentOS Stream 9 - CRB 56 MB/s | 7.4 MB 00:00 2025-12-10 02:11:45.297484 | controller | crb: using metadata from Mon 08 Dec 2025 10:17:14 AM EST. 2025-12-10 02:11:45.297521 | controller | repo: downloading from remote: extras-common 2025-12-10 02:11:45.297558 | controller | CentOS Stream 9 - Extras packages 1.6 MB/s | 20 kB 00:00 2025-12-10 02:11:45.297595 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-10 02:11:45.297632 | controller | Last metadata expiration check: 0:00:01 ago on Tue 09 Dec 2025 09:11:43 PM EST. 2025-12-10 02:11:45.297669 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-10 02:11:45.297705 | controller | Completion plugin: Generating completion cache... 2025-12-10 02:11:45.297794 | controller | Metadata cache created. 2025-12-10 02:11:45.297852 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.333389 2025-12-10 02:11:45.318020 | 2025-12-10 02:11:45.318138 | PLAY RECAP 2025-12-10 02:11:45.318219 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-10 02:11:45.318273 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-10 02:11:45.318312 | 2025-12-10 02:11:45.464469 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-10 02:11:45.465300 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-10 02:11:45.987675 | 2025-12-10 02:11:45.987790 | PLAY [all] 2025-12-10 02:11:46.007921 | 2025-12-10 02:11:46.008008 | TASK [Install binary dependencies] 2025-12-10 02:11:46.058661 | controller | ok 2025-12-10 02:11:46.084433 | 2025-12-10 02:11:46.084543 | TASK [bindep : Include find tasks] 2025-12-10 02:11:46.113364 | controller | ok 2025-12-10 02:11:46.120486 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-10 02:11:46.126288 | 2025-12-10 02:11:46.126349 | TASK [bindep : Look for bindep.txt] 2025-12-10 02:11:46.604699 | controller | ok 2025-12-10 02:11:46.615320 | 2025-12-10 02:11:46.615482 | TASK [bindep : Define bindep_file fact] 2025-12-10 02:11:46.649952 | controller | ok 2025-12-10 02:11:46.662305 | 2025-12-10 02:11:46.662442 | TASK [bindep : Look for other-requirements.txt] 2025-12-10 02:11:46.676708 | controller | skipping: Conditional result was False 2025-12-10 02:11:46.682502 | 2025-12-10 02:11:46.682630 | TASK [bindep : Define bindep_file fact] 2025-12-10 02:11:46.697278 | controller | skipping: Conditional result was False 2025-12-10 02:11:46.703790 | 2025-12-10 02:11:46.703867 | TASK [bindep : Look for bindep fallback file] 2025-12-10 02:11:46.727952 | controller | skipping: Conditional result was False 2025-12-10 02:11:46.733760 | 2025-12-10 02:11:46.733833 | TASK [bindep : Define bindep_file fact] 2025-12-10 02:11:46.758072 | controller | skipping: Conditional result was False 2025-12-10 02:11:46.763830 | 2025-12-10 02:11:46.763910 | TASK [bindep : Include bindep tasks] 2025-12-10 02:11:46.794141 | controller | ok 2025-12-10 02:11:46.800916 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-10 02:11:46.808802 | 2025-12-10 02:11:46.808882 | TASK [bindep : Look for bindep command] 2025-12-10 02:11:46.832954 | controller | skipping: Conditional result was False 2025-12-10 02:11:46.841986 | 2025-12-10 02:11:46.842099 | TASK [bindep : Check for system bindep] 2025-12-10 02:11:47.382691 | controller | ok: Runtime: 0:00:00.004849 2025-12-10 02:11:47.388582 | 2025-12-10 02:11:47.388644 | TASK [bindep : Define bindep_command fact] 2025-12-10 02:11:47.412238 | controller | skipping: Conditional result was False 2025-12-10 02:11:47.418106 | 2025-12-10 02:11:47.418171 | TASK [bindep : Include install tasks] 2025-12-10 02:11:47.447064 | controller | ok 2025-12-10 02:11:47.455329 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-10 02:11:47.464211 | 2025-12-10 02:11:47.464273 | TASK [bindep : Create temp dir for bindep] 2025-12-10 02:11:47.823276 | controller | changed 2025-12-10 02:11:47.834865 | 2025-12-10 02:11:47.834992 | TASK [Ensure we have pip dependencies] 2025-12-10 02:11:47.866175 | controller | ok 2025-12-10 02:11:47.904561 | 2025-12-10 02:11:47.904650 | TASK [ensure-pip : Check if pip is installed] 2025-12-09 21:11:48.216069 | controller | /usr/bin/pip3 2025-12-09 21:11:48.258443 | controller | /usr/bin/python3: No module named wheel 2025-12-10 02:11:48.439897 | controller | ok: Runtime: 0:00:00.056133 2025-12-10 02:11:48.448512 | 2025-12-10 02:11:48.448601 | LOOP [ensure-pip : Install pip from packages] 2025-12-10 02:11:48.487602 | controller | ok: "/var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-10 02:11:48.507475 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-10 02:11:48.524451 | 2025-12-10 02:11:48.524579 | TASK [ensure-pip : Install Python 3 pip] 2025-12-10 02:11:50.433995 | controller | changed 2025-12-10 02:11:50.446924 | 2025-12-10 02:11:50.447065 | TASK [ensure-pip : Check for EPEL repository] 2025-12-10 02:11:50.503640 | controller | skipping: Conditional result was False 2025-12-10 02:11:50.512984 | 2025-12-10 02:11:50.513087 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-10 02:11:50.567006 | controller | skipping: Conditional result was False 2025-12-10 02:11:50.574659 | 2025-12-10 02:11:50.574758 | TASK [ensure-pip : Install Python 2 pip] 2025-12-10 02:11:50.631578 | controller | skipping: Conditional result was False 2025-12-10 02:11:50.638623 | 2025-12-10 02:11:50.638692 | TASK [ensure-pip : Ensure setuptools] 2025-12-10 02:11:50.652871 | controller | skipping: Conditional result was False 2025-12-10 02:11:50.659798 | 2025-12-10 02:11:50.659864 | TASK [ensure-pip : Check for ensurepip module] 2025-12-10 02:11:51.187555 | controller | skipping: Conditional result was False 2025-12-10 02:11:51.203129 | 2025-12-10 02:11:51.203315 | TASK [ensure-pip : Ensure python3-venv] 2025-12-10 02:11:51.231835 | controller | skipping: Conditional result was False 2025-12-10 02:11:51.246428 | 2025-12-10 02:11:51.246625 | TASK [ensure-pip : Install pip from source] 2025-12-10 02:11:51.284834 | controller | skipping: Conditional result was False 2025-12-10 02:11:51.297783 | 2025-12-10 02:11:51.297937 | TASK [ensure-pip : Probe for venv python full path] 2025-12-09 21:11:51.603394 | controller | /usr/bin/python3 2025-12-10 02:11:51.851761 | controller | ok: Runtime: 0:00:00.006007 2025-12-10 02:11:51.858490 | 2025-12-10 02:11:51.858566 | TASK [ensure-pip : Set host default] 2025-12-10 02:11:51.918747 | controller | ok 2025-12-10 02:11:51.928463 | 2025-12-10 02:11:51.928649 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-10 02:11:51.988393 | controller | ok 2025-12-10 02:11:51.997885 | 2025-12-10 02:11:51.997948 | TASK [bindep : Install bindep into temporary venv] 2025-12-10 02:11:56.036452 | controller | changed 2025-12-10 02:11:56.048068 | 2025-12-10 02:11:56.048224 | TASK [bindep : Define bindep_command] 2025-12-10 02:11:56.086696 | controller | ok 2025-12-10 02:11:56.098415 | 2025-12-10 02:11:56.098625 | LOOP [bindep : Include package tasks] 2025-12-10 02:11:56.175982 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-10 02:11:56.176405 | controller | ok: All items complete 2025-12-10 02:11:56.176467 | 2025-12-10 02:11:56.201220 | controller | included: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-10 02:11:56.231704 | 2025-12-10 02:11:56.231872 | TASK [bindep : Define bindep_run fact] 2025-12-10 02:11:56.273215 | controller | ok 2025-12-10 02:11:56.283234 | 2025-12-10 02:11:56.283315 | TASK [bindep : Get list of packages to install from bindep] 2025-12-09 21:11:57.690475 | controller | podman 2025-12-09 21:11:57.719289 | controller | python3-jmespath 2025-12-09 21:11:57.719491 | controller | python3-libvirt 2025-12-09 21:11:57.719512 | controller | python3-lxml 2025-12-09 21:11:57.719531 | controller | python3-netaddr 2025-12-10 02:11:57.824360 | controller | ok: Runtime: 0:00:01.139831 2025-12-10 02:11:57.835995 | 2025-12-10 02:11:57.836129 | TASK [bindep : Install distro packages from bindep] 2025-12-10 02:12:58.627574 | controller | changed 2025-12-10 02:12:58.640139 | 2025-12-10 02:12:58.640374 | TASK [bindep : Check that packages are installed] 2025-12-10 02:13:00.229720 | controller | ok: Runtime: 0:00:01.241457 2025-12-10 02:13:00.245565 | 2025-12-10 02:13:00.245869 | TASK [bindep : Fail if we cannot install all packages] 2025-12-10 02:13:00.274124 | controller | skipping: Conditional result was False 2025-12-10 02:13:00.296921 | 2025-12-10 02:13:00.297056 | TASK [Run test-setup role] 2025-12-10 02:13:00.320718 | controller | ok 2025-12-10 02:13:00.390458 | 2025-12-10 02:13:00.390642 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-10 02:13:00.674038 | controller | ok 2025-12-10 02:13:00.679284 | 2025-12-10 02:13:00.679351 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-10 02:13:01.216621 | controller | skipping: Conditional result was False 2025-12-10 02:13:01.267761 | 2025-12-10 02:13:01.267904 | TASK [bindep : Remove bindep temp dir] 2025-12-10 02:13:01.657885 | controller | ok 2025-12-10 02:13:01.672972 | 2025-12-10 02:13:01.673071 | PLAY RECAP 2025-12-10 02:13:01.673124 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-10 02:13:01.673153 | 2025-12-10 02:13:01.774158 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-10 02:13:01.775070 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-10 02:13:02.407802 | 2025-12-10 02:13:02.407925 | PLAY [all] 2025-12-10 02:13:02.428585 | 2025-12-10 02:13:02.428717 | TASK [Abort when test_command variable is undefined] 2025-12-10 02:13:02.473525 | controller | skipping: Conditional result was False 2025-12-10 02:13:02.479258 | 2025-12-10 02:13:02.479356 | TASK [Convert test_command to list] 2025-12-10 02:13:02.534054 | controller | skipping: Conditional result was False 2025-12-10 02:13:02.546678 | 2025-12-10 02:13:02.546860 | TASK [Use test_command list] 2025-12-10 02:13:02.602669 | controller | ok 2025-12-10 02:13:02.616898 | 2025-12-10 02:13:02.617037 | LOOP [Run test_command] 2025-12-10 02:13:03.037533 | controller | no check to run 2025-12-10 02:13:03.037758 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006078 2025-12-10 02:13:03.059704 | 2025-12-10 02:13:03.059842 | PLAY RECAP 2025-12-10 02:13:03.059885 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-10 02:13:03.059905 | 2025-12-10 02:13:03.158390 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-10 02:13:03.160134 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-10 02:13:03.750976 | 2025-12-10 02:13:03.751098 | PLAY [all] 2025-12-10 02:13:03.771817 | 2025-12-10 02:13:03.771911 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-10 02:13:04.196802 | controller | changed: non-zero return code 2025-12-10 02:13:04.204249 | 2025-12-10 02:13:04.204419 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-10 02:13:04.231672 | controller | skipping: Conditional result was False 2025-12-10 02:13:04.246556 | 2025-12-10 02:13:04.246826 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-10 02:13:04.287533 | 2025-12-10 02:13:04.287807 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-10 02:13:04.326434 | 2025-12-10 02:13:04.326677 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-10 02:13:04.353601 | controller | skipping: Conditional result was False 2025-12-10 02:13:04.366121 | 2025-12-10 02:13:04.366415 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-10 02:13:04.407825 | 2025-12-10 02:13:04.408077 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-10 02:13:04.435023 | controller | skipping: Conditional result was False 2025-12-10 02:13:04.447001 | 2025-12-10 02:13:04.447138 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-10 02:13:04.474851 | controller | skipping: Conditional result was False 2025-12-10 02:13:04.486900 | 2025-12-10 02:13:04.487037 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-10 02:13:04.514032 | controller | skipping: Conditional result was False 2025-12-10 02:13:04.560059 | 2025-12-10 02:13:04.560136 | PLAY RECAP 2025-12-10 02:13:04.560192 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-10 02:13:04.560218 | 2025-12-10 02:13:04.662261 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-10 02:13:04.663480 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-10 02:13:05.230773 | 2025-12-10 02:13:05.230879 | PLAY [all] 2025-12-10 02:13:05.249299 | 2025-12-10 02:13:05.249373 | TASK [include_role : fetch-output] 2025-12-10 02:13:05.289591 | controller | ok 2025-12-10 02:13:05.306468 | 2025-12-10 02:13:05.306602 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-10 02:13:05.373538 | controller | skipping: Conditional result was False 2025-12-10 02:13:05.385834 | 2025-12-10 02:13:05.385977 | TASK [fetch-output : Set log path for single node] 2025-12-10 02:13:05.434536 | controller | ok 2025-12-10 02:13:05.446152 | 2025-12-10 02:13:05.446290 | LOOP [fetch-output : Ensure local output dirs] 2025-12-10 02:13:05.907836 | controller -> localhost | ok: "/var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/logs" 2025-12-10 02:13:06.193929 | controller -> localhost | changed: "/var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/artifacts" 2025-12-10 02:13:06.456381 | controller -> localhost | changed: "/var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/docs" 2025-12-10 02:13:06.480474 | 2025-12-10 02:13:06.480663 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-10 02:13:07.192407 | controller | changed: .d..t...... ./ 2025-12-10 02:13:07.192958 | controller | changed: All items complete 2025-12-10 02:13:07.193034 | 2025-12-10 02:13:07.706546 | controller | changed: .d..t...... ./ 2025-12-10 02:13:08.203782 | controller | changed: .d..t...... ./ 2025-12-10 02:13:08.217640 | 2025-12-10 02:13:08.217787 | TASK [include_role : fetch-output-openshift] 2025-12-10 02:13:08.241368 | controller | skipping: Conditional result was False 2025-12-10 02:13:08.247788 | 2025-12-10 02:13:08.247851 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-10 02:13:08.670499 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008211 2025-12-10 02:13:08.909461 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012527 2025-12-10 02:13:08.936495 | 2025-12-10 02:13:08.936593 | PLAY [all] 2025-12-10 02:13:08.950665 | 2025-12-10 02:13:08.950756 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-10 02:13:09.446600 | controller | changed 2025-12-10 02:13:09.468880 | 2025-12-10 02:13:09.468931 | PLAY RECAP 2025-12-10 02:13:09.468969 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-10 02:13:09.468989 | 2025-12-10 02:13:09.560498 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-10 02:13:09.562170 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-10 02:13:10.160031 | 2025-12-10 02:13:10.160147 | PLAY [localhost] 2025-12-10 02:13:10.177791 | 2025-12-10 02:13:10.177869 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-10 02:13:10.547478 | localhost | changed 2025-12-10 02:13:10.557764 | 2025-12-10 02:13:10.557939 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-10 02:13:10.586752 | localhost | ok 2025-12-10 02:13:10.601439 | 2025-12-10 02:13:10.601535 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-10 02:13:10.963411 | localhost | changed 2025-12-10 02:13:10.974472 | 2025-12-10 02:13:10.974619 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-10 02:13:11.706299 | localhost | changed 2025-12-10 02:13:11.717344 | 2025-12-10 02:13:11.717498 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-10 02:13:12.188648 | localhost | Identity added: /var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/tmp/ansible._600mk1t (/var/lib/zuul/builds/ee5329e3093540989108ff57bdda2de8/work/tmp/ansible._600mk1t) 2025-12-10 02:13:12.188888 | localhost | ok: Runtime: 0:00:00.013548 2025-12-10 02:13:12.194818 | 2025-12-10 02:13:12.194908 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-10 02:13:12.503833 | localhost | ok: Runtime: 0:00:00.008473 2025-12-10 02:13:12.514024 | 2025-12-10 02:13:12.514167 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-10 02:13:12.601830 | localhost | changed 2025-12-10 02:13:12.610882 | 2025-12-10 02:13:12.611017 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-10 02:13:13.068706 | localhost | changed 2025-12-10 02:13:13.102701 | 2025-12-10 02:13:13.102845 | PLAY [localhost] 2025-12-10 02:13:13.120133 | 2025-12-10 02:13:13.120226 | TASK [Generate bulk log download script] 2025-12-10 02:13:13.140746 | localhost | ok 2025-12-10 02:13:13.157104 | 2025-12-10 02:13:13.157202 | TASK [local-log-download : Check API endpoint is defined] 2025-12-10 02:13:13.199578 | localhost | ok: All assertions passed 2025-12-10 02:13:13.205913 | 2025-12-10 02:13:13.206005 | TASK [local-log-download : Create download script] 2025-12-10 02:13:13.728344 | localhost -> localhost | changed 2025-12-10 02:13:13.737193 | 2025-12-10 02:13:13.737257 | TASK [Register quick-download link] 2025-12-10 02:13:13.769295 | localhost | ok 2025-12-10 02:13:13.836171 | 2025-12-10 02:13:13.836334 | PLAY [logserver.rdoproject.org] 2025-12-10 02:13:13.846119 | 2025-12-10 02:13:13.846205 | TASK [Set zuul-log-path fact] 2025-12-10 02:13:13.862913 | logserver.rdoproject.org | ok 2025-12-10 02:13:13.871399 | 2025-12-10 02:13:13.871464 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-10 02:13:13.908825 | logserver.rdoproject.org | ok 2025-12-10 02:13:13.916216 | 2025-12-10 02:13:13.916308 | TASK [upload-logs : Create log directories] 2025-12-10 02:13:14.620453 | logserver.rdoproject.org | changed 2025-12-10 02:13:14.627017 | 2025-12-10 02:13:14.627144 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-10 02:13:14.967337 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.015357 2025-12-10 02:13:14.973338 | 2025-12-10 02:13:14.973416 | TASK [upload-logs : Upload logs to log server] 2025-12-10 02:13:15.698604 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-10 02:13:15.704834 | 2025-12-10 02:13:15.704968 | LOOP [upload-logs : Compress console log and json output] 2025-12-10 02:13:15.780067 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-10 02:13:15.791135 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-10 02:13:15.800654 | 2025-12-10 02:13:15.800776 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-10 02:13:15.848289 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-10 02:13:15.848787 | 2025-12-10 02:13:15.851699 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-10 02:13:15.863459 | 2025-12-10 02:13:15.863604 | LOOP [upload-logs : Upload console log and json output]