2025-10-08 05:36:59.550843 | Job console starting... 2025-10-08 05:36:59.563325 | Updating repositories 2025-10-08 05:36:59.599320 | Preparing job workspace 2025-10-08 05:37:03.888021 | Running Ansible setup... 2025-10-08 05:37:08.119425 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 05:37:08.947687 | 2025-10-08 05:37:08.947890 | PLAY [localhost] 2025-10-08 05:37:08.957306 | 2025-10-08 05:37:08.957399 | TASK [Gathering Facts] 2025-10-08 05:37:09.972737 | localhost | ok 2025-10-08 05:37:09.986624 | 2025-10-08 05:37:09.986722 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 05:37:10.440808 | localhost -> localhost | changed 2025-10-08 05:37:10.446930 | 2025-10-08 05:37:10.447018 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 05:37:11.819052 | localhost -> localhost | changed 2025-10-08 05:37:11.827599 | 2025-10-08 05:37:11.827678 | TASK [Setup log path fact] 2025-10-08 05:37:11.871925 | localhost | ok 2025-10-08 05:37:11.888057 | 2025-10-08 05:37:11.888164 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 05:37:11.926374 | localhost | ok 2025-10-08 05:37:11.934014 | 2025-10-08 05:37:11.934082 | TASK [emit-job-header : Print job information] 2025-10-08 05:37:11.991919 | # Job Information 2025-10-08 05:37:11.992089 | Ansible Version: 2.15.12 2025-10-08 05:37:11.992139 | Job: cifmw-molecule-cifmw_helpers 2025-10-08 05:37:11.992164 | Pipeline: github-check 2025-10-08 05:37:11.992185 | Executor: ze03.softwarefactory-project.io 2025-10-08 05:37:11.992206 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-08 05:37:11.992227 | Log URL (when completed): https://logserver.rdoproject.org/fee/rdoproject.org/fee6f62626ed4d8f9a2983fc99ad02ca/ 2025-10-08 05:37:11.992247 | Event ID: 920c7930-a408-11f0-96e0-244f77bacc6d 2025-10-08 05:37:11.996893 | 2025-10-08 05:37:11.996957 | LOOP [emit-job-header : Print node information] 2025-10-08 05:37:12.093109 | localhost | ok: 2025-10-08 05:37:12.093274 | localhost | # Node Information 2025-10-08 05:37:12.093302 | localhost | Inventory Hostname: controller 2025-10-08 05:37:12.093325 | localhost | Hostname: np0005475237 2025-10-08 05:37:12.093346 | localhost | Username: zuul 2025-10-08 05:37:12.093367 | localhost | Distro: CentOS 9 2025-10-08 05:37:12.093385 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 05:37:12.093404 | localhost | Region: RegionOne 2025-10-08 05:37:12.093423 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 05:37:12.093444 | localhost | Product Name: OpenStack Nova 2025-10-08 05:37:12.093460 | localhost | Interface IP: 38.102.83.80 2025-10-08 05:37:12.151241 | 2025-10-08 05:37:12.151363 | PLAY [all] 2025-10-08 05:37:12.159254 | 2025-10-08 05:37:12.159317 | TASK [Gather network facts] 2025-10-08 05:37:12.708512 | controller | ok 2025-10-08 05:37:12.729272 | 2025-10-08 05:37:12.729396 | TASK [include_role : start-zuul-console] 2025-10-08 05:37:12.747188 | controller | ok 2025-10-08 05:37:12.760202 | 2025-10-08 05:37:12.760299 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 05:37:13.213428 | controller | ok 2025-10-08 05:37:13.227896 | 2025-10-08 05:37:13.228025 | TASK [include_role : add-build-sshkey] 2025-10-08 05:37:13.282239 | controller | ok 2025-10-08 05:37:13.297315 | 2025-10-08 05:37:13.297410 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 05:37:13.612619 | controller -> localhost | ok 2025-10-08 05:37:13.619052 | 2025-10-08 05:37:13.619118 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 05:37:13.639968 | controller | ok 2025-10-08 05:37:13.658257 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 05:37:13.663987 | 2025-10-08 05:37:13.664047 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 05:37:14.379311 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 05:37:14.379504 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/fee6f62626ed4d8f9a2983fc99ad02ca_id_rsa. 2025-10-08 05:37:14.379535 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/fee6f62626ed4d8f9a2983fc99ad02ca_id_rsa.pub. 2025-10-08 05:37:14.379574 | controller -> localhost | The key fingerprint is: 2025-10-08 05:37:14.379595 | controller -> localhost | SHA256:IZzVWXx58Ti5XfuRQUSV7ezs0RZjl8nBj93hX1Pa04s zuul-build-sshkey 2025-10-08 05:37:14.379615 | controller -> localhost | The key's randomart image is: 2025-10-08 05:37:14.379634 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 05:37:14.379652 | controller -> localhost | | .. +. +**| 2025-10-08 05:37:14.379670 | controller -> localhost | | . o o . +B=| 2025-10-08 05:37:14.379688 | controller -> localhost | | + . .*X%| 2025-10-08 05:37:14.379707 | controller -> localhost | | . . o#/| 2025-10-08 05:37:14.379738 | controller -> localhost | | S +*%| 2025-10-08 05:37:14.379762 | controller -> localhost | | E oO| 2025-10-08 05:37:14.379781 | controller -> localhost | | oo| 2025-10-08 05:37:14.379799 | controller -> localhost | | .| 2025-10-08 05:37:14.379816 | controller -> localhost | | | 2025-10-08 05:37:14.379833 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 05:37:14.379877 | controller -> localhost | ok: Runtime: 0:00:00.296724 2025-10-08 05:37:14.397269 | 2025-10-08 05:37:14.397351 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 05:37:14.462130 | controller | ok 2025-10-08 05:37:14.484820 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 05:37:14.516301 | 2025-10-08 05:37:14.516428 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 05:37:14.558257 | controller | skipping: Conditional result was False 2025-10-08 05:37:14.564043 | 2025-10-08 05:37:14.564108 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 05:37:15.181730 | controller | changed 2025-10-08 05:37:15.187439 | 2025-10-08 05:37:15.187524 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 05:37:15.462129 | controller | ok 2025-10-08 05:37:15.539519 | 2025-10-08 05:37:15.539653 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 05:37:16.609578 | controller | changed 2025-10-08 05:37:16.615291 | 2025-10-08 05:37:16.615394 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 05:37:17.603914 | controller | changed 2025-10-08 05:37:17.612447 | 2025-10-08 05:37:17.612550 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 05:37:17.635623 | controller | skipping: Conditional result was False 2025-10-08 05:37:17.645544 | 2025-10-08 05:37:17.645651 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 05:37:18.017674 | controller -> localhost | changed 2025-10-08 05:37:18.029043 | 2025-10-08 05:37:18.029128 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 05:37:18.289622 | controller -> localhost | Identity added: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/fee6f62626ed4d8f9a2983fc99ad02ca_id_rsa (zuul-build-sshkey) 2025-10-08 05:37:18.289848 | controller -> localhost | ok: Runtime: 0:00:00.010883 2025-10-08 05:37:18.295327 | 2025-10-08 05:37:18.295391 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 05:37:18.678094 | controller | ok 2025-10-08 05:37:18.683575 | 2025-10-08 05:37:18.683651 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 05:37:18.708162 | controller | skipping: Conditional result was False 2025-10-08 05:37:18.717746 | 2025-10-08 05:37:18.717812 | TASK [include_role : validate-host] 2025-10-08 05:37:18.736067 | controller | ok 2025-10-08 05:37:18.754693 | 2025-10-08 05:37:18.754785 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 05:37:18.783111 | controller | ok 2025-10-08 05:37:18.789030 | 2025-10-08 05:37:18.789096 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 05:37:19.075446 | controller -> localhost | ok 2025-10-08 05:37:19.080941 | 2025-10-08 05:37:19.081017 | TASK [validate-host : Collect information about the host] 2025-10-08 05:37:19.939484 | controller | ok 2025-10-08 05:37:19.963239 | 2025-10-08 05:37:19.963363 | TASK [validate-host : Sanitize hostname] 2025-10-08 05:37:20.032875 | controller | ok 2025-10-08 05:37:20.040174 | 2025-10-08 05:37:20.040287 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 05:37:20.525646 | controller -> localhost | changed 2025-10-08 05:37:20.531772 | 2025-10-08 05:37:20.531886 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 05:37:21.011876 | controller | ok 2025-10-08 05:37:21.016758 | 2025-10-08 05:37:21.016853 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 05:37:21.623207 | controller -> localhost | changed 2025-10-08 05:37:21.632589 | 2025-10-08 05:37:21.632654 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 05:37:21.645759 | controller | skipping: Conditional result was False 2025-10-08 05:37:21.651323 | 2025-10-08 05:37:21.651390 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 05:37:21.664983 | controller | skipping: Conditional result was False 2025-10-08 05:37:21.670487 | 2025-10-08 05:37:21.670557 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 05:37:21.981980 | controller | ok: "logs" 2025-10-08 05:37:21.982297 | controller | ok: All items complete 2025-10-08 05:37:21.990791 | 2025-10-08 05:37:22.226474 | controller | ok: "artifacts" 2025-10-08 05:37:22.492474 | controller | ok: "docs" 2025-10-08 05:37:22.506023 | 2025-10-08 05:37:22.506215 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 05:37:22.837183 | controller | changed: "logs" 2025-10-08 05:37:23.095385 | controller | changed: "artifacts" 2025-10-08 05:37:23.322358 | controller | changed: "docs" 2025-10-08 05:37:23.369544 | 2025-10-08 05:37:23.369665 | PLAY RECAP 2025-10-08 05:37:23.369752 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 05:37:23.369797 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 05:37:23.369824 | 2025-10-08 05:37:23.497186 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 05:37:23.498099 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 05:37:24.177503 | 2025-10-08 05:37:24.177633 | PLAY [localhost] 2025-10-08 05:37:24.193865 | 2025-10-08 05:37:24.193965 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 05:37:24.654777 | localhost | ok 2025-10-08 05:37:24.660448 | 2025-10-08 05:37:24.660574 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 05:37:25.451913 | localhost | changed 2025-10-08 05:37:25.475814 | 2025-10-08 05:37:25.476100 | PLAY [all] 2025-10-08 05:37:25.503901 | 2025-10-08 05:37:25.504117 | TASK [include_role : prepare-workspace] 2025-10-08 05:37:25.539195 | controller | ok 2025-10-08 05:37:25.561396 | 2025-10-08 05:37:25.561618 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 05:37:26.039362 | controller | ok 2025-10-08 05:37:26.049494 | 2025-10-08 05:37:26.049640 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 05:37:28.014560 | controller | Output suppressed because no_log was given 2025-10-08 05:37:28.025634 | 2025-10-08 05:37:28.025758 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 05:37:28.327813 | controller | changed: "logs" 2025-10-08 05:37:28.572924 | controller | changed: "artifacts" 2025-10-08 05:37:28.815360 | controller | changed: "docs" 2025-10-08 05:37:28.827389 | 2025-10-08 05:37:28.827862 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 05:37:29.134053 | controller | changed: "logs" 2025-10-08 05:37:29.134375 | controller | changed: All items complete 2025-10-08 05:37:29.134416 | 2025-10-08 05:37:29.393589 | controller | changed: "artifacts" 2025-10-08 05:37:29.653659 | controller | changed: "docs" 2025-10-08 05:37:29.668433 | 2025-10-08 05:37:29.668570 | TASK [Check if worker can sudo] 2025-10-08 05:37:30.699637 | controller | ok: Runtime: 0:00:00.045098 2025-10-08 05:37:30.707538 | 2025-10-08 05:37:30.707665 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 05:37:30.773986 | controller | skipping: Conditional result was False 2025-10-08 05:37:30.783562 | 2025-10-08 05:37:30.783665 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 05:37:30.879617 | controller | ok 2025-10-08 05:37:30.893301 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 05:37:30.944080 | 2025-10-08 05:37:30.944263 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 05:37:31.271627 | controller | ok 2025-10-08 05:37:31.285103 | 2025-10-08 05:37:31.285234 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 05:37:31.347154 | controller | ok: "/var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 05:37:31.361799 | 2025-10-08 05:37:31.361961 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 05:37:32.469788 | controller | changed 2025-10-08 05:37:32.486256 | 2025-10-08 05:37:32.486453 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 05:37:32.576663 | controller | ok: "/var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 05:37:32.577063 | controller | ok: All items complete 2025-10-08 05:37:32.577099 | 2025-10-08 05:37:32.637353 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 05:37:32.645073 | 2025-10-08 05:37:32.645172 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 05:37:33.786607 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 05:37:34.812459 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 05:37:34.825199 | 2025-10-08 05:37:34.825392 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 05:37:35.318557 | controller | changed: section and option added 2025-10-08 05:37:35.349748 | 2025-10-08 05:37:35.349908 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 05:37:36.213887 | controller | 29 files removed 2025-10-08 05:37:36.214300 | controller | ok: Item: dnf clean all Runtime: 0:00:00.503599 2025-10-08 05:37:36.214364 | controller | changed: All items complete 2025-10-08 05:37:36.214395 | 2025-10-08 05:37:46.557321 | 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-08 05:37:46.557429 | controller | DNF version: 4.14.0 2025-10-08 05:37:46.557453 | controller | cachedir: /var/cache/dnf 2025-10-08 05:37:46.557473 | controller | Making cache files for all metadata files. 2025-10-08 05:37:46.557492 | controller | baseos: has expired and will be refreshed. 2025-10-08 05:37:46.557509 | controller | appstream: has expired and will be refreshed. 2025-10-08 05:37:46.557526 | controller | crb: has expired and will be refreshed. 2025-10-08 05:37:46.557552 | controller | extras-common: has expired and will be refreshed. 2025-10-08 05:37:46.557569 | controller | repo: downloading from remote: baseos 2025-10-08 05:37:46.557585 | controller | CentOS Stream 9 - BaseOS 85 MB/s | 8.8 MB 00:00 2025-10-08 05:37:46.557603 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 05:37:46.557619 | controller | repo: downloading from remote: appstream 2025-10-08 05:37:46.557636 | controller | CentOS Stream 9 - AppStream 104 MB/s | 25 MB 00:00 2025-10-08 05:37:46.557652 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 05:37:46.557669 | controller | repo: downloading from remote: crb 2025-10-08 05:37:46.557685 | controller | CentOS Stream 9 - CRB 66 MB/s | 7.1 MB 00:00 2025-10-08 05:37:46.557702 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 05:37:46.557718 | controller | repo: downloading from remote: extras-common 2025-10-08 05:37:46.557792 | controller | CentOS Stream 9 - Extras packages 1.8 MB/s | 20 kB 00:00 2025-10-08 05:37:46.557812 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 05:37:46.557829 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 05:37:46.557845 | controller | Completion plugin: Generating completion cache... 2025-10-08 05:37:46.557862 | controller | Metadata cache created. 2025-10-08 05:37:46.557887 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.055690 2025-10-08 05:37:46.574892 | 2025-10-08 05:37:46.574979 | PLAY RECAP 2025-10-08 05:37:46.575179 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 05:37:46.575254 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 05:37:46.575281 | 2025-10-08 05:37:46.856654 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 05:37:46.857692 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 05:37:47.487922 | 2025-10-08 05:37:47.488041 | PLAY [all] 2025-10-08 05:37:47.511981 | 2025-10-08 05:37:47.512070 | TASK [Install binary dependencies] 2025-10-08 05:37:47.572912 | controller | ok 2025-10-08 05:37:47.606692 | 2025-10-08 05:37:47.606887 | TASK [bindep : Include find tasks] 2025-10-08 05:37:47.646485 | controller | ok 2025-10-08 05:37:47.659681 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 05:37:47.674447 | 2025-10-08 05:37:47.674517 | TASK [bindep : Look for bindep.txt] 2025-10-08 05:37:48.276676 | controller | ok 2025-10-08 05:37:48.285712 | 2025-10-08 05:37:48.288120 | TASK [bindep : Define bindep_file fact] 2025-10-08 05:37:48.320933 | controller | ok 2025-10-08 05:37:48.330912 | 2025-10-08 05:37:48.331262 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 05:37:48.388384 | controller | skipping: Conditional result was False 2025-10-08 05:37:48.395164 | 2025-10-08 05:37:48.395247 | TASK [bindep : Define bindep_file fact] 2025-10-08 05:37:48.435945 | controller | skipping: Conditional result was False 2025-10-08 05:37:48.450764 | 2025-10-08 05:37:48.450857 | TASK [bindep : Look for bindep fallback file] 2025-10-08 05:37:48.489026 | controller | skipping: Conditional result was False 2025-10-08 05:37:48.495814 | 2025-10-08 05:37:48.495901 | TASK [bindep : Define bindep_file fact] 2025-10-08 05:37:48.531301 | controller | skipping: Conditional result was False 2025-10-08 05:37:48.543397 | 2025-10-08 05:37:48.543546 | TASK [bindep : Include bindep tasks] 2025-10-08 05:37:48.583938 | controller | ok 2025-10-08 05:37:48.590939 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 05:37:48.599044 | 2025-10-08 05:37:48.599106 | TASK [bindep : Look for bindep command] 2025-10-08 05:37:48.629378 | controller | skipping: Conditional result was False 2025-10-08 05:37:48.637630 | 2025-10-08 05:37:48.637713 | TASK [bindep : Check for system bindep] 2025-10-08 05:37:49.173855 | controller | ok: Runtime: 0:00:00.010466 2025-10-08 05:37:49.181437 | 2025-10-08 05:37:49.181534 | TASK [bindep : Define bindep_command fact] 2025-10-08 05:37:49.227903 | controller | skipping: Conditional result was False 2025-10-08 05:37:49.235330 | 2025-10-08 05:37:49.235410 | TASK [bindep : Include install tasks] 2025-10-08 05:37:49.267619 | controller | ok 2025-10-08 05:37:49.285287 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 05:37:49.321594 | 2025-10-08 05:37:49.321771 | TASK [bindep : Create temp dir for bindep] 2025-10-08 05:37:49.865644 | controller | changed 2025-10-08 05:37:49.871506 | 2025-10-08 05:37:49.871586 | TASK [Ensure we have pip dependencies] 2025-10-08 05:37:49.891806 | controller | ok 2025-10-08 05:37:49.929260 | 2025-10-08 05:37:49.929400 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 01:37:50.276411 | controller | /usr/bin/pip3 2025-10-08 01:37:50.321964 | controller | /usr/bin/python3: No module named wheel 2025-10-08 05:37:50.463876 | controller | ok: Runtime: 0:00:00.063375 2025-10-08 05:37:50.469892 | 2025-10-08 05:37:50.469965 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 05:37:50.519238 | controller | ok: "/var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 05:37:50.580330 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 05:37:50.615593 | 2025-10-08 05:37:50.615804 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 05:37:53.244180 | controller | changed 2025-10-08 05:37:53.255273 | 2025-10-08 05:37:53.255346 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 05:37:53.304703 | controller | skipping: Conditional result was False 2025-10-08 05:37:53.312034 | 2025-10-08 05:37:53.312101 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 05:37:53.348196 | controller | skipping: Conditional result was False 2025-10-08 05:37:53.357519 | 2025-10-08 05:37:53.357617 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 05:37:53.408215 | controller | skipping: Conditional result was False 2025-10-08 05:37:53.415520 | 2025-10-08 05:37:53.415614 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 05:37:53.432808 | controller | skipping: Conditional result was False 2025-10-08 05:37:53.439959 | 2025-10-08 05:37:53.440045 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 05:37:53.975708 | controller | skipping: Conditional result was False 2025-10-08 05:37:53.994661 | 2025-10-08 05:37:53.995450 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 05:37:54.042981 | controller | skipping: Conditional result was False 2025-10-08 05:37:54.064299 | 2025-10-08 05:37:54.064411 | TASK [ensure-pip : Install pip from source] 2025-10-08 05:37:54.128706 | controller | skipping: Conditional result was False 2025-10-08 05:37:54.135255 | 2025-10-08 05:37:54.135328 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 01:37:54.450710 | controller | /usr/bin/python3 2025-10-08 05:37:54.670139 | controller | ok: Runtime: 0:00:00.007666 2025-10-08 05:37:54.676256 | 2025-10-08 05:37:54.676318 | TASK [ensure-pip : Set host default] 2025-10-08 05:37:54.777482 | controller | ok 2025-10-08 05:37:54.783037 | 2025-10-08 05:37:54.783104 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 05:37:54.871272 | controller | ok 2025-10-08 05:37:54.882009 | 2025-10-08 05:37:54.882071 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 05:37:59.059874 | controller | changed 2025-10-08 05:37:59.065870 | 2025-10-08 05:37:59.065941 | TASK [bindep : Define bindep_command] 2025-10-08 05:37:59.117800 | controller | ok 2025-10-08 05:37:59.123030 | 2025-10-08 05:37:59.123094 | LOOP [bindep : Include package tasks] 2025-10-08 05:37:59.229785 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 05:37:59.230033 | controller | ok: All items complete 2025-10-08 05:37:59.230068 | 2025-10-08 05:37:59.239268 | controller | included: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 05:37:59.249842 | 2025-10-08 05:37:59.249908 | TASK [bindep : Define bindep_run fact] 2025-10-08 05:37:59.279925 | controller | ok 2025-10-08 05:37:59.289271 | 2025-10-08 05:37:59.289353 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 01:38:00.932667 | controller | podman 2025-10-08 01:38:00.972326 | controller | python3-jmespath 2025-10-08 01:38:00.972523 | controller | python3-libvirt 2025-10-08 01:38:00.972541 | controller | python3-lxml 2025-10-08 01:38:00.972556 | controller | python3-netaddr 2025-10-08 05:38:01.329220 | controller | ok: Runtime: 0:00:01.362464 2025-10-08 05:38:01.335601 | 2025-10-08 05:38:01.335672 | TASK [bindep : Install distro packages from bindep] 2025-10-08 05:39:02.309596 | controller | changed 2025-10-08 05:39:02.323027 | 2025-10-08 05:39:02.323233 | TASK [bindep : Check that packages are installed] 2025-10-08 05:39:04.369597 | controller | ok: Runtime: 0:00:01.265556 2025-10-08 05:39:04.378718 | 2025-10-08 05:39:04.378922 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 05:39:04.405040 | controller | skipping: Conditional result was False 2025-10-08 05:39:04.419277 | 2025-10-08 05:39:04.419429 | TASK [Run test-setup role] 2025-10-08 05:39:04.444371 | controller | ok 2025-10-08 05:39:04.470810 | 2025-10-08 05:39:04.470967 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 05:39:04.749818 | controller | ok 2025-10-08 05:39:04.758156 | 2025-10-08 05:39:04.758263 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 05:39:05.305150 | controller | skipping: Conditional result was False 2025-10-08 05:39:05.334281 | 2025-10-08 05:39:05.334492 | TASK [bindep : Remove bindep temp dir] 2025-10-08 05:39:05.780023 | controller | ok 2025-10-08 05:39:05.795015 | 2025-10-08 05:39:05.795131 | PLAY RECAP 2025-10-08 05:39:05.795187 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 05:39:05.795217 | 2025-10-08 05:39:05.978267 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 05:39:05.980071 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 05:39:06.567376 | 2025-10-08 05:39:06.567482 | PLAY [all] 2025-10-08 05:39:06.586796 | 2025-10-08 05:39:06.586877 | TASK [Abort when test_command variable is undefined] 2025-10-08 05:39:06.621517 | controller | skipping: Conditional result was False 2025-10-08 05:39:06.627292 | 2025-10-08 05:39:06.627367 | TASK [Convert test_command to list] 2025-10-08 05:39:06.671265 | controller | skipping: Conditional result was False 2025-10-08 05:39:06.679887 | 2025-10-08 05:39:06.679976 | TASK [Use test_command list] 2025-10-08 05:39:06.740654 | controller | ok 2025-10-08 05:39:06.753389 | 2025-10-08 05:39:06.753484 | LOOP [Run test_command] 2025-10-08 05:39:07.165854 | controller | no check to run 2025-10-08 05:39:07.166142 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008689 2025-10-08 05:39:07.205044 | 2025-10-08 05:39:07.205265 | PLAY RECAP 2025-10-08 05:39:07.205323 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 05:39:07.205351 | 2025-10-08 05:39:07.307547 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 05:39:07.308510 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 05:39:07.877549 | 2025-10-08 05:39:07.877682 | PLAY [all] 2025-10-08 05:39:07.898163 | 2025-10-08 05:39:07.898252 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 05:39:08.390150 | controller | changed: non-zero return code 2025-10-08 05:39:08.403317 | 2025-10-08 05:39:08.403516 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 05:39:08.431125 | controller | skipping: Conditional result was False 2025-10-08 05:39:08.443791 | 2025-10-08 05:39:08.443947 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 05:39:08.485527 | 2025-10-08 05:39:08.485862 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 05:39:08.526248 | 2025-10-08 05:39:08.526521 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 05:39:08.567149 | controller | skipping: Conditional result was False 2025-10-08 05:39:08.576182 | 2025-10-08 05:39:08.576295 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 05:39:08.611488 | 2025-10-08 05:39:08.611697 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 05:39:08.636539 | controller | skipping: Conditional result was False 2025-10-08 05:39:08.644289 | 2025-10-08 05:39:08.644388 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 05:39:08.669334 | controller | skipping: Conditional result was False 2025-10-08 05:39:08.677977 | 2025-10-08 05:39:08.678084 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 05:39:08.702960 | controller | skipping: Conditional result was False 2025-10-08 05:39:08.727806 | 2025-10-08 05:39:08.727884 | PLAY RECAP 2025-10-08 05:39:08.727931 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 05:39:08.727959 | 2025-10-08 05:39:08.831632 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 05:39:08.832581 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 05:39:09.438130 | 2025-10-08 05:39:09.438288 | PLAY [all] 2025-10-08 05:39:09.458758 | 2025-10-08 05:39:09.458925 | TASK [include_role : fetch-output] 2025-10-08 05:39:09.509690 | controller | ok 2025-10-08 05:39:09.528142 | 2025-10-08 05:39:09.528358 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 05:39:09.584522 | controller | skipping: Conditional result was False 2025-10-08 05:39:09.595399 | 2025-10-08 05:39:09.595537 | TASK [fetch-output : Set log path for single node] 2025-10-08 05:39:09.631009 | controller | ok 2025-10-08 05:39:09.639217 | 2025-10-08 05:39:09.639346 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 05:39:10.085072 | controller -> localhost | ok: "/var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/logs" 2025-10-08 05:39:10.300299 | controller -> localhost | changed: "/var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/artifacts" 2025-10-08 05:39:10.514906 | controller -> localhost | changed: "/var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/docs" 2025-10-08 05:39:10.528806 | 2025-10-08 05:39:10.528952 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 05:39:11.225296 | controller | changed: .d..t...... ./ 2025-10-08 05:39:11.225528 | controller | changed: All items complete 2025-10-08 05:39:11.225556 | 2025-10-08 05:39:11.713828 | controller | changed: .d..t...... ./ 2025-10-08 05:39:12.238166 | controller | changed: .d..t...... ./ 2025-10-08 05:39:12.270775 | 2025-10-08 05:39:12.270929 | TASK [include_role : fetch-output-openshift] 2025-10-08 05:39:12.296007 | controller | skipping: Conditional result was False 2025-10-08 05:39:12.304560 | 2025-10-08 05:39:12.304654 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 05:39:12.835185 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013570 2025-10-08 05:39:13.136975 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013350 2025-10-08 05:39:13.175949 | 2025-10-08 05:39:13.176126 | PLAY [all] 2025-10-08 05:39:13.196747 | 2025-10-08 05:39:13.196864 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 05:39:13.694098 | controller | changed 2025-10-08 05:39:13.738246 | 2025-10-08 05:39:13.738379 | PLAY RECAP 2025-10-08 05:39:13.738441 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 05:39:13.738470 | 2025-10-08 05:39:13.859506 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 05:39:13.860487 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 05:39:14.552630 | 2025-10-08 05:39:14.552813 | PLAY [localhost] 2025-10-08 05:39:14.572104 | 2025-10-08 05:39:14.572225 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 05:39:15.030766 | localhost | changed 2025-10-08 05:39:15.036001 | 2025-10-08 05:39:15.036131 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 05:39:15.066366 | localhost | ok 2025-10-08 05:39:15.074776 | 2025-10-08 05:39:15.074853 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 05:39:15.472176 | localhost | changed 2025-10-08 05:39:15.489145 | 2025-10-08 05:39:15.489467 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 05:39:16.199301 | localhost | changed 2025-10-08 05:39:16.205151 | 2025-10-08 05:39:16.205223 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 05:39:16.627221 | localhost | Identity added: /var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/tmp/ansible.95njdssl (/var/lib/zuul/builds/fee6f62626ed4d8f9a2983fc99ad02ca/work/tmp/ansible.95njdssl) 2025-10-08 05:39:16.627477 | localhost | ok: Runtime: 0:00:00.010986 2025-10-08 05:39:16.639347 | 2025-10-08 05:39:16.639561 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 05:39:16.901241 | localhost | ok: Runtime: 0:00:00.007339 2025-10-08 05:39:16.906538 | 2025-10-08 05:39:16.906605 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 05:39:16.971548 | localhost | changed 2025-10-08 05:39:16.981849 | 2025-10-08 05:39:16.982042 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 05:39:17.431047 | localhost | changed 2025-10-08 05:39:17.486242 | 2025-10-08 05:39:17.486371 | PLAY [localhost] 2025-10-08 05:39:17.499273 | 2025-10-08 05:39:17.499334 | TASK [Generate bulk log download script] 2025-10-08 05:39:17.517861 | localhost | ok 2025-10-08 05:39:17.529599 | 2025-10-08 05:39:17.529664 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 05:39:17.568213 | localhost | ok: All assertions passed 2025-10-08 05:39:17.573314 | 2025-10-08 05:39:17.573412 | TASK [local-log-download : Create download script] 2025-10-08 05:39:17.985879 | localhost -> localhost | changed 2025-10-08 05:39:17.996131 | 2025-10-08 05:39:17.996287 | TASK [Register quick-download link] 2025-10-08 05:39:18.019306 | localhost | ok 2025-10-08 05:39:18.071940 | 2025-10-08 05:39:18.072084 | PLAY [logserver.rdoproject.org] 2025-10-08 05:39:18.082844 | 2025-10-08 05:39:18.082971 | TASK [Set zuul-log-path fact] 2025-10-08 05:39:18.101081 | logserver.rdoproject.org | ok 2025-10-08 05:39:18.111192 | 2025-10-08 05:39:18.111306 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 05:39:18.149333 | logserver.rdoproject.org | ok 2025-10-08 05:39:18.155139 | 2025-10-08 05:39:18.155233 | TASK [upload-logs : Create log directories] 2025-10-08 05:39:18.829388 | logserver.rdoproject.org | changed 2025-10-08 05:39:18.836247 | 2025-10-08 05:39:18.836323 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 05:39:19.108192 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.010774 2025-10-08 05:39:19.114153 | 2025-10-08 05:39:19.114256 | TASK [upload-logs : Upload logs to log server] 2025-10-08 05:39:19.901494 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 05:39:19.907973 | 2025-10-08 05:39:19.908150 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 05:39:19.979115 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:39:19.992698 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:39:20.003775 | 2025-10-08 05:39:20.003984 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 05:39:20.057812 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:39:20.058277 | 2025-10-08 05:39:20.061441 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:39:20.080660 | 2025-10-08 05:39:20.080851 | LOOP [upload-logs : Upload console log and json output]