2025-10-13 07:00:12.750807 | Job console starting... 2025-10-13 07:00:12.763066 | Updating repositories 2025-10-13 07:00:12.809442 | Preparing job workspace 2025-10-13 07:00:16.512242 | Running Ansible setup... 2025-10-13 07:00:21.456005 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 07:00:22.155688 | 2025-10-13 07:00:22.155830 | PLAY [localhost] 2025-10-13 07:00:22.167513 | 2025-10-13 07:00:22.167604 | TASK [Gathering Facts] 2025-10-13 07:00:23.250879 | localhost | ok 2025-10-13 07:00:23.274892 | 2025-10-13 07:00:23.275023 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 07:00:23.670963 | localhost -> localhost | changed 2025-10-13 07:00:23.682226 | 2025-10-13 07:00:23.682369 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 07:00:24.515488 | localhost -> localhost | changed 2025-10-13 07:00:24.532155 | 2025-10-13 07:00:24.532263 | TASK [Setup log path fact] 2025-10-13 07:00:24.574964 | localhost | ok 2025-10-13 07:00:24.586435 | 2025-10-13 07:00:24.586500 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 07:00:24.614583 | localhost | ok 2025-10-13 07:00:24.622396 | 2025-10-13 07:00:24.622459 | TASK [emit-job-header : Print job information] 2025-10-13 07:00:24.650985 | # Job Information 2025-10-13 07:00:24.651225 | Ansible Version: 2.15.12 2025-10-13 07:00:24.651253 | Job: cifmw-molecule-openshift_adm 2025-10-13 07:00:24.651273 | Pipeline: github-check 2025-10-13 07:00:24.651292 | Executor: ze02.softwarefactory-project.io 2025-10-13 07:00:24.651310 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-13 07:00:24.651329 | Log URL (when completed): https://logserver.rdoproject.org/bc6/rdoproject.org/bc6599309f6149f59b4c627cdc08ef4c/ 2025-10-13 07:00:24.651347 | Event ID: 07b5c7c0-a802-11f0-8dbe-38d1533757a8 2025-10-13 07:00:24.655248 | 2025-10-13 07:00:24.655312 | LOOP [emit-job-header : Print node information] 2025-10-13 07:00:24.763511 | localhost | ok: 2025-10-13 07:00:24.763867 | localhost | # Node Information 2025-10-13 07:00:24.763900 | localhost | Inventory Hostname: controller 2025-10-13 07:00:24.763923 | localhost | Hostname: np0005482738 2025-10-13 07:00:24.763942 | localhost | Username: zuul 2025-10-13 07:00:24.763962 | localhost | Distro: CentOS 9 2025-10-13 07:00:24.764008 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 07:00:24.764030 | localhost | Region: RegionOne 2025-10-13 07:00:24.764047 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 07:00:24.764063 | localhost | Product Name: OpenStack Nova 2025-10-13 07:00:24.764104 | localhost | Interface IP: 38.102.83.234 2025-10-13 07:00:24.791870 | 2025-10-13 07:00:24.791930 | PLAY [all] 2025-10-13 07:00:24.798090 | 2025-10-13 07:00:24.798151 | TASK [Gather network facts] 2025-10-13 07:00:25.298625 | controller | ok 2025-10-13 07:00:25.313149 | 2025-10-13 07:00:25.313210 | TASK [include_role : start-zuul-console] 2025-10-13 07:00:25.331808 | controller | ok 2025-10-13 07:00:25.343017 | 2025-10-13 07:00:25.343078 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 07:00:25.740209 | controller | ok 2025-10-13 07:00:25.752834 | 2025-10-13 07:00:25.752954 | TASK [include_role : add-build-sshkey] 2025-10-13 07:00:25.782641 | controller | ok 2025-10-13 07:00:25.795525 | 2025-10-13 07:00:25.795592 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 07:00:26.042526 | controller -> localhost | ok 2025-10-13 07:00:26.048358 | 2025-10-13 07:00:26.048420 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 07:00:26.078439 | controller | ok 2025-10-13 07:00:26.094679 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 07:00:26.101426 | 2025-10-13 07:00:26.101486 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 07:00:27.133828 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 07:00:27.134054 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/bc6599309f6149f59b4c627cdc08ef4c_id_rsa. 2025-10-13 07:00:27.134087 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/bc6599309f6149f59b4c627cdc08ef4c_id_rsa.pub. 2025-10-13 07:00:27.134109 | controller -> localhost | The key fingerprint is: 2025-10-13 07:00:27.134128 | controller -> localhost | SHA256:kcNcTKCOtkH2XkTp6zZDIuxPonvVjtPqHu51TVorP9s zuul-build-sshkey 2025-10-13 07:00:27.134146 | controller -> localhost | The key's randomart image is: 2025-10-13 07:00:27.134164 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 07:00:27.134181 | controller -> localhost | | o=o | 2025-10-13 07:00:27.134199 | controller -> localhost | | =.o. | 2025-10-13 07:00:27.134217 | controller -> localhost | | o ..B | 2025-10-13 07:00:27.134235 | controller -> localhost | | o + ..o | 2025-10-13 07:00:27.134252 | controller -> localhost | | .+ o.S. o | 2025-10-13 07:00:27.134270 | controller -> localhost | | .o+o.+ = . | 2025-10-13 07:00:27.134287 | controller -> localhost | | .oo+B. + o | 2025-10-13 07:00:27.134306 | controller -> localhost | | .o+ooB. o.. | 2025-10-13 07:00:27.134324 | controller -> localhost | | oo =B+ o ooE | 2025-10-13 07:00:27.134341 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 07:00:27.134401 | controller -> localhost | ok: Runtime: 0:00:00.590386 2025-10-13 07:00:27.142470 | 2025-10-13 07:00:27.142565 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 07:00:27.173167 | controller | ok 2025-10-13 07:00:27.183558 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 07:00:27.192424 | 2025-10-13 07:00:27.192494 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 07:00:27.217018 | controller | skipping: Conditional result was False 2025-10-13 07:00:27.224868 | 2025-10-13 07:00:27.224968 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 07:00:27.677998 | controller | changed 2025-10-13 07:00:27.686563 | 2025-10-13 07:00:27.686724 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 07:00:27.961904 | controller | ok 2025-10-13 07:00:27.967345 | 2025-10-13 07:00:27.967419 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 07:00:28.873577 | controller | changed 2025-10-13 07:00:28.886143 | 2025-10-13 07:00:28.886313 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 07:00:29.736747 | controller | changed 2025-10-13 07:00:29.741684 | 2025-10-13 07:00:29.741744 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 07:00:29.770745 | controller | skipping: Conditional result was False 2025-10-13 07:00:29.777937 | 2025-10-13 07:00:29.778014 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 07:00:30.150759 | controller -> localhost | changed 2025-10-13 07:00:30.161736 | 2025-10-13 07:00:30.161860 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 07:00:30.408654 | controller -> localhost | Identity added: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/bc6599309f6149f59b4c627cdc08ef4c_id_rsa (zuul-build-sshkey) 2025-10-13 07:00:30.408865 | controller -> localhost | ok: Runtime: 0:00:00.012515 2025-10-13 07:00:30.414731 | 2025-10-13 07:00:30.414793 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 07:00:30.789583 | controller | ok 2025-10-13 07:00:30.794630 | 2025-10-13 07:00:30.794737 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 07:00:30.819515 | controller | skipping: Conditional result was False 2025-10-13 07:00:30.829554 | 2025-10-13 07:00:30.829636 | TASK [include_role : validate-host] 2025-10-13 07:00:30.857991 | controller | ok 2025-10-13 07:00:30.878401 | 2025-10-13 07:00:30.878495 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 07:00:30.918036 | controller | ok 2025-10-13 07:00:30.922641 | 2025-10-13 07:00:30.922740 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 07:00:31.151070 | controller -> localhost | ok 2025-10-13 07:00:31.157097 | 2025-10-13 07:00:31.157161 | TASK [validate-host : Collect information about the host] 2025-10-13 07:00:31.964127 | controller | ok 2025-10-13 07:00:31.973161 | 2025-10-13 07:00:31.973264 | TASK [validate-host : Sanitize hostname] 2025-10-13 07:00:32.043970 | controller | ok 2025-10-13 07:00:32.048936 | 2025-10-13 07:00:32.049062 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 07:00:32.552267 | controller -> localhost | changed 2025-10-13 07:00:32.559643 | 2025-10-13 07:00:32.559740 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 07:00:32.964739 | controller | ok 2025-10-13 07:00:32.969659 | 2025-10-13 07:00:32.969739 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 07:00:33.430779 | controller -> localhost | changed 2025-10-13 07:00:33.440464 | 2025-10-13 07:00:33.440535 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 07:00:33.476491 | controller | skipping: Conditional result was False 2025-10-13 07:00:33.483093 | 2025-10-13 07:00:33.483272 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 07:00:33.507876 | controller | skipping: Conditional result was False 2025-10-13 07:00:33.513565 | 2025-10-13 07:00:33.513693 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 07:00:33.755615 | controller | ok: "logs" 2025-10-13 07:00:33.755899 | controller | ok: All items complete 2025-10-13 07:00:33.755933 | 2025-10-13 07:00:33.991416 | controller | ok: "artifacts" 2025-10-13 07:00:34.258830 | controller | ok: "docs" 2025-10-13 07:00:34.275254 | 2025-10-13 07:00:34.275390 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 07:00:34.585677 | controller | changed: "logs" 2025-10-13 07:00:34.814705 | controller | changed: "artifacts" 2025-10-13 07:00:35.072025 | controller | changed: "docs" 2025-10-13 07:00:35.100730 | 2025-10-13 07:00:35.100841 | PLAY RECAP 2025-10-13 07:00:35.100884 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 07:00:35.100912 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 07:00:35.100929 | 2025-10-13 07:00:35.222953 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 07:00:35.224014 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 07:00:35.873377 | 2025-10-13 07:00:35.873494 | PLAY [localhost] 2025-10-13 07:00:35.897656 | 2025-10-13 07:00:35.897790 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 07:00:36.379116 | localhost | ok 2025-10-13 07:00:36.385430 | 2025-10-13 07:00:36.385515 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 07:00:37.035873 | localhost | changed 2025-10-13 07:00:37.058904 | 2025-10-13 07:00:37.059025 | PLAY [all] 2025-10-13 07:00:37.076089 | 2025-10-13 07:00:37.076165 | TASK [include_role : prepare-workspace] 2025-10-13 07:00:37.105578 | controller | ok 2025-10-13 07:00:37.120546 | 2025-10-13 07:00:37.120611 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 07:00:37.495744 | controller | ok 2025-10-13 07:00:37.505173 | 2025-10-13 07:00:37.505253 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 07:00:39.234260 | controller | Output suppressed because no_log was given 2025-10-13 07:00:39.243925 | 2025-10-13 07:00:39.243987 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 07:00:39.484658 | controller | changed: "logs" 2025-10-13 07:00:39.718939 | controller | changed: "artifacts" 2025-10-13 07:00:39.938506 | controller | changed: "docs" 2025-10-13 07:00:39.955799 | 2025-10-13 07:00:39.955924 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 07:00:40.254053 | controller | changed: "logs" 2025-10-13 07:00:40.254349 | controller | changed: All items complete 2025-10-13 07:00:40.254386 | 2025-10-13 07:00:40.483280 | controller | changed: "artifacts" 2025-10-13 07:00:40.702516 | controller | changed: "docs" 2025-10-13 07:00:40.719569 | 2025-10-13 07:00:40.719724 | TASK [Check if worker can sudo] 2025-10-13 07:00:41.250837 | controller | ok: Runtime: 0:00:00.053349 2025-10-13 07:00:41.261326 | 2025-10-13 07:00:41.261482 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 07:00:41.317494 | controller | skipping: Conditional result was False 2025-10-13 07:00:41.326207 | 2025-10-13 07:00:41.326296 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 07:00:41.387653 | controller | ok 2025-10-13 07:00:41.395304 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 07:00:41.405070 | 2025-10-13 07:00:41.405187 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 07:00:41.726420 | controller | ok 2025-10-13 07:00:41.732344 | 2025-10-13 07:00:41.732407 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 07:00:41.786133 | controller | ok: "/var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 07:00:41.794247 | 2025-10-13 07:00:41.794366 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 07:00:42.573014 | controller | changed 2025-10-13 07:00:42.581784 | 2025-10-13 07:00:42.581876 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 07:00:42.659443 | controller | ok: "/var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 07:00:42.659671 | controller | ok: All items complete 2025-10-13 07:00:42.659717 | 2025-10-13 07:00:42.714285 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 07:00:42.721099 | 2025-10-13 07:00:42.721162 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 07:00:43.593269 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 07:00:44.345918 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 07:00:44.368561 | 2025-10-13 07:00:44.368779 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 07:00:44.797517 | controller | changed: section and option added 2025-10-13 07:00:44.836238 | 2025-10-13 07:00:44.836337 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 07:00:45.631421 | controller | 29 files removed 2025-10-13 07:00:45.631868 | controller | ok: Item: dnf clean all Runtime: 0:00:00.453996 2025-10-13 07:00:45.631952 | controller | changed: All items complete 2025-10-13 07:00:45.631997 | 2025-10-13 07:00:56.281010 | 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-13 07:00:56.281143 | controller | DNF version: 4.14.0 2025-10-13 07:00:56.281179 | controller | cachedir: /var/cache/dnf 2025-10-13 07:00:56.281209 | controller | Making cache files for all metadata files. 2025-10-13 07:00:56.281236 | controller | baseos: has expired and will be refreshed. 2025-10-13 07:00:56.281262 | controller | appstream: has expired and will be refreshed. 2025-10-13 07:00:56.281287 | controller | crb: has expired and will be refreshed. 2025-10-13 07:00:56.281325 | controller | extras-common: has expired and will be refreshed. 2025-10-13 07:00:56.281350 | controller | repo: downloading from remote: baseos 2025-10-13 07:00:56.281374 | controller | CentOS Stream 9 - BaseOS 81 MB/s | 8.8 MB 00:00 2025-10-13 07:00:56.281398 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 07:00:56.281422 | controller | repo: downloading from remote: appstream 2025-10-13 07:00:56.281446 | controller | CentOS Stream 9 - AppStream 106 MB/s | 25 MB 00:00 2025-10-13 07:00:56.281470 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 07:00:56.281494 | controller | repo: downloading from remote: crb 2025-10-13 07:00:56.281518 | controller | CentOS Stream 9 - CRB 65 MB/s | 7.2 MB 00:00 2025-10-13 07:00:56.281542 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 07:00:56.281566 | controller | repo: downloading from remote: extras-common 2025-10-13 07:00:56.281590 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-10-13 07:00:56.281614 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 07:00:56.281638 | controller | Last metadata expiration check: 0:00:01 ago on Mon 13 Oct 2025 03:00:54 AM EDT. 2025-10-13 07:00:56.281706 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 07:00:56.281739 | controller | Completion plugin: Generating completion cache... 2025-10-13 07:00:56.281766 | controller | Metadata cache created. 2025-10-13 07:00:56.281802 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.384172 2025-10-13 07:00:56.312542 | 2025-10-13 07:00:56.312726 | PLAY RECAP 2025-10-13 07:00:56.312822 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 07:00:56.312878 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 07:00:56.312915 | 2025-10-13 07:00:56.452262 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 07:00:56.453165 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 07:00:57.035522 | 2025-10-13 07:00:57.035634 | PLAY [all] 2025-10-13 07:00:57.057524 | 2025-10-13 07:00:57.057613 | TASK [Install binary dependencies] 2025-10-13 07:00:57.117837 | controller | ok 2025-10-13 07:00:57.140853 | 2025-10-13 07:00:57.140969 | TASK [bindep : Include find tasks] 2025-10-13 07:00:57.170096 | controller | ok 2025-10-13 07:00:57.178585 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 07:00:57.184516 | 2025-10-13 07:00:57.184584 | TASK [bindep : Look for bindep.txt] 2025-10-13 07:00:57.573036 | controller | ok 2025-10-13 07:00:57.583556 | 2025-10-13 07:00:57.583755 | TASK [bindep : Define bindep_file fact] 2025-10-13 07:00:57.633254 | controller | ok 2025-10-13 07:00:57.647186 | 2025-10-13 07:00:57.647404 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 07:00:57.677252 | controller | skipping: Conditional result was False 2025-10-13 07:00:57.691070 | 2025-10-13 07:00:57.691227 | TASK [bindep : Define bindep_file fact] 2025-10-13 07:00:57.728928 | controller | skipping: Conditional result was False 2025-10-13 07:00:57.741530 | 2025-10-13 07:00:57.741708 | TASK [bindep : Look for bindep fallback file] 2025-10-13 07:00:57.769327 | controller | skipping: Conditional result was False 2025-10-13 07:00:57.782583 | 2025-10-13 07:00:57.782782 | TASK [bindep : Define bindep_file fact] 2025-10-13 07:00:57.819726 | controller | skipping: Conditional result was False 2025-10-13 07:00:57.832751 | 2025-10-13 07:00:57.832939 | TASK [bindep : Include bindep tasks] 2025-10-13 07:00:57.878036 | controller | ok 2025-10-13 07:00:57.887574 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 07:00:57.898717 | 2025-10-13 07:00:57.898890 | TASK [bindep : Look for bindep command] 2025-10-13 07:00:57.934210 | controller | skipping: Conditional result was False 2025-10-13 07:00:57.944779 | 2025-10-13 07:00:57.944924 | TASK [bindep : Check for system bindep] 2025-10-13 07:00:58.485552 | controller | ok: Runtime: 0:00:00.004831 2025-10-13 07:00:58.493900 | 2025-10-13 07:00:58.494006 | TASK [bindep : Define bindep_command fact] 2025-10-13 07:00:58.518790 | controller | skipping: Conditional result was False 2025-10-13 07:00:58.527014 | 2025-10-13 07:00:58.527241 | TASK [bindep : Include install tasks] 2025-10-13 07:00:58.558880 | controller | ok 2025-10-13 07:00:58.569602 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 07:00:58.582555 | 2025-10-13 07:00:58.582688 | TASK [bindep : Create temp dir for bindep] 2025-10-13 07:00:58.969519 | controller | changed 2025-10-13 07:00:58.974988 | 2025-10-13 07:00:58.975050 | TASK [Ensure we have pip dependencies] 2025-10-13 07:00:58.994860 | controller | ok 2025-10-13 07:00:59.019417 | 2025-10-13 07:00:59.019497 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 03:00:59.291150 | controller | /usr/bin/pip3 2025-10-13 03:00:59.314582 | controller | /usr/bin/python3: No module named wheel 2025-10-13 07:00:59.553796 | controller | ok: Runtime: 0:00:00.032988 2025-10-13 07:00:59.566710 | 2025-10-13 07:00:59.566981 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 07:00:59.614764 | controller | ok: "/var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 07:00:59.631924 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 07:00:59.654628 | 2025-10-13 07:00:59.654909 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 07:01:04.236629 | controller | changed 2025-10-13 07:01:04.251128 | 2025-10-13 07:01:04.251292 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 07:01:04.310957 | controller | skipping: Conditional result was False 2025-10-13 07:01:04.326436 | 2025-10-13 07:01:04.326660 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 07:01:04.386169 | controller | skipping: Conditional result was False 2025-10-13 07:01:04.400603 | 2025-10-13 07:01:04.400836 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 07:01:04.463013 | controller | skipping: Conditional result was False 2025-10-13 07:01:04.481601 | 2025-10-13 07:01:04.481871 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 07:01:04.500841 | controller | skipping: Conditional result was False 2025-10-13 07:01:04.518704 | 2025-10-13 07:01:04.519005 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 07:01:05.064274 | controller | skipping: Conditional result was False 2025-10-13 07:01:05.077414 | 2025-10-13 07:01:05.077566 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 07:01:05.104339 | controller | skipping: Conditional result was False 2025-10-13 07:01:05.117859 | 2025-10-13 07:01:05.118011 | TASK [ensure-pip : Install pip from source] 2025-10-13 07:01:05.145101 | controller | skipping: Conditional result was False 2025-10-13 07:01:05.157878 | 2025-10-13 07:01:05.158028 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 03:01:05.456172 | controller | /usr/bin/python3 2025-10-13 07:01:05.730760 | controller | ok: Runtime: 0:00:00.004733 2025-10-13 07:01:05.737109 | 2025-10-13 07:01:05.737182 | TASK [ensure-pip : Set host default] 2025-10-13 07:01:05.806824 | controller | ok 2025-10-13 07:01:05.812492 | 2025-10-13 07:01:05.812568 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 07:01:05.873497 | controller | ok 2025-10-13 07:01:05.883624 | 2025-10-13 07:01:05.883702 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 07:01:10.100692 | controller | changed 2025-10-13 07:01:10.114264 | 2025-10-13 07:01:10.114418 | TASK [bindep : Define bindep_command] 2025-10-13 07:01:10.153880 | controller | ok 2025-10-13 07:01:10.166330 | 2025-10-13 07:01:10.166482 | LOOP [bindep : Include package tasks] 2025-10-13 07:01:10.233178 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 07:01:10.233451 | controller | ok: All items complete 2025-10-13 07:01:10.233506 | 2025-10-13 07:01:10.247553 | controller | included: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 07:01:10.266761 | 2025-10-13 07:01:10.266905 | TASK [bindep : Define bindep_run fact] 2025-10-13 07:01:10.314092 | controller | ok 2025-10-13 07:01:10.323940 | 2025-10-13 07:01:10.324074 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 03:01:11.662788 | controller | podman 2025-10-13 03:01:11.695756 | controller | python3-jmespath 2025-10-13 03:01:11.695896 | controller | python3-libvirt 2025-10-13 03:01:11.695908 | controller | python3-lxml 2025-10-13 03:01:11.695918 | controller | python3-netaddr 2025-10-13 07:01:11.865377 | controller | ok: Runtime: 0:00:01.125602 2025-10-13 07:01:11.873762 | 2025-10-13 07:01:11.873855 | TASK [bindep : Install distro packages from bindep] 2025-10-13 07:02:17.096258 | controller | changed 2025-10-13 07:02:17.106397 | 2025-10-13 07:02:17.106493 | TASK [bindep : Check that packages are installed] 2025-10-13 07:02:18.658488 | controller | ok: Runtime: 0:00:01.139349 2025-10-13 07:02:18.671411 | 2025-10-13 07:02:18.671545 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 07:02:18.699817 | controller | skipping: Conditional result was False 2025-10-13 07:02:18.723945 | 2025-10-13 07:02:18.724136 | TASK [Run test-setup role] 2025-10-13 07:02:18.752966 | controller | ok 2025-10-13 07:02:18.781171 | 2025-10-13 07:02:18.781304 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 07:02:19.024571 | controller | ok 2025-10-13 07:02:19.035751 | 2025-10-13 07:02:19.035884 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 07:02:19.581545 | controller | skipping: Conditional result was False 2025-10-13 07:02:19.610637 | 2025-10-13 07:02:19.610762 | TASK [bindep : Remove bindep temp dir] 2025-10-13 07:02:19.999174 | controller | ok 2025-10-13 07:02:20.011653 | 2025-10-13 07:02:20.011790 | PLAY RECAP 2025-10-13 07:02:20.011842 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 07:02:20.011868 | 2025-10-13 07:02:20.122378 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 07:02:20.124119 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 07:02:20.732416 | 2025-10-13 07:02:20.732554 | PLAY [all] 2025-10-13 07:02:20.752773 | 2025-10-13 07:02:20.752947 | TASK [Abort when test_command variable is undefined] 2025-10-13 07:02:20.777734 | controller | skipping: Conditional result was False 2025-10-13 07:02:20.783530 | 2025-10-13 07:02:20.783608 | TASK [Convert test_command to list] 2025-10-13 07:02:20.817460 | controller | skipping: Conditional result was False 2025-10-13 07:02:20.824260 | 2025-10-13 07:02:20.824326 | TASK [Use test_command list] 2025-10-13 07:02:20.883897 | controller | ok 2025-10-13 07:02:20.889343 | 2025-10-13 07:02:20.889406 | LOOP [Run test_command] 2025-10-13 07:02:21.310588 | controller | no check to run 2025-10-13 07:02:21.310826 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008796 2025-10-13 07:02:21.352780 | 2025-10-13 07:02:21.352912 | PLAY RECAP 2025-10-13 07:02:21.352989 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 07:02:21.353023 | 2025-10-13 07:02:21.452737 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 07:02:21.454403 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 07:02:22.078701 | 2025-10-13 07:02:22.078812 | PLAY [all] 2025-10-13 07:02:22.099657 | 2025-10-13 07:02:22.099757 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 07:02:22.425136 | controller | changed: non-zero return code 2025-10-13 07:02:22.430816 | 2025-10-13 07:02:22.430886 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 07:02:22.454456 | controller | skipping: Conditional result was False 2025-10-13 07:02:22.461014 | 2025-10-13 07:02:22.461082 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 07:02:22.492319 | 2025-10-13 07:02:22.492508 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 07:02:22.522512 | 2025-10-13 07:02:22.522690 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 07:02:22.546853 | controller | skipping: Conditional result was False 2025-10-13 07:02:22.553514 | 2025-10-13 07:02:22.553580 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 07:02:22.583122 | 2025-10-13 07:02:22.583245 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 07:02:22.609018 | controller | skipping: Conditional result was False 2025-10-13 07:02:22.614559 | 2025-10-13 07:02:22.614628 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 07:02:22.638401 | controller | skipping: Conditional result was False 2025-10-13 07:02:22.644038 | 2025-10-13 07:02:22.644100 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 07:02:22.667955 | controller | skipping: Conditional result was False 2025-10-13 07:02:22.692240 | 2025-10-13 07:02:22.692295 | PLAY RECAP 2025-10-13 07:02:22.692337 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 07:02:22.692357 | 2025-10-13 07:02:22.824070 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 07:02:22.825741 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 07:02:23.383970 | 2025-10-13 07:02:23.384079 | PLAY [all] 2025-10-13 07:02:23.403359 | 2025-10-13 07:02:23.403444 | TASK [include_role : fetch-output] 2025-10-13 07:02:23.443795 | controller | ok 2025-10-13 07:02:23.460751 | 2025-10-13 07:02:23.460831 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 07:02:23.504774 | controller | skipping: Conditional result was False 2025-10-13 07:02:23.510425 | 2025-10-13 07:02:23.510489 | TASK [fetch-output : Set log path for single node] 2025-10-13 07:02:23.539131 | controller | ok 2025-10-13 07:02:23.545626 | 2025-10-13 07:02:23.545708 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 07:02:23.912925 | controller -> localhost | ok: "/var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/logs" 2025-10-13 07:02:24.126523 | controller -> localhost | changed: "/var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/artifacts" 2025-10-13 07:02:24.329216 | controller -> localhost | changed: "/var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/docs" 2025-10-13 07:02:24.348423 | 2025-10-13 07:02:24.348632 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 07:02:24.966278 | controller | changed: .d..t...... ./ 2025-10-13 07:02:24.966808 | controller | changed: All items complete 2025-10-13 07:02:24.966882 | 2025-10-13 07:02:25.408759 | controller | changed: .d..t...... ./ 2025-10-13 07:02:25.847212 | controller | changed: .d..t...... ./ 2025-10-13 07:02:25.874031 | 2025-10-13 07:02:25.874329 | TASK [include_role : fetch-output-openshift] 2025-10-13 07:02:25.892414 | controller | skipping: Conditional result was False 2025-10-13 07:02:25.906318 | 2025-10-13 07:02:25.906490 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 07:02:26.369870 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012118 2025-10-13 07:02:26.605411 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012654 2025-10-13 07:02:26.640680 | 2025-10-13 07:02:26.640787 | PLAY [all] 2025-10-13 07:02:26.655660 | 2025-10-13 07:02:26.655802 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 07:02:27.072572 | controller | changed 2025-10-13 07:02:27.096253 | 2025-10-13 07:02:27.096349 | PLAY RECAP 2025-10-13 07:02:27.096388 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 07:02:27.096408 | 2025-10-13 07:02:27.194236 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 07:02:27.195032 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 07:02:27.780787 | 2025-10-13 07:02:27.780917 | PLAY [localhost] 2025-10-13 07:02:27.799829 | 2025-10-13 07:02:27.799948 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 07:02:28.214949 | localhost | changed 2025-10-13 07:02:28.219870 | 2025-10-13 07:02:28.219956 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 07:02:28.248383 | localhost | ok 2025-10-13 07:02:28.256638 | 2025-10-13 07:02:28.256724 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 07:02:28.628866 | localhost | changed 2025-10-13 07:02:28.634833 | 2025-10-13 07:02:28.634940 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 07:02:29.317870 | localhost | changed 2025-10-13 07:02:29.323121 | 2025-10-13 07:02:29.323190 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 07:02:29.720298 | localhost | Identity added: /var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/tmp/ansible.symy6m0b (/var/lib/zuul/builds/bc6599309f6149f59b4c627cdc08ef4c/work/tmp/ansible.symy6m0b) 2025-10-13 07:02:29.720587 | localhost | ok: Runtime: 0:00:00.009560 2025-10-13 07:02:29.728380 | 2025-10-13 07:02:29.728482 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 07:02:29.998871 | localhost | ok: Runtime: 0:00:00.006940 2025-10-13 07:02:30.003657 | 2025-10-13 07:02:30.013957 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 07:02:30.063208 | localhost | changed 2025-10-13 07:02:30.069901 | 2025-10-13 07:02:30.069965 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 07:02:30.490891 | localhost | changed 2025-10-13 07:02:30.511341 | 2025-10-13 07:02:30.511404 | PLAY [localhost] 2025-10-13 07:02:30.528273 | 2025-10-13 07:02:30.528332 | TASK [Generate bulk log download script] 2025-10-13 07:02:30.557477 | localhost | ok 2025-10-13 07:02:30.569279 | 2025-10-13 07:02:30.569349 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 07:02:30.597162 | localhost | ok: All assertions passed 2025-10-13 07:02:30.601967 | 2025-10-13 07:02:30.602029 | TASK [local-log-download : Create download script] 2025-10-13 07:02:30.991366 | localhost -> localhost | changed 2025-10-13 07:02:31.001081 | 2025-10-13 07:02:31.001143 | TASK [Register quick-download link] 2025-10-13 07:02:31.028229 | localhost | ok 2025-10-13 07:02:31.069660 | 2025-10-13 07:02:31.069769 | PLAY [logserver.rdoproject.org] 2025-10-13 07:02:31.079419 | 2025-10-13 07:02:31.079476 | TASK [Set zuul-log-path fact] 2025-10-13 07:02:31.096132 | logserver.rdoproject.org | ok 2025-10-13 07:02:31.105111 | 2025-10-13 07:02:31.105174 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 07:02:31.141841 | logserver.rdoproject.org | ok 2025-10-13 07:02:31.147431 | 2025-10-13 07:02:31.147491 | TASK [upload-logs : Create log directories] 2025-10-13 07:02:31.864056 | logserver.rdoproject.org | changed 2025-10-13 07:02:31.871979 | 2025-10-13 07:02:31.872118 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 07:02:32.123459 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006976 2025-10-13 07:02:32.131404 | 2025-10-13 07:02:32.131494 | TASK [upload-logs : Upload logs to log server] 2025-10-13 07:02:32.836240 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 07:02:32.840934 | 2025-10-13 07:02:32.841028 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 07:02:32.913821 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:32.923448 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:32.929703 | 2025-10-13 07:02:32.929808 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 07:02:32.972224 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:32.972645 | 2025-10-13 07:02:32.975931 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:32.988428 | 2025-10-13 07:02:32.988526 | LOOP [upload-logs : Upload console log and json output]