2025-10-07 15:36:46.441834 | Job console starting... 2025-10-07 15:36:46.453650 | Updating repositories 2025-10-07 15:36:46.501149 | Preparing job workspace 2025-10-07 15:36:50.723628 | Running Ansible setup... 2025-10-07 15:36:54.634695 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 15:36:55.588516 | 2025-10-07 15:36:55.588671 | PLAY [localhost] 2025-10-07 15:36:55.628941 | 2025-10-07 15:36:55.629165 | TASK [Gathering Facts] 2025-10-07 15:36:56.774366 | localhost | ok 2025-10-07 15:36:56.792708 | 2025-10-07 15:36:56.792886 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-07 15:36:57.300410 | localhost -> localhost | changed 2025-10-07 15:36:57.306779 | 2025-10-07 15:36:57.306851 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-07 15:36:59.174785 | localhost -> localhost | changed 2025-10-07 15:36:59.185686 | 2025-10-07 15:36:59.185794 | TASK [Setup log path fact] 2025-10-07 15:36:59.244942 | localhost | ok 2025-10-07 15:36:59.268676 | 2025-10-07 15:36:59.268819 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 15:36:59.318274 | localhost | ok 2025-10-07 15:36:59.337186 | 2025-10-07 15:36:59.337293 | TASK [emit-job-header : Print job information] 2025-10-07 15:36:59.396007 | # Job Information 2025-10-07 15:36:59.396183 | Ansible Version: 2.15.12 2025-10-07 15:36:59.396211 | Job: cifmw-molecule-ipa 2025-10-07 15:36:59.396231 | Pipeline: github-check 2025-10-07 15:36:59.396249 | Executor: ze03.softwarefactory-project.io 2025-10-07 15:36:59.396266 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368 2025-10-07 15:36:59.396284 | Log URL (when completed): https://logserver.rdoproject.org/532/rdoproject.org/532a2f9a5c154b2db557dffbe28f94c2/ 2025-10-07 15:36:59.396302 | Event ID: 3bf07620-a393-11f0-9221-eb052759ad8c 2025-10-07 15:36:59.401153 | 2025-10-07 15:36:59.401229 | LOOP [emit-job-header : Print node information] 2025-10-07 15:36:59.633176 | localhost | ok: 2025-10-07 15:36:59.633441 | localhost | # Node Information 2025-10-07 15:36:59.633477 | localhost | Inventory Hostname: controller 2025-10-07 15:36:59.633505 | localhost | Hostname: np0005474522 2025-10-07 15:36:59.633527 | localhost | Username: zuul 2025-10-07 15:36:59.633549 | localhost | Distro: CentOS 9 2025-10-07 15:36:59.633569 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-07 15:36:59.633589 | localhost | Region: RegionOne 2025-10-07 15:36:59.633609 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-07 15:36:59.633630 | localhost | Product Name: OpenStack Nova 2025-10-07 15:36:59.633649 | localhost | Interface IP: 38.102.83.75 2025-10-07 15:36:59.711962 | 2025-10-07 15:36:59.712076 | PLAY [all] 2025-10-07 15:36:59.735190 | 2025-10-07 15:36:59.735313 | TASK [Gather network facts] 2025-10-07 15:37:00.340050 | controller | ok 2025-10-07 15:37:00.376256 | 2025-10-07 15:37:00.376386 | TASK [include_role : start-zuul-console] 2025-10-07 15:37:00.420279 | controller | ok 2025-10-07 15:37:00.452172 | 2025-10-07 15:37:00.452301 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-07 15:37:00.924171 | controller | ok 2025-10-07 15:37:00.934392 | 2025-10-07 15:37:00.934481 | TASK [include_role : add-build-sshkey] 2025-10-07 15:37:00.970526 | controller | ok 2025-10-07 15:37:01.007036 | 2025-10-07 15:37:01.007173 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-07 15:37:01.564842 | controller -> localhost | ok 2025-10-07 15:37:01.570674 | 2025-10-07 15:37:01.570762 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-07 15:37:01.632167 | controller | ok 2025-10-07 15:37:01.665675 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-07 15:37:01.699155 | 2025-10-07 15:37:01.699289 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-07 15:37:02.695564 | controller -> localhost | Generating public/private rsa key pair. 2025-10-07 15:37:02.695826 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/532a2f9a5c154b2db557dffbe28f94c2_id_rsa. 2025-10-07 15:37:02.695860 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/532a2f9a5c154b2db557dffbe28f94c2_id_rsa.pub. 2025-10-07 15:37:02.695884 | controller -> localhost | The key fingerprint is: 2025-10-07 15:37:02.695904 | controller -> localhost | SHA256:eLlfzNiKSKeVPnpa7bRI2omW8eArlxKo+J8nZoDHmzg zuul-build-sshkey 2025-10-07 15:37:02.695923 | controller -> localhost | The key's randomart image is: 2025-10-07 15:37:02.695943 | controller -> localhost | +---[RSA 3072]----+ 2025-10-07 15:37:02.695962 | controller -> localhost | | | 2025-10-07 15:37:02.695982 | controller -> localhost | | | 2025-10-07 15:37:02.696000 | controller -> localhost | | | 2025-10-07 15:37:02.696020 | controller -> localhost | | . . | 2025-10-07 15:37:02.696040 | controller -> localhost | | o . . S | 2025-10-07 15:37:02.696076 | controller -> localhost | |. = . o. + = | 2025-10-07 15:37:02.696098 | controller -> localhost | |.+ + o.*B + = | 2025-10-07 15:37:02.696117 | controller -> localhost | |E o *oB%+B + | 2025-10-07 15:37:02.696135 | controller -> localhost | | o.+oBO=*.= | 2025-10-07 15:37:02.696157 | controller -> localhost | +----[SHA256]-----+ 2025-10-07 15:37:02.696207 | controller -> localhost | ok: Runtime: 0:00:00.494880 2025-10-07 15:37:02.702322 | 2025-10-07 15:37:02.702431 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-07 15:37:02.767307 | controller | ok 2025-10-07 15:37:02.786560 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-07 15:37:02.803654 | 2025-10-07 15:37:02.805393 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-07 15:37:02.875618 | controller | skipping: Conditional result was False 2025-10-07 15:37:02.882304 | 2025-10-07 15:37:02.882388 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-07 15:37:03.439468 | controller | changed 2025-10-07 15:37:03.464084 | 2025-10-07 15:37:03.464198 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-07 15:37:03.860338 | controller | ok 2025-10-07 15:37:03.868105 | 2025-10-07 15:37:03.868273 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-07 15:37:04.749812 | controller | changed 2025-10-07 15:37:04.761518 | 2025-10-07 15:37:04.761656 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-07 15:37:05.697435 | controller | changed 2025-10-07 15:37:05.708342 | 2025-10-07 15:37:05.708478 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-07 15:37:05.773287 | controller | skipping: Conditional result was False 2025-10-07 15:37:05.781425 | 2025-10-07 15:37:05.781512 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-07 15:37:06.624472 | controller -> localhost | changed 2025-10-07 15:37:06.638080 | 2025-10-07 15:37:06.638203 | TASK [add-build-sshkey : Add back temp key] 2025-10-07 15:37:07.027456 | controller -> localhost | Identity added: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/532a2f9a5c154b2db557dffbe28f94c2_id_rsa (zuul-build-sshkey) 2025-10-07 15:37:07.027666 | controller -> localhost | ok: Runtime: 0:00:00.010812 2025-10-07 15:37:07.035374 | 2025-10-07 15:37:07.035457 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-07 15:37:07.494941 | controller | ok 2025-10-07 15:37:07.502796 | 2025-10-07 15:37:07.502924 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-07 15:37:07.592642 | controller | skipping: Conditional result was False 2025-10-07 15:37:07.607531 | 2025-10-07 15:37:07.607658 | TASK [include_role : validate-host] 2025-10-07 15:37:07.693752 | controller | ok 2025-10-07 15:37:07.714444 | 2025-10-07 15:37:07.714552 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-07 15:37:07.765473 | controller | ok 2025-10-07 15:37:07.770910 | 2025-10-07 15:37:07.770994 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-07 15:37:08.264013 | controller -> localhost | ok 2025-10-07 15:37:08.271649 | 2025-10-07 15:37:08.271791 | TASK [validate-host : Collect information about the host] 2025-10-07 15:37:08.963617 | controller | ok 2025-10-07 15:37:08.990211 | 2025-10-07 15:37:08.990337 | TASK [validate-host : Sanitize hostname] 2025-10-07 15:37:09.071781 | controller | ok 2025-10-07 15:37:09.085557 | 2025-10-07 15:37:09.085703 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-07 15:37:10.031411 | controller -> localhost | changed 2025-10-07 15:37:10.038339 | 2025-10-07 15:37:10.038468 | TASK [validate-host : Collect information about zuul worker] 2025-10-07 15:37:10.502569 | controller | ok 2025-10-07 15:37:10.509868 | 2025-10-07 15:37:10.509996 | TASK [validate-host : Write out all zuul information for each host] 2025-10-07 15:37:11.093310 | controller -> localhost | changed 2025-10-07 15:37:11.130307 | 2025-10-07 15:37:11.130440 | TASK [include_role : prepare-workspace-openshift] 2025-10-07 15:37:11.189360 | controller | skipping: Conditional result was False 2025-10-07 15:37:11.196377 | 2025-10-07 15:37:11.198323 | TASK [include_role : remove-zuul-sshkey] 2025-10-07 15:37:11.246718 | controller | skipping: Conditional result was False 2025-10-07 15:37:11.260627 | 2025-10-07 15:37:11.260776 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 15:37:11.532791 | controller | ok: "logs" 2025-10-07 15:37:11.533113 | controller | ok: All items complete 2025-10-07 15:37:11.533145 | 2025-10-07 15:37:11.728945 | controller | ok: "artifacts" 2025-10-07 15:37:11.987258 | controller | ok: "docs" 2025-10-07 15:37:11.996133 | 2025-10-07 15:37:11.996274 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 15:37:12.266921 | controller | changed: "logs" 2025-10-07 15:37:12.516281 | controller | changed: "artifacts" 2025-10-07 15:37:12.775585 | controller | changed: "docs" 2025-10-07 15:37:12.820525 | 2025-10-07 15:37:12.820634 | PLAY RECAP 2025-10-07 15:37:12.820683 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-07 15:37:12.820713 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 15:37:12.820763 | 2025-10-07 15:37:12.961813 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 15:37:12.962642 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 15:37:13.791986 | 2025-10-07 15:37:13.792135 | PLAY [localhost] 2025-10-07 15:37:13.817428 | 2025-10-07 15:37:13.817609 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-07 15:37:14.311429 | localhost | ok 2025-10-07 15:37:14.316548 | 2025-10-07 15:37:14.316627 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-07 15:37:15.145797 | localhost | changed 2025-10-07 15:37:15.218139 | 2025-10-07 15:37:15.218264 | PLAY [all] 2025-10-07 15:37:15.265546 | 2025-10-07 15:37:15.265686 | TASK [include_role : prepare-workspace] 2025-10-07 15:37:15.301184 | controller | ok 2025-10-07 15:37:15.319596 | 2025-10-07 15:37:15.319894 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-07 15:37:15.811203 | controller | ok 2025-10-07 15:37:15.828143 | 2025-10-07 15:37:15.828301 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-07 15:37:17.568309 | controller | Output suppressed because no_log was given 2025-10-07 15:37:17.584788 | 2025-10-07 15:37:17.584921 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 15:37:17.836408 | controller | changed: "logs" 2025-10-07 15:37:18.053473 | controller | changed: "artifacts" 2025-10-07 15:37:18.294962 | controller | changed: "docs" 2025-10-07 15:37:18.310557 | 2025-10-07 15:37:18.310708 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 15:37:18.561385 | controller | changed: "logs" 2025-10-07 15:37:18.561673 | controller | changed: All items complete 2025-10-07 15:37:18.561703 | 2025-10-07 15:37:18.842438 | controller | changed: "artifacts" 2025-10-07 15:37:19.065977 | controller | changed: "docs" 2025-10-07 15:37:19.088570 | 2025-10-07 15:37:19.088705 | TASK [Check if worker can sudo] 2025-10-07 15:37:19.625037 | controller | ok: Runtime: 0:00:00.067128 2025-10-07 15:37:19.631012 | 2025-10-07 15:37:19.631097 | TASK [configure-mirrors : Gather needed facts] 2025-10-07 15:37:19.688034 | controller | skipping: Conditional result was False 2025-10-07 15:37:19.696059 | 2025-10-07 15:37:19.696138 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-07 15:37:19.759978 | controller | ok 2025-10-07 15:37:19.767929 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-07 15:37:19.774189 | 2025-10-07 15:37:19.774256 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-07 15:37:20.146280 | controller | ok 2025-10-07 15:37:20.156586 | 2025-10-07 15:37:20.156806 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-07 15:37:20.219383 | controller | ok: "/var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-07 15:37:20.232800 | 2025-10-07 15:37:20.232918 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-07 15:37:21.107900 | controller | changed 2025-10-07 15:37:21.118143 | 2025-10-07 15:37:21.118303 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-07 15:37:21.208589 | controller | ok: "/var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-07 15:37:21.208864 | controller | ok: All items complete 2025-10-07 15:37:21.208898 | 2025-10-07 15:37:21.279012 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-07 15:37:21.289210 | 2025-10-07 15:37:21.289350 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-07 15:37:22.273961 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-07 15:37:23.038018 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-07 15:37:23.048101 | 2025-10-07 15:37:23.048212 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-07 15:37:23.495501 | controller | changed: section and option added 2025-10-07 15:37:23.517527 | 2025-10-07 15:37:23.517659 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-07 15:37:24.362834 | controller | 29 files removed 2025-10-07 15:37:24.363079 | controller | ok: Item: dnf clean all Runtime: 0:00:00.504925 2025-10-07 15:37:24.363120 | controller | changed: All items complete 2025-10-07 15:37:24.363142 | 2025-10-07 15:37:35.765073 | 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-07 15:37:35.765187 | controller | DNF version: 4.14.0 2025-10-07 15:37:35.765212 | controller | cachedir: /var/cache/dnf 2025-10-07 15:37:35.765231 | controller | Making cache files for all metadata files. 2025-10-07 15:37:35.765249 | controller | baseos: has expired and will be refreshed. 2025-10-07 15:37:35.765266 | controller | appstream: has expired and will be refreshed. 2025-10-07 15:37:35.765283 | controller | crb: has expired and will be refreshed. 2025-10-07 15:37:35.765310 | controller | extras-common: has expired and will be refreshed. 2025-10-07 15:37:35.765326 | controller | repo: downloading from remote: baseos 2025-10-07 15:37:35.765342 | controller | CentOS Stream 9 - BaseOS 88 MB/s | 8.8 MB 00:00 2025-10-07 15:37:35.765358 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-07 15:37:35.765374 | controller | repo: downloading from remote: appstream 2025-10-07 15:37:35.765389 | controller | CentOS Stream 9 - AppStream 108 MB/s | 25 MB 00:00 2025-10-07 15:37:35.765405 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-07 15:37:35.765420 | controller | repo: downloading from remote: crb 2025-10-07 15:37:35.765436 | controller | CentOS Stream 9 - CRB 58 MB/s | 7.1 MB 00:00 2025-10-07 15:37:35.765452 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-07 15:37:35.765467 | controller | repo: downloading from remote: extras-common 2025-10-07 15:37:35.765483 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-07 15:37:35.765499 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-07 15:37:35.765515 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-07 15:37:35.765531 | controller | Completion plugin: Generating completion cache... 2025-10-07 15:37:35.765546 | controller | Metadata cache created. 2025-10-07 15:37:35.765575 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.135278 2025-10-07 15:37:35.783771 | 2025-10-07 15:37:35.783868 | PLAY RECAP 2025-10-07 15:37:35.783912 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-07 15:37:35.783939 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 15:37:35.783959 | 2025-10-07 15:37:35.905021 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 15:37:35.906617 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 15:37:36.550541 | 2025-10-07 15:37:36.550657 | PLAY [all] 2025-10-07 15:37:36.571710 | 2025-10-07 15:37:36.571862 | TASK [Install binary dependencies] 2025-10-07 15:37:36.613717 | controller | ok 2025-10-07 15:37:36.639022 | 2025-10-07 15:37:36.639125 | TASK [bindep : Include find tasks] 2025-10-07 15:37:36.668687 | controller | ok 2025-10-07 15:37:36.676383 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-07 15:37:36.682466 | 2025-10-07 15:37:36.682530 | TASK [bindep : Look for bindep.txt] 2025-10-07 15:37:37.098149 | controller | ok 2025-10-07 15:37:37.115141 | 2025-10-07 15:37:37.115344 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:37:37.150537 | controller | ok 2025-10-07 15:37:37.159125 | 2025-10-07 15:37:37.159235 | TASK [bindep : Look for other-requirements.txt] 2025-10-07 15:37:37.195993 | controller | skipping: Conditional result was False 2025-10-07 15:37:37.205834 | 2025-10-07 15:37:37.206022 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:37:37.244081 | controller | skipping: Conditional result was False 2025-10-07 15:37:37.252958 | 2025-10-07 15:37:37.253115 | TASK [bindep : Look for bindep fallback file] 2025-10-07 15:37:37.289675 | controller | skipping: Conditional result was False 2025-10-07 15:37:37.296264 | 2025-10-07 15:37:37.296392 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:37:37.320922 | controller | skipping: Conditional result was False 2025-10-07 15:37:37.327707 | 2025-10-07 15:37:37.327861 | TASK [bindep : Include bindep tasks] 2025-10-07 15:37:37.369865 | controller | ok 2025-10-07 15:37:37.377504 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-07 15:37:37.387319 | 2025-10-07 15:37:37.387454 | TASK [bindep : Look for bindep command] 2025-10-07 15:37:37.413381 | controller | skipping: Conditional result was False 2025-10-07 15:37:37.421124 | 2025-10-07 15:37:37.421253 | TASK [bindep : Check for system bindep] 2025-10-07 15:37:37.960762 | controller | ok: Runtime: 0:00:00.007002 2025-10-07 15:37:37.967231 | 2025-10-07 15:37:37.967347 | TASK [bindep : Define bindep_command fact] 2025-10-07 15:37:37.993089 | controller | skipping: Conditional result was False 2025-10-07 15:37:38.000148 | 2025-10-07 15:37:38.000249 | TASK [bindep : Include install tasks] 2025-10-07 15:37:38.040967 | controller | ok 2025-10-07 15:37:38.049210 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-07 15:37:38.059943 | 2025-10-07 15:37:38.060076 | TASK [bindep : Create temp dir for bindep] 2025-10-07 15:37:38.465915 | controller | changed 2025-10-07 15:37:38.472624 | 2025-10-07 15:37:38.472776 | TASK [Ensure we have pip dependencies] 2025-10-07 15:37:38.493802 | controller | ok 2025-10-07 15:37:38.524350 | 2025-10-07 15:37:38.524493 | TASK [ensure-pip : Check if pip is installed] 2025-10-07 11:37:38.813953 | controller | /usr/bin/pip3 2025-10-07 11:37:38.834922 | controller | /usr/bin/python3: No module named wheel 2025-10-07 15:37:39.058576 | controller | ok: Runtime: 0:00:00.038741 2025-10-07 15:37:39.067591 | 2025-10-07 15:37:39.067710 | LOOP [ensure-pip : Install pip from packages] 2025-10-07 15:37:39.099061 | controller | ok: "/var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-07 15:37:39.117525 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-07 15:37:39.128704 | 2025-10-07 15:37:39.128847 | TASK [ensure-pip : Install Python 3 pip] 2025-10-07 15:37:41.783407 | controller | changed 2025-10-07 15:37:41.789999 | 2025-10-07 15:37:41.790118 | TASK [ensure-pip : Check for EPEL repository] 2025-10-07 15:37:41.826315 | controller | skipping: Conditional result was False 2025-10-07 15:37:41.834222 | 2025-10-07 15:37:41.834344 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-07 15:37:41.881372 | controller | skipping: Conditional result was False 2025-10-07 15:37:41.889554 | 2025-10-07 15:37:41.889703 | TASK [ensure-pip : Install Python 2 pip] 2025-10-07 15:37:41.936092 | controller | skipping: Conditional result was False 2025-10-07 15:37:41.943959 | 2025-10-07 15:37:41.953404 | TASK [ensure-pip : Ensure setuptools] 2025-10-07 15:37:41.994435 | controller | skipping: Conditional result was False 2025-10-07 15:37:42.003047 | 2025-10-07 15:37:42.003191 | TASK [ensure-pip : Check for ensurepip module] 2025-10-07 15:37:42.544467 | controller | skipping: Conditional result was False 2025-10-07 15:37:42.552091 | 2025-10-07 15:37:42.552213 | TASK [ensure-pip : Ensure python3-venv] 2025-10-07 15:37:42.569160 | controller | skipping: Conditional result was False 2025-10-07 15:37:42.577272 | 2025-10-07 15:37:42.577401 | TASK [ensure-pip : Install pip from source] 2025-10-07 15:37:42.603591 | controller | skipping: Conditional result was False 2025-10-07 15:37:42.610581 | 2025-10-07 15:37:42.610706 | TASK [ensure-pip : Probe for venv python full path] 2025-10-07 11:37:42.917361 | controller | /usr/bin/python3 2025-10-07 15:37:43.169288 | controller | ok: Runtime: 0:00:00.012759 2025-10-07 15:37:43.192717 | 2025-10-07 15:37:43.193017 | TASK [ensure-pip : Set host default] 2025-10-07 15:37:43.285734 | controller | ok 2025-10-07 15:37:43.293907 | 2025-10-07 15:37:43.293997 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-07 15:37:43.439757 | controller | ok 2025-10-07 15:37:43.477924 | 2025-10-07 15:37:43.478063 | TASK [bindep : Install bindep into temporary venv] 2025-10-07 15:37:48.197446 | controller | changed 2025-10-07 15:37:48.203492 | 2025-10-07 15:37:48.203625 | TASK [bindep : Define bindep_command] 2025-10-07 15:37:48.234448 | controller | ok 2025-10-07 15:37:48.240173 | 2025-10-07 15:37:48.240300 | LOOP [bindep : Include package tasks] 2025-10-07 15:37:48.317649 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-07 15:37:48.319860 | controller | ok: All items complete 2025-10-07 15:37:48.319940 | 2025-10-07 15:37:48.336462 | controller | included: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-07 15:37:48.348022 | 2025-10-07 15:37:48.348164 | TASK [bindep : Define bindep_run fact] 2025-10-07 15:37:48.378908 | controller | ok 2025-10-07 15:37:48.384532 | 2025-10-07 15:37:48.384661 | TASK [bindep : Get list of packages to install from bindep] 2025-10-07 11:37:50.117710 | controller | podman 2025-10-07 11:37:50.182018 | controller | python3-jmespath 2025-10-07 11:37:50.182262 | controller | python3-libvirt 2025-10-07 11:37:50.182284 | controller | python3-lxml 2025-10-07 11:37:50.182305 | controller | python3-netaddr 2025-10-07 15:37:50.424045 | controller | ok: Runtime: 0:00:01.500460 2025-10-07 15:37:50.429898 | 2025-10-07 15:37:50.429959 | TASK [bindep : Install distro packages from bindep] 2025-10-07 15:39:04.314184 | controller | changed 2025-10-07 15:39:04.330336 | 2025-10-07 15:39:04.330681 | TASK [bindep : Check that packages are installed] 2025-10-07 15:39:06.377881 | controller | ok: Runtime: 0:00:01.279346 2025-10-07 15:39:06.384809 | 2025-10-07 15:39:06.384893 | TASK [bindep : Fail if we cannot install all packages] 2025-10-07 15:39:06.409957 | controller | skipping: Conditional result was False 2025-10-07 15:39:06.420837 | 2025-10-07 15:39:06.420926 | TASK [Run test-setup role] 2025-10-07 15:39:06.440575 | controller | ok 2025-10-07 15:39:06.458356 | 2025-10-07 15:39:06.458472 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-07 15:39:06.729201 | controller | ok 2025-10-07 15:39:06.740062 | 2025-10-07 15:39:06.740198 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-07 15:39:07.288393 | controller | skipping: Conditional result was False 2025-10-07 15:39:07.332678 | 2025-10-07 15:39:07.332830 | TASK [bindep : Remove bindep temp dir] 2025-10-07 15:39:07.750250 | controller | ok 2025-10-07 15:39:07.771789 | 2025-10-07 15:39:07.771909 | PLAY RECAP 2025-10-07 15:39:07.771976 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-07 15:39:07.772017 | 2025-10-07 15:39:07.972320 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 15:39:07.973358 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 15:39:08.641425 | 2025-10-07 15:39:08.641568 | PLAY [all] 2025-10-07 15:39:08.663461 | 2025-10-07 15:39:08.663620 | TASK [Abort when test_command variable is undefined] 2025-10-07 15:39:08.708840 | controller | skipping: Conditional result was False 2025-10-07 15:39:08.717557 | 2025-10-07 15:39:08.717746 | TASK [Convert test_command to list] 2025-10-07 15:39:08.755858 | controller | skipping: Conditional result was False 2025-10-07 15:39:08.763619 | 2025-10-07 15:39:08.763775 | TASK [Use test_command list] 2025-10-07 15:39:08.829897 | controller | ok 2025-10-07 15:39:08.837137 | 2025-10-07 15:39:08.837252 | LOOP [Run test_command] 2025-10-07 15:39:09.307820 | controller | no check to run 2025-10-07 15:39:09.308013 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.009240 2025-10-07 15:39:09.361869 | 2025-10-07 15:39:09.361988 | PLAY RECAP 2025-10-07 15:39:09.362046 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 15:39:09.362075 | 2025-10-07 15:39:09.472266 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 15:39:09.473449 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 15:39:10.080635 | 2025-10-07 15:39:10.080792 | PLAY [all] 2025-10-07 15:39:10.103579 | 2025-10-07 15:39:10.103778 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-07 15:39:10.506323 | controller | changed: non-zero return code 2025-10-07 15:39:10.515237 | 2025-10-07 15:39:10.515353 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-07 15:39:10.541515 | controller | skipping: Conditional result was False 2025-10-07 15:39:10.547953 | 2025-10-07 15:39:10.548026 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-07 15:39:10.578194 | 2025-10-07 15:39:10.578332 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-07 15:39:10.608489 | 2025-10-07 15:39:10.608646 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-07 15:39:10.632851 | controller | skipping: Conditional result was False 2025-10-07 15:39:10.640157 | 2025-10-07 15:39:10.640334 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-07 15:39:10.674226 | 2025-10-07 15:39:10.674416 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-07 15:39:10.688690 | controller | skipping: Conditional result was False 2025-10-07 15:39:10.695660 | 2025-10-07 15:39:10.695817 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-07 15:39:10.720562 | controller | skipping: Conditional result was False 2025-10-07 15:39:10.726604 | 2025-10-07 15:39:10.726715 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-07 15:39:10.740748 | controller | skipping: Conditional result was False 2025-10-07 15:39:10.766642 | 2025-10-07 15:39:10.766787 | PLAY RECAP 2025-10-07 15:39:10.766832 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-07 15:39:10.766852 | 2025-10-07 15:39:10.878253 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 15:39:10.879550 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 15:39:11.479624 | 2025-10-07 15:39:11.479775 | PLAY [all] 2025-10-07 15:39:11.500134 | 2025-10-07 15:39:11.500276 | TASK [include_role : fetch-output] 2025-10-07 15:39:11.529842 | controller | ok 2025-10-07 15:39:11.547927 | 2025-10-07 15:39:11.548077 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-07 15:39:11.603954 | controller | skipping: Conditional result was False 2025-10-07 15:39:11.609825 | 2025-10-07 15:39:11.609925 | TASK [fetch-output : Set log path for single node] 2025-10-07 15:39:11.649608 | controller | ok 2025-10-07 15:39:11.654871 | 2025-10-07 15:39:11.654956 | LOOP [fetch-output : Ensure local output dirs] 2025-10-07 15:39:12.076048 | controller -> localhost | ok: "/var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/logs" 2025-10-07 15:39:12.312456 | controller -> localhost | changed: "/var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/artifacts" 2025-10-07 15:39:12.595250 | controller -> localhost | changed: "/var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/docs" 2025-10-07 15:39:12.613071 | 2025-10-07 15:39:12.613183 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-07 15:39:13.284483 | controller | changed: .d..t...... ./ 2025-10-07 15:39:13.284795 | controller | changed: All items complete 2025-10-07 15:39:13.284842 | 2025-10-07 15:39:13.801693 | controller | changed: .d..t...... ./ 2025-10-07 15:39:14.270098 | controller | changed: .d..t...... ./ 2025-10-07 15:39:14.306625 | 2025-10-07 15:39:14.306846 | TASK [include_role : fetch-output-openshift] 2025-10-07 15:39:14.323252 | controller | skipping: Conditional result was False 2025-10-07 15:39:14.333240 | 2025-10-07 15:39:14.333359 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-07 15:39:14.770227 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009351 2025-10-07 15:39:15.044129 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007632 2025-10-07 15:39:15.080020 | 2025-10-07 15:39:15.080130 | PLAY [all] 2025-10-07 15:39:15.098915 | 2025-10-07 15:39:15.099050 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-07 15:39:15.568043 | controller | changed 2025-10-07 15:39:15.591016 | 2025-10-07 15:39:15.591130 | PLAY RECAP 2025-10-07 15:39:15.591172 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 15:39:15.591194 | 2025-10-07 15:39:15.700483 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 15:39:15.702194 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-07 15:39:16.353520 | 2025-10-07 15:39:16.353650 | PLAY [localhost] 2025-10-07 15:39:16.373945 | 2025-10-07 15:39:16.374075 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-07 15:39:16.771845 | localhost | changed 2025-10-07 15:39:16.776375 | 2025-10-07 15:39:16.776457 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-07 15:39:16.805620 | localhost | ok 2025-10-07 15:39:16.814292 | 2025-10-07 15:39:16.814386 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-07 15:39:17.181968 | localhost | changed 2025-10-07 15:39:17.188453 | 2025-10-07 15:39:17.188573 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-07 15:39:17.824341 | localhost | changed 2025-10-07 15:39:17.830259 | 2025-10-07 15:39:17.830372 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-07 15:39:18.298523 | localhost | Identity added: /var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/tmp/ansible.mr8cxwco (/var/lib/zuul/builds/532a2f9a5c154b2db557dffbe28f94c2/work/tmp/ansible.mr8cxwco) 2025-10-07 15:39:18.298701 | localhost | ok: Runtime: 0:00:00.007880 2025-10-07 15:39:18.305189 | 2025-10-07 15:39:18.305284 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-07 15:39:18.596028 | localhost | ok: Runtime: 0:00:00.007548 2025-10-07 15:39:18.601331 | 2025-10-07 15:39:18.601452 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-07 15:39:18.702216 | localhost | changed 2025-10-07 15:39:18.713134 | 2025-10-07 15:39:18.713332 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-07 15:39:19.205485 | localhost | changed 2025-10-07 15:39:19.229819 | 2025-10-07 15:39:19.229941 | PLAY [localhost] 2025-10-07 15:39:19.244350 | 2025-10-07 15:39:19.244471 | TASK [Generate bulk log download script] 2025-10-07 15:39:19.263692 | localhost | ok 2025-10-07 15:39:19.277946 | 2025-10-07 15:39:19.278100 | TASK [local-log-download : Check API endpoint is defined] 2025-10-07 15:39:19.308981 | localhost | ok: All assertions passed 2025-10-07 15:39:19.314104 | 2025-10-07 15:39:19.314223 | TASK [local-log-download : Create download script] 2025-10-07 15:39:19.778224 | localhost -> localhost | changed 2025-10-07 15:39:19.788505 | 2025-10-07 15:39:19.788633 | TASK [Register quick-download link] 2025-10-07 15:39:19.817800 | localhost | ok 2025-10-07 15:39:19.871780 | 2025-10-07 15:39:19.871888 | PLAY [logserver.rdoproject.org] 2025-10-07 15:39:19.883003 | 2025-10-07 15:39:19.883126 | TASK [Set zuul-log-path fact] 2025-10-07 15:39:19.901234 | logserver.rdoproject.org | ok 2025-10-07 15:39:19.914367 | 2025-10-07 15:39:19.914491 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 15:39:19.951708 | logserver.rdoproject.org | ok 2025-10-07 15:39:19.968374 | 2025-10-07 15:39:19.968468 | TASK [upload-logs : Create log directories] 2025-10-07 15:39:20.665025 | logserver.rdoproject.org | changed 2025-10-07 15:39:20.672528 | 2025-10-07 15:39:20.672696 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-07 15:39:21.065207 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005272 2025-10-07 15:39:21.069993 | 2025-10-07 15:39:21.070092 | TASK [upload-logs : Upload logs to log server] 2025-10-07 15:39:21.793996 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-07 15:39:21.797359 | 2025-10-07 15:39:21.797452 | LOOP [upload-logs : Compress console log and json output] 2025-10-07 15:39:21.857197 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:21.864835 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:21.878664 | 2025-10-07 15:39:21.878841 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-07 15:39:21.940173 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:21.940438 | 2025-10-07 15:39:21.943944 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:21.949043 | 2025-10-07 15:39:21.949177 | LOOP [upload-logs : Upload console log and json output]