2025-10-13 09:35:11.031589 | Job console starting... 2025-10-13 09:35:11.044578 | Updating repositories 2025-10-13 09:35:11.074725 | Preparing job workspace 2025-10-13 09:35:15.112134 | Running Ansible setup... 2025-10-13 09:35:19.307545 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 09:35:19.925230 | 2025-10-13 09:35:19.925365 | PLAY [localhost] 2025-10-13 09:35:19.934545 | 2025-10-13 09:35:19.934647 | TASK [Gathering Facts] 2025-10-13 09:35:21.004235 | localhost | ok 2025-10-13 09:35:21.041379 | 2025-10-13 09:35:21.041728 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 09:35:21.438500 | localhost -> localhost | changed 2025-10-13 09:35:21.446261 | 2025-10-13 09:35:21.446366 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 09:35:22.355427 | localhost -> localhost | changed 2025-10-13 09:35:22.365091 | 2025-10-13 09:35:22.365198 | TASK [Setup log path fact] 2025-10-13 09:35:22.384227 | localhost | ok 2025-10-13 09:35:22.396195 | 2025-10-13 09:35:22.396307 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 09:35:22.426406 | localhost | ok 2025-10-13 09:35:22.434601 | 2025-10-13 09:35:22.434668 | TASK [emit-job-header : Print job information] 2025-10-13 09:35:22.472374 | # Job Information 2025-10-13 09:35:22.472510 | Ansible Version: 2.15.12 2025-10-13 09:35:22.472537 | Job: cifmw-molecule-openshift_adm 2025-10-13 09:35:22.472557 | Pipeline: github-check 2025-10-13 09:35:22.472580 | Executor: ze01.softwarefactory-project.io 2025-10-13 09:35:22.472603 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-13 09:35:22.472627 | Log URL (when completed): https://logserver.rdoproject.org/2e1/rdoproject.org/2e1e53baa2ea4a32b5fcac4abda64bd8/ 2025-10-13 09:35:22.472652 | Event ID: dc7e7520-a815-11f0-9fb0-d110e1a8d56a 2025-10-13 09:35:22.476329 | 2025-10-13 09:35:22.476394 | LOOP [emit-job-header : Print node information] 2025-10-13 09:35:22.586181 | localhost | ok: 2025-10-13 09:35:22.586475 | localhost | # Node Information 2025-10-13 09:35:22.586534 | localhost | Inventory Hostname: controller 2025-10-13 09:35:22.586584 | localhost | Hostname: np0005483024 2025-10-13 09:35:22.586627 | localhost | Username: zuul 2025-10-13 09:35:22.586672 | localhost | Distro: CentOS 9 2025-10-13 09:35:22.586714 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 09:35:22.586754 | localhost | Region: RegionOne 2025-10-13 09:35:22.586792 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 09:35:22.586835 | localhost | Product Name: OpenStack Nova 2025-10-13 09:35:22.586892 | localhost | Interface IP: 38.102.83.227 2025-10-13 09:35:22.613656 | 2025-10-13 09:35:22.613782 | PLAY [all] 2025-10-13 09:35:22.620427 | 2025-10-13 09:35:22.620487 | TASK [Gather network facts] 2025-10-13 09:35:23.179325 | controller | ok 2025-10-13 09:35:23.199877 | 2025-10-13 09:35:23.199993 | TASK [include_role : start-zuul-console] 2025-10-13 09:35:23.222856 | controller | ok 2025-10-13 09:35:23.239472 | 2025-10-13 09:35:23.239623 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 09:35:23.722294 | controller | ok 2025-10-13 09:35:23.743978 | 2025-10-13 09:35:23.744193 | TASK [include_role : add-build-sshkey] 2025-10-13 09:35:23.778874 | controller | ok 2025-10-13 09:35:23.801303 | 2025-10-13 09:35:23.801540 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 09:35:24.128505 | controller -> localhost | ok 2025-10-13 09:35:24.141685 | 2025-10-13 09:35:24.141871 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 09:35:24.169175 | controller | ok 2025-10-13 09:35:24.189778 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 09:35:24.198001 | 2025-10-13 09:35:24.198158 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 09:35:24.879405 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 09:35:24.879639 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/2e1e53baa2ea4a32b5fcac4abda64bd8_id_rsa. 2025-10-13 09:35:24.879673 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/2e1e53baa2ea4a32b5fcac4abda64bd8_id_rsa.pub. 2025-10-13 09:35:24.879697 | controller -> localhost | The key fingerprint is: 2025-10-13 09:35:24.879718 | controller -> localhost | SHA256:LZB3GWFZDR7n6ApRI8Y1j08x89yAYPeLVDyzDEK21ss zuul-build-sshkey 2025-10-13 09:35:24.879737 | controller -> localhost | The key's randomart image is: 2025-10-13 09:35:24.879757 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 09:35:24.879784 | controller -> localhost | | .oo&=O=+ | 2025-10-13 09:35:24.879813 | controller -> localhost | | o.*o%o&=o | 2025-10-13 09:35:24.879840 | controller -> localhost | | o o *.Bo=+.| 2025-10-13 09:35:24.879860 | controller -> localhost | | o = * oo. | 2025-10-13 09:35:24.879878 | controller -> localhost | | S . E . | 2025-10-13 09:35:24.879896 | controller -> localhost | | o . | 2025-10-13 09:35:24.879913 | controller -> localhost | | . | 2025-10-13 09:35:24.879931 | controller -> localhost | | | 2025-10-13 09:35:24.879948 | controller -> localhost | | | 2025-10-13 09:35:24.879966 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 09:35:24.880011 | controller -> localhost | ok: Runtime: 0:00:00.243766 2025-10-13 09:35:24.886070 | 2025-10-13 09:35:24.886138 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 09:35:24.915188 | controller | ok 2025-10-13 09:35:24.925359 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 09:35:24.933945 | 2025-10-13 09:35:24.934056 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 09:35:24.958237 | controller | skipping: Conditional result was False 2025-10-13 09:35:24.964827 | 2025-10-13 09:35:24.964906 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 09:35:25.447249 | controller | changed 2025-10-13 09:35:25.455807 | 2025-10-13 09:35:25.455975 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 09:35:25.720345 | controller | ok 2025-10-13 09:35:25.731239 | 2025-10-13 09:35:25.731384 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 09:35:26.662398 | controller | changed 2025-10-13 09:35:26.668494 | 2025-10-13 09:35:26.668562 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 09:35:27.585428 | controller | changed 2025-10-13 09:35:27.592983 | 2025-10-13 09:35:27.593216 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 09:35:27.619533 | controller | skipping: Conditional result was False 2025-10-13 09:35:27.628253 | 2025-10-13 09:35:27.628366 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 09:35:28.051478 | controller -> localhost | changed 2025-10-13 09:35:28.061832 | 2025-10-13 09:35:28.061910 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 09:35:28.391770 | controller -> localhost | Identity added: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/2e1e53baa2ea4a32b5fcac4abda64bd8_id_rsa (zuul-build-sshkey) 2025-10-13 09:35:28.392113 | controller -> localhost | ok: Runtime: 0:00:00.009689 2025-10-13 09:35:28.400376 | 2025-10-13 09:35:28.400536 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 09:35:28.855853 | controller | ok 2025-10-13 09:35:28.866623 | 2025-10-13 09:35:28.866756 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 09:35:28.903183 | controller | skipping: Conditional result was False 2025-10-13 09:35:28.921720 | 2025-10-13 09:35:28.921849 | TASK [include_role : validate-host] 2025-10-13 09:35:28.951579 | controller | ok 2025-10-13 09:35:28.972283 | 2025-10-13 09:35:28.972415 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 09:35:29.003417 | controller | ok 2025-10-13 09:35:29.009260 | 2025-10-13 09:35:29.009341 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 09:35:29.236434 | controller -> localhost | ok 2025-10-13 09:35:29.244132 | 2025-10-13 09:35:29.244244 | TASK [validate-host : Collect information about the host] 2025-10-13 09:35:30.084001 | controller | ok 2025-10-13 09:35:30.094284 | 2025-10-13 09:35:30.094399 | TASK [validate-host : Sanitize hostname] 2025-10-13 09:35:30.154219 | controller | ok 2025-10-13 09:35:30.159786 | 2025-10-13 09:35:30.159886 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 09:35:30.673408 | controller -> localhost | changed 2025-10-13 09:35:30.688138 | 2025-10-13 09:35:30.688308 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 09:35:31.210798 | controller | ok 2025-10-13 09:35:31.217345 | 2025-10-13 09:35:31.217494 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 09:35:31.743525 | controller -> localhost | changed 2025-10-13 09:35:31.756515 | 2025-10-13 09:35:31.756651 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 09:35:31.800574 | controller | skipping: Conditional result was False 2025-10-13 09:35:31.812677 | 2025-10-13 09:35:31.812939 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 09:35:31.842840 | controller | skipping: Conditional result was False 2025-10-13 09:35:31.849134 | 2025-10-13 09:35:31.849207 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 09:35:32.146286 | controller | ok: "logs" 2025-10-13 09:35:32.146897 | controller | ok: All items complete 2025-10-13 09:35:32.146941 | 2025-10-13 09:35:32.364986 | controller | ok: "artifacts" 2025-10-13 09:35:32.588683 | controller | ok: "docs" 2025-10-13 09:35:32.605060 | 2025-10-13 09:35:32.605254 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 09:35:32.922451 | controller | changed: "logs" 2025-10-13 09:35:33.171380 | controller | changed: "artifacts" 2025-10-13 09:35:33.429107 | controller | changed: "docs" 2025-10-13 09:35:33.457965 | 2025-10-13 09:35:33.458114 | PLAY RECAP 2025-10-13 09:35:33.458164 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 09:35:33.458190 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 09:35:33.458209 | 2025-10-13 09:35:33.605340 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 09:35:33.606337 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 09:35:34.257839 | 2025-10-13 09:35:34.258093 | PLAY [localhost] 2025-10-13 09:35:34.280072 | 2025-10-13 09:35:34.280260 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 09:35:34.780225 | localhost | ok 2025-10-13 09:35:34.788522 | 2025-10-13 09:35:34.788702 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 09:35:35.489364 | localhost | changed 2025-10-13 09:35:35.529607 | 2025-10-13 09:35:35.529769 | PLAY [all] 2025-10-13 09:35:35.558187 | 2025-10-13 09:35:35.558360 | TASK [include_role : prepare-workspace] 2025-10-13 09:35:35.593809 | controller | ok 2025-10-13 09:35:35.624475 | 2025-10-13 09:35:35.624609 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 09:35:36.079783 | controller | ok 2025-10-13 09:35:36.094051 | 2025-10-13 09:35:36.094205 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 09:35:38.072533 | controller | Output suppressed because no_log was given 2025-10-13 09:35:38.095279 | 2025-10-13 09:35:38.095498 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 09:35:38.413279 | controller | changed: "logs" 2025-10-13 09:35:38.658812 | controller | changed: "artifacts" 2025-10-13 09:35:38.932224 | controller | changed: "docs" 2025-10-13 09:35:38.943561 | 2025-10-13 09:35:38.943727 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 09:35:39.259078 | controller | changed: "logs" 2025-10-13 09:35:39.259515 | controller | changed: All items complete 2025-10-13 09:35:39.259590 | 2025-10-13 09:35:39.487791 | controller | changed: "artifacts" 2025-10-13 09:35:39.764326 | controller | changed: "docs" 2025-10-13 09:35:39.795713 | 2025-10-13 09:35:39.796396 | TASK [Check if worker can sudo] 2025-10-13 09:35:40.373275 | controller | ok: Runtime: 0:00:00.059263 2025-10-13 09:35:40.382214 | 2025-10-13 09:35:40.382339 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 09:35:40.447952 | controller | skipping: Conditional result was False 2025-10-13 09:35:40.458805 | 2025-10-13 09:35:40.458958 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 09:35:40.519199 | controller | ok 2025-10-13 09:35:40.526911 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 09:35:40.558621 | 2025-10-13 09:35:40.558757 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 09:35:40.922611 | controller | ok 2025-10-13 09:35:40.935802 | 2025-10-13 09:35:40.935968 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 09:35:41.026556 | controller | ok: "/var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 09:35:41.048235 | 2025-10-13 09:35:41.048442 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 09:35:42.072179 | controller | changed 2025-10-13 09:35:42.084301 | 2025-10-13 09:35:42.084497 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 09:35:42.170493 | controller | ok: "/var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 09:35:42.170797 | controller | ok: All items complete 2025-10-13 09:35:42.170839 | 2025-10-13 09:35:42.230367 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 09:35:42.237668 | 2025-10-13 09:35:42.237771 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 09:35:43.321436 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 09:35:44.347436 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 09:35:44.378298 | 2025-10-13 09:35:44.378633 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 09:35:44.949312 | controller | changed: section and option added 2025-10-13 09:35:44.995525 | 2025-10-13 09:35:44.995703 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 09:35:45.814264 | controller | 29 files removed 2025-10-13 09:35:45.814531 | controller | ok: Item: dnf clean all Runtime: 0:00:00.465422 2025-10-13 09:35:45.814583 | controller | changed: All items complete 2025-10-13 09:35:45.814613 | 2025-10-13 09:35:55.990889 | 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 09:35:55.991130 | controller | DNF version: 4.14.0 2025-10-13 09:35:55.991239 | controller | cachedir: /var/cache/dnf 2025-10-13 09:35:55.991287 | controller | Making cache files for all metadata files. 2025-10-13 09:35:55.991329 | controller | baseos: has expired and will be refreshed. 2025-10-13 09:35:55.991369 | controller | appstream: has expired and will be refreshed. 2025-10-13 09:35:55.991406 | controller | crb: has expired and will be refreshed. 2025-10-13 09:35:55.991462 | controller | extras-common: has expired and will be refreshed. 2025-10-13 09:35:55.991499 | controller | repo: downloading from remote: baseos 2025-10-13 09:35:55.991538 | controller | CentOS Stream 9 - BaseOS 72 MB/s | 8.8 MB 00:00 2025-10-13 09:35:55.991575 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 09:35:55.991614 | controller | repo: downloading from remote: appstream 2025-10-13 09:35:55.991652 | controller | CentOS Stream 9 - AppStream 114 MB/s | 25 MB 00:00 2025-10-13 09:35:55.991688 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 09:35:55.991724 | controller | repo: downloading from remote: crb 2025-10-13 09:35:55.991763 | controller | CentOS Stream 9 - CRB 92 MB/s | 7.2 MB 00:00 2025-10-13 09:35:55.991800 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 09:35:55.991840 | controller | repo: downloading from remote: extras-common 2025-10-13 09:35:55.991881 | controller | CentOS Stream 9 - Extras packages 1.1 MB/s | 20 kB 00:00 2025-10-13 09:35:55.991918 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 09:35:55.991956 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 09:35:55.991993 | controller | Completion plugin: Generating completion cache... 2025-10-13 09:35:55.992072 | controller | Metadata cache created. 2025-10-13 09:35:55.992138 | controller | ok: Item: dnf makecache -v Runtime: 0:00:09.850857 2025-10-13 09:35:56.025528 | 2025-10-13 09:35:56.025760 | PLAY RECAP 2025-10-13 09:35:56.025860 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 09:35:56.025914 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 09:35:56.025951 | 2025-10-13 09:35:56.184519 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 09:35:56.186188 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 09:35:56.906123 | 2025-10-13 09:35:56.906352 | PLAY [all] 2025-10-13 09:35:56.933558 | 2025-10-13 09:35:56.933768 | TASK [Install binary dependencies] 2025-10-13 09:35:56.998552 | controller | ok 2025-10-13 09:35:57.022374 | 2025-10-13 09:35:57.022596 | TASK [bindep : Include find tasks] 2025-10-13 09:35:57.053548 | controller | ok 2025-10-13 09:35:57.061265 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 09:35:57.067374 | 2025-10-13 09:35:57.067481 | TASK [bindep : Look for bindep.txt] 2025-10-13 09:35:57.608593 | controller | ok 2025-10-13 09:35:57.624508 | 2025-10-13 09:35:57.624685 | TASK [bindep : Define bindep_file fact] 2025-10-13 09:35:57.664836 | controller | ok 2025-10-13 09:35:57.673371 | 2025-10-13 09:35:57.673505 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 09:35:57.699916 | controller | skipping: Conditional result was False 2025-10-13 09:35:57.709236 | 2025-10-13 09:35:57.709433 | TASK [bindep : Define bindep_file fact] 2025-10-13 09:35:57.745602 | controller | skipping: Conditional result was False 2025-10-13 09:35:57.754425 | 2025-10-13 09:35:57.754592 | TASK [bindep : Look for bindep fallback file] 2025-10-13 09:35:57.780510 | controller | skipping: Conditional result was False 2025-10-13 09:35:57.789768 | 2025-10-13 09:35:57.789944 | TASK [bindep : Define bindep_file fact] 2025-10-13 09:35:57.842738 | controller | skipping: Conditional result was False 2025-10-13 09:35:57.851182 | 2025-10-13 09:35:57.851340 | TASK [bindep : Include bindep tasks] 2025-10-13 09:35:57.897161 | controller | ok 2025-10-13 09:35:57.906791 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 09:35:57.917827 | 2025-10-13 09:35:57.917982 | TASK [bindep : Look for bindep command] 2025-10-13 09:35:57.942628 | controller | skipping: Conditional result was False 2025-10-13 09:35:57.951403 | 2025-10-13 09:35:57.951585 | TASK [bindep : Check for system bindep] 2025-10-13 09:35:58.988868 | controller | ok: Runtime: 0:00:00.008693 2025-10-13 09:35:58.996355 | 2025-10-13 09:35:58.996486 | TASK [bindep : Define bindep_command fact] 2025-10-13 09:35:59.023816 | controller | skipping: Conditional result was False 2025-10-13 09:35:59.031153 | 2025-10-13 09:35:59.031310 | TASK [bindep : Include install tasks] 2025-10-13 09:35:59.088283 | controller | ok 2025-10-13 09:35:59.097126 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 09:35:59.107241 | 2025-10-13 09:35:59.107413 | TASK [bindep : Create temp dir for bindep] 2025-10-13 09:35:59.554582 | controller | changed 2025-10-13 09:35:59.566591 | 2025-10-13 09:35:59.566756 | TASK [Ensure we have pip dependencies] 2025-10-13 09:35:59.597004 | controller | ok 2025-10-13 09:35:59.639805 | 2025-10-13 09:35:59.639986 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 05:35:59.998326 | controller | /usr/bin/pip3 2025-10-13 05:36:00.044525 | controller | /usr/bin/python3: No module named wheel 2025-10-13 09:36:00.176046 | controller | ok: Runtime: 0:00:00.062937 2025-10-13 09:36:00.182707 | 2025-10-13 09:36:00.182892 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 09:36:00.239146 | controller | ok: "/var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 09:36:00.257424 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 09:36:00.272712 | 2025-10-13 09:36:00.272816 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 09:36:02.809367 | controller | changed 2025-10-13 09:36:02.817639 | 2025-10-13 09:36:02.817759 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 09:36:02.874323 | controller | skipping: Conditional result was False 2025-10-13 09:36:02.885300 | 2025-10-13 09:36:02.885551 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 09:36:02.922302 | controller | skipping: Conditional result was False 2025-10-13 09:36:02.931060 | 2025-10-13 09:36:02.931234 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 09:36:02.966359 | controller | skipping: Conditional result was False 2025-10-13 09:36:02.979219 | 2025-10-13 09:36:02.979412 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 09:36:03.006478 | controller | skipping: Conditional result was False 2025-10-13 09:36:03.016237 | 2025-10-13 09:36:03.016340 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 09:36:03.559840 | controller | skipping: Conditional result was False 2025-10-13 09:36:03.574009 | 2025-10-13 09:36:03.574228 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 09:36:03.591279 | controller | skipping: Conditional result was False 2025-10-13 09:36:03.606746 | 2025-10-13 09:36:03.606949 | TASK [ensure-pip : Install pip from source] 2025-10-13 09:36:03.636385 | controller | skipping: Conditional result was False 2025-10-13 09:36:03.651623 | 2025-10-13 09:36:03.651943 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 05:36:04.006783 | controller | /usr/bin/python3 2025-10-13 09:36:04.212660 | controller | ok: Runtime: 0:00:00.008532 2025-10-13 09:36:04.222485 | 2025-10-13 09:36:04.222648 | TASK [ensure-pip : Set host default] 2025-10-13 09:36:04.303403 | controller | ok 2025-10-13 09:36:04.315672 | 2025-10-13 09:36:04.315827 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 09:36:04.390766 | controller | ok 2025-10-13 09:36:04.414375 | 2025-10-13 09:36:04.414541 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 09:36:08.570894 | controller | changed 2025-10-13 09:36:08.589056 | 2025-10-13 09:36:08.589273 | TASK [bindep : Define bindep_command] 2025-10-13 09:36:08.628267 | controller | ok 2025-10-13 09:36:08.638349 | 2025-10-13 09:36:08.638575 | LOOP [bindep : Include package tasks] 2025-10-13 09:36:08.713072 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 09:36:08.713382 | controller | ok: All items complete 2025-10-13 09:36:08.713423 | 2025-10-13 09:36:08.732291 | controller | included: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 09:36:08.751215 | 2025-10-13 09:36:08.751771 | TASK [bindep : Define bindep_run fact] 2025-10-13 09:36:08.789313 | controller | ok 2025-10-13 09:36:08.798578 | 2025-10-13 09:36:08.798744 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 05:36:10.325413 | controller | podman 2025-10-13 05:36:10.373685 | controller | python3-jmespath 2025-10-13 05:36:10.374836 | controller | python3-libvirt 2025-10-13 05:36:10.375005 | controller | python3-lxml 2025-10-13 05:36:10.375023 | controller | python3-netaddr 2025-10-13 09:36:10.846151 | controller | ok: Runtime: 0:00:01.255254 2025-10-13 09:36:10.863760 | 2025-10-13 09:36:10.864073 | TASK [bindep : Install distro packages from bindep] 2025-10-13 09:37:14.313939 | controller | changed 2025-10-13 09:37:14.327369 | 2025-10-13 09:37:14.328497 | TASK [bindep : Check that packages are installed] 2025-10-13 09:37:16.376457 | controller | ok: Runtime: 0:00:01.243440 2025-10-13 09:37:16.390079 | 2025-10-13 09:37:16.390287 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 09:37:16.428643 | controller | skipping: Conditional result was False 2025-10-13 09:37:16.453533 | 2025-10-13 09:37:16.453733 | TASK [Run test-setup role] 2025-10-13 09:37:16.488687 | controller | ok 2025-10-13 09:37:16.513774 | 2025-10-13 09:37:16.513901 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 09:37:16.795860 | controller | ok 2025-10-13 09:37:16.807871 | 2025-10-13 09:37:16.808058 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 09:37:17.357769 | controller | skipping: Conditional result was False 2025-10-13 09:37:17.402660 | 2025-10-13 09:37:17.402833 | TASK [bindep : Remove bindep temp dir] 2025-10-13 09:37:17.806810 | controller | ok 2025-10-13 09:37:17.821145 | 2025-10-13 09:37:17.821290 | PLAY RECAP 2025-10-13 09:37:17.821336 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 09:37:17.821357 | 2025-10-13 09:37:17.946721 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 09:37:17.948693 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 09:37:18.563613 | 2025-10-13 09:37:18.563743 | PLAY [all] 2025-10-13 09:37:18.585670 | 2025-10-13 09:37:18.585803 | TASK [Abort when test_command variable is undefined] 2025-10-13 09:37:18.630290 | controller | skipping: Conditional result was False 2025-10-13 09:37:18.636145 | 2025-10-13 09:37:18.636243 | TASK [Convert test_command to list] 2025-10-13 09:37:18.691659 | controller | skipping: Conditional result was False 2025-10-13 09:37:18.705739 | 2025-10-13 09:37:18.705888 | TASK [Use test_command list] 2025-10-13 09:37:18.785195 | controller | ok 2025-10-13 09:37:18.800215 | 2025-10-13 09:37:18.800430 | LOOP [Run test_command] 2025-10-13 09:37:19.263912 | controller | no check to run 2025-10-13 09:37:19.264131 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005627 2025-10-13 09:37:19.309913 | 2025-10-13 09:37:19.310099 | PLAY RECAP 2025-10-13 09:37:19.310184 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 09:37:19.310226 | 2025-10-13 09:37:19.427471 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 09:37:19.429738 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 09:37:20.029682 | 2025-10-13 09:37:20.030036 | PLAY [all] 2025-10-13 09:37:20.051653 | 2025-10-13 09:37:20.051791 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 09:37:20.487452 | controller | changed: non-zero return code 2025-10-13 09:37:20.496082 | 2025-10-13 09:37:20.496329 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 09:37:20.525367 | controller | skipping: Conditional result was False 2025-10-13 09:37:20.534420 | 2025-10-13 09:37:20.534757 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 09:37:20.573348 | 2025-10-13 09:37:20.573629 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 09:37:20.610252 | 2025-10-13 09:37:20.610588 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 09:37:20.637897 | controller | skipping: Conditional result was False 2025-10-13 09:37:20.647891 | 2025-10-13 09:37:20.648140 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 09:37:20.686787 | 2025-10-13 09:37:20.687159 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 09:37:20.714655 | controller | skipping: Conditional result was False 2025-10-13 09:37:20.724331 | 2025-10-13 09:37:20.724555 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 09:37:20.752272 | controller | skipping: Conditional result was False 2025-10-13 09:37:20.761496 | 2025-10-13 09:37:20.761709 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 09:37:20.789542 | controller | skipping: Conditional result was False 2025-10-13 09:37:20.833239 | 2025-10-13 09:37:20.833466 | PLAY RECAP 2025-10-13 09:37:20.833566 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 09:37:20.833613 | 2025-10-13 09:37:21.019740 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 09:37:21.021735 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 09:37:21.726511 | 2025-10-13 09:37:21.726675 | PLAY [all] 2025-10-13 09:37:21.747993 | 2025-10-13 09:37:21.748153 | TASK [include_role : fetch-output] 2025-10-13 09:37:21.803660 | controller | ok 2025-10-13 09:37:21.832476 | 2025-10-13 09:37:21.832683 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 09:37:21.911174 | controller | skipping: Conditional result was False 2025-10-13 09:37:21.920998 | 2025-10-13 09:37:21.921154 | TASK [fetch-output : Set log path for single node] 2025-10-13 09:37:21.966391 | controller | ok 2025-10-13 09:37:21.974803 | 2025-10-13 09:37:21.974966 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 09:37:22.562686 | controller -> localhost | ok: "/var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/logs" 2025-10-13 09:37:22.853912 | controller -> localhost | changed: "/var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/artifacts" 2025-10-13 09:37:23.127501 | controller -> localhost | changed: "/var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/docs" 2025-10-13 09:37:23.155759 | 2025-10-13 09:37:23.156004 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 09:37:24.003750 | controller | changed: .d..t...... ./ 2025-10-13 09:37:24.004147 | controller | changed: All items complete 2025-10-13 09:37:24.004204 | 2025-10-13 09:37:24.635143 | controller | changed: .d..t...... ./ 2025-10-13 09:37:25.181488 | controller | changed: .d..t...... ./ 2025-10-13 09:37:25.193139 | 2025-10-13 09:37:25.193214 | TASK [include_role : fetch-output-openshift] 2025-10-13 09:37:25.210299 | controller | skipping: Conditional result was False 2025-10-13 09:37:25.217791 | 2025-10-13 09:37:25.217873 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 09:37:25.788536 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014943 2025-10-13 09:37:26.117972 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015214 2025-10-13 09:37:26.182760 | 2025-10-13 09:37:26.183007 | PLAY [all] 2025-10-13 09:37:26.211579 | 2025-10-13 09:37:26.212174 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 09:37:26.725431 | controller | changed 2025-10-13 09:37:26.756603 | 2025-10-13 09:37:26.756759 | PLAY RECAP 2025-10-13 09:37:26.756805 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 09:37:26.756825 | 2025-10-13 09:37:26.937989 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 09:37:26.938922 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 09:37:27.632248 | 2025-10-13 09:37:27.632419 | PLAY [localhost] 2025-10-13 09:37:27.653473 | 2025-10-13 09:37:27.653668 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 09:37:28.041085 | localhost | changed 2025-10-13 09:37:28.046581 | 2025-10-13 09:37:28.046682 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 09:37:28.087393 | localhost | ok 2025-10-13 09:37:28.098884 | 2025-10-13 09:37:28.099005 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 09:37:28.568160 | localhost | changed 2025-10-13 09:37:28.574280 | 2025-10-13 09:37:28.574386 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 09:37:29.353741 | localhost | changed 2025-10-13 09:37:29.365956 | 2025-10-13 09:37:29.366152 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 09:37:29.858097 | localhost | Identity added: /var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/tmp/ansible.ki82s94r (/var/lib/zuul/builds/2e1e53baa2ea4a32b5fcac4abda64bd8/work/tmp/ansible.ki82s94r) 2025-10-13 09:37:29.858334 | localhost | ok: Runtime: 0:00:00.014171 2025-10-13 09:37:29.863274 | 2025-10-13 09:37:29.863397 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 09:37:30.199965 | localhost | ok: Runtime: 0:00:00.006652 2025-10-13 09:37:30.205638 | 2025-10-13 09:37:30.205715 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 09:37:30.270655 | localhost | changed 2025-10-13 09:37:30.280772 | 2025-10-13 09:37:30.280917 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 09:37:30.741437 | localhost | changed 2025-10-13 09:37:30.762238 | 2025-10-13 09:37:30.762334 | PLAY [localhost] 2025-10-13 09:37:30.775523 | 2025-10-13 09:37:30.775617 | TASK [Generate bulk log download script] 2025-10-13 09:37:30.794837 | localhost | ok 2025-10-13 09:37:30.807532 | 2025-10-13 09:37:30.807633 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 09:37:30.855946 | localhost | ok: All assertions passed 2025-10-13 09:37:30.860518 | 2025-10-13 09:37:30.860581 | TASK [local-log-download : Create download script] 2025-10-13 09:37:31.323031 | localhost -> localhost | changed 2025-10-13 09:37:31.331856 | 2025-10-13 09:37:31.331936 | TASK [Register quick-download link] 2025-10-13 09:37:31.360838 | localhost | ok 2025-10-13 09:37:31.402255 | 2025-10-13 09:37:31.402371 | PLAY [logserver.rdoproject.org] 2025-10-13 09:37:31.411989 | 2025-10-13 09:37:31.412089 | TASK [Set zuul-log-path fact] 2025-10-13 09:37:31.430615 | logserver.rdoproject.org | ok 2025-10-13 09:37:31.440472 | 2025-10-13 09:37:31.440618 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 09:37:31.479973 | logserver.rdoproject.org | ok 2025-10-13 09:37:31.486137 | 2025-10-13 09:37:31.486228 | TASK [upload-logs : Create log directories] 2025-10-13 09:37:32.203531 | logserver.rdoproject.org | changed 2025-10-13 09:37:32.211663 | 2025-10-13 09:37:32.211818 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 09:37:32.548007 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009443 2025-10-13 09:37:32.554240 | 2025-10-13 09:37:32.554334 | TASK [upload-logs : Upload logs to log server] 2025-10-13 09:37:33.285106 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 09:37:33.294341 | 2025-10-13 09:37:33.294477 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 09:37:33.365943 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:37:33.378794 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:37:33.391425 | 2025-10-13 09:37:33.391647 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 09:37:33.443133 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:37:33.443430 | 2025-10-13 09:37:33.447377 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:37:33.458534 | 2025-10-13 09:37:33.458747 | LOOP [upload-logs : Upload console log and json output]