2025-10-14 06:50:08.791327 | Job console starting... 2025-10-14 06:50:08.802608 | Updating repositories 2025-10-14 06:50:08.831008 | Preparing job workspace 2025-10-14 06:50:12.843722 | Running Ansible setup... 2025-10-14 06:50:16.737957 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-14 06:50:17.308897 | 2025-10-14 06:50:17.309005 | PLAY [localhost] 2025-10-14 06:50:17.317752 | 2025-10-14 06:50:17.317823 | TASK [Gathering Facts] 2025-10-14 06:50:18.284592 | localhost | ok 2025-10-14 06:50:18.303402 | 2025-10-14 06:50:18.303514 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-14 06:50:18.681757 | localhost -> localhost | changed 2025-10-14 06:50:18.693012 | 2025-10-14 06:50:18.693158 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-14 06:50:19.596260 | localhost -> localhost | changed 2025-10-14 06:50:19.611740 | 2025-10-14 06:50:19.611868 | TASK [Setup log path fact] 2025-10-14 06:50:19.630206 | localhost | ok 2025-10-14 06:50:19.645093 | 2025-10-14 06:50:19.645292 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-14 06:50:19.676338 | localhost | ok 2025-10-14 06:50:19.686774 | 2025-10-14 06:50:19.686863 | TASK [emit-job-header : Print job information] 2025-10-14 06:50:19.726390 | # Job Information 2025-10-14 06:50:19.726546 | Ansible Version: 2.15.12 2025-10-14 06:50:19.726581 | Job: cifmw-molecule-ovirt 2025-10-14 06:50:19.726608 | Pipeline: github-check 2025-10-14 06:50:19.726633 | Executor: ze04.softwarefactory-project.io 2025-10-14 06:50:19.726657 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-14 06:50:19.726707 | Log URL (when completed): https://logserver.rdoproject.org/63e/rdoproject.org/63e77819490c435b8d7af79d93327172/ 2025-10-14 06:50:19.726736 | Event ID: c940b7c0-a8c9-11f0-80da-b48bf6033ab5 2025-10-14 06:50:19.731836 | 2025-10-14 06:50:19.731928 | LOOP [emit-job-header : Print node information] 2025-10-14 06:50:19.819909 | localhost | ok: 2025-10-14 06:50:19.820073 | localhost | # Node Information 2025-10-14 06:50:19.820100 | localhost | Inventory Hostname: controller 2025-10-14 06:50:19.820122 | localhost | Hostname: np0005486821 2025-10-14 06:50:19.820141 | localhost | Username: zuul 2025-10-14 06:50:19.820161 | localhost | Distro: CentOS 9 2025-10-14 06:50:19.820179 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-14 06:50:19.820196 | localhost | Region: RegionOne 2025-10-14 06:50:19.820212 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-14 06:50:19.820228 | localhost | Product Name: OpenStack Nova 2025-10-14 06:50:19.820245 | localhost | Interface IP: 38.102.83.190 2025-10-14 06:50:19.870810 | 2025-10-14 06:50:19.870962 | PLAY [all] 2025-10-14 06:50:19.885150 | 2025-10-14 06:50:19.885285 | TASK [Gather network facts] 2025-10-14 06:50:20.363854 | controller | ok 2025-10-14 06:50:20.395319 | 2025-10-14 06:50:20.395441 | TASK [include_role : start-zuul-console] 2025-10-14 06:50:20.417211 | controller | ok 2025-10-14 06:50:20.433568 | 2025-10-14 06:50:20.433658 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-14 06:50:20.881346 | controller | ok 2025-10-14 06:50:20.889867 | 2025-10-14 06:50:20.889929 | TASK [include_role : add-build-sshkey] 2025-10-14 06:50:20.917535 | controller | ok 2025-10-14 06:50:20.929929 | 2025-10-14 06:50:20.930134 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-14 06:50:21.148674 | controller -> localhost | ok 2025-10-14 06:50:21.160096 | 2025-10-14 06:50:21.160220 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-14 06:50:21.186930 | controller | ok 2025-10-14 06:50:21.212324 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-14 06:50:21.220370 | 2025-10-14 06:50:21.220457 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-14 06:50:21.765013 | controller -> localhost | Generating public/private rsa key pair. 2025-10-14 06:50:21.765209 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/63e77819490c435b8d7af79d93327172_id_rsa. 2025-10-14 06:50:21.765242 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/63e77819490c435b8d7af79d93327172_id_rsa.pub. 2025-10-14 06:50:21.765264 | controller -> localhost | The key fingerprint is: 2025-10-14 06:50:21.765284 | controller -> localhost | SHA256:R61l+JmugBnesQjEl6la6iwMBElkyShCb71aP4qA3Dk zuul-build-sshkey 2025-10-14 06:50:21.765303 | controller -> localhost | The key's randomart image is: 2025-10-14 06:50:21.765322 | controller -> localhost | +---[RSA 3072]----+ 2025-10-14 06:50:21.765341 | controller -> localhost | |**. | 2025-10-14 06:50:21.765360 | controller -> localhost | |Bo... o o | 2025-10-14 06:50:21.765379 | controller -> localhost | |+ oo.+ o + | 2025-10-14 06:50:21.765397 | controller -> localhost | | ... o. . = o | 2025-10-14 06:50:21.765415 | controller -> localhost | |. +o. S o + | 2025-10-14 06:50:21.765433 | controller -> localhost | |+ .++o.* + . | 2025-10-14 06:50:21.765451 | controller -> localhost | |+ooE =o+ . | 2025-10-14 06:50:21.765471 | controller -> localhost | |.+. o . .. . | 2025-10-14 06:50:21.765490 | controller -> localhost | | .o. . . | 2025-10-14 06:50:21.765507 | controller -> localhost | +----[SHA256]-----+ 2025-10-14 06:50:21.765546 | controller -> localhost | ok: Runtime: 0:00:00.157824 2025-10-14 06:50:21.771059 | 2025-10-14 06:50:21.771119 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-14 06:50:21.799149 | controller | ok 2025-10-14 06:50:21.808535 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-14 06:50:21.816414 | 2025-10-14 06:50:21.816471 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-14 06:50:21.840548 | controller | skipping: Conditional result was False 2025-10-14 06:50:21.845883 | 2025-10-14 06:50:21.845946 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-14 06:50:22.336245 | controller | changed 2025-10-14 06:50:22.347436 | 2025-10-14 06:50:22.347574 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-14 06:50:22.615166 | controller | ok 2025-10-14 06:50:22.621952 | 2025-10-14 06:50:22.622034 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-14 06:50:23.599722 | controller | changed 2025-10-14 06:50:23.611659 | 2025-10-14 06:50:23.611872 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-14 06:50:24.462963 | controller | changed 2025-10-14 06:50:24.486157 | 2025-10-14 06:50:24.486322 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-14 06:50:24.511465 | controller | skipping: Conditional result was False 2025-10-14 06:50:24.519755 | 2025-10-14 06:50:24.519861 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-14 06:50:24.859584 | controller -> localhost | changed 2025-10-14 06:50:24.869662 | 2025-10-14 06:50:24.869755 | TASK [add-build-sshkey : Add back temp key] 2025-10-14 06:50:25.188077 | controller -> localhost | Identity added: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/63e77819490c435b8d7af79d93327172_id_rsa (zuul-build-sshkey) 2025-10-14 06:50:25.188300 | controller -> localhost | ok: Runtime: 0:00:00.017567 2025-10-14 06:50:25.193948 | 2025-10-14 06:50:25.194009 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-14 06:50:25.586516 | controller | ok 2025-10-14 06:50:25.593115 | 2025-10-14 06:50:25.593183 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-14 06:50:25.631907 | controller | skipping: Conditional result was False 2025-10-14 06:50:25.642510 | 2025-10-14 06:50:25.642573 | TASK [include_role : validate-host] 2025-10-14 06:50:25.675854 | controller | ok 2025-10-14 06:50:25.694596 | 2025-10-14 06:50:25.694660 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-14 06:50:25.723157 | controller | ok 2025-10-14 06:50:25.727523 | 2025-10-14 06:50:25.727581 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-14 06:50:25.934861 | controller -> localhost | ok 2025-10-14 06:50:25.943125 | 2025-10-14 06:50:25.943217 | TASK [validate-host : Collect information about the host] 2025-10-14 06:50:26.757890 | controller | ok 2025-10-14 06:50:26.770568 | 2025-10-14 06:50:26.770681 | TASK [validate-host : Sanitize hostname] 2025-10-14 06:50:26.848562 | controller | ok 2025-10-14 06:50:26.860101 | 2025-10-14 06:50:26.860300 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-14 06:50:27.339043 | controller -> localhost | changed 2025-10-14 06:50:27.351868 | 2025-10-14 06:50:27.351998 | TASK [validate-host : Collect information about zuul worker] 2025-10-14 06:50:27.736027 | controller | ok 2025-10-14 06:50:27.747674 | 2025-10-14 06:50:27.747834 | TASK [validate-host : Write out all zuul information for each host] 2025-10-14 06:50:28.227826 | controller -> localhost | changed 2025-10-14 06:50:28.249733 | 2025-10-14 06:50:28.249822 | TASK [include_role : prepare-workspace-openshift] 2025-10-14 06:50:28.274896 | controller | skipping: Conditional result was False 2025-10-14 06:50:28.282325 | 2025-10-14 06:50:28.282407 | TASK [include_role : remove-zuul-sshkey] 2025-10-14 06:50:28.307673 | controller | skipping: Conditional result was False 2025-10-14 06:50:28.315620 | 2025-10-14 06:50:28.315742 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-14 06:50:28.570937 | controller | ok: "logs" 2025-10-14 06:50:28.571353 | controller | ok: All items complete 2025-10-14 06:50:28.571423 | 2025-10-14 06:50:28.795173 | controller | ok: "artifacts" 2025-10-14 06:50:29.064168 | controller | ok: "docs" 2025-10-14 06:50:29.077320 | 2025-10-14 06:50:29.077513 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-14 06:50:29.442718 | controller | changed: "logs" 2025-10-14 06:50:29.688523 | controller | changed: "artifacts" 2025-10-14 06:50:29.930600 | controller | changed: "docs" 2025-10-14 06:50:29.986145 | 2025-10-14 06:50:29.986267 | PLAY RECAP 2025-10-14 06:50:29.986326 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-14 06:50:29.986363 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-14 06:50:29.986388 | 2025-10-14 06:50:30.099874 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-14 06:50:30.100675 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-14 06:50:30.687881 | 2025-10-14 06:50:30.687983 | PLAY [localhost] 2025-10-14 06:50:30.703775 | 2025-10-14 06:50:30.703846 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-14 06:50:31.159735 | localhost | ok 2025-10-14 06:50:31.164915 | 2025-10-14 06:50:31.164995 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-14 06:50:31.857309 | localhost | changed 2025-10-14 06:50:31.877199 | 2025-10-14 06:50:31.877254 | PLAY [all] 2025-10-14 06:50:31.892166 | 2025-10-14 06:50:31.892225 | TASK [include_role : prepare-workspace] 2025-10-14 06:50:31.921306 | controller | ok 2025-10-14 06:50:31.935328 | 2025-10-14 06:50:31.935390 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-14 06:50:32.356421 | controller | ok 2025-10-14 06:50:32.377742 | 2025-10-14 06:50:32.378038 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-14 06:50:34.292164 | controller | Output suppressed because no_log was given 2025-10-14 06:50:34.305947 | 2025-10-14 06:50:34.306036 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-14 06:50:34.621344 | controller | changed: "logs" 2025-10-14 06:50:34.838297 | controller | changed: "artifacts" 2025-10-14 06:50:35.096778 | controller | changed: "docs" 2025-10-14 06:50:35.114427 | 2025-10-14 06:50:35.114648 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-14 06:50:35.452474 | controller | changed: "logs" 2025-10-14 06:50:35.452815 | controller | changed: All items complete 2025-10-14 06:50:35.452863 | 2025-10-14 06:50:35.759026 | controller | changed: "artifacts" 2025-10-14 06:50:36.007155 | controller | changed: "docs" 2025-10-14 06:50:36.036048 | 2025-10-14 06:50:36.036251 | TASK [Check if worker can sudo] 2025-10-14 06:50:36.587142 | controller | ok: Runtime: 0:00:00.053141 2025-10-14 06:50:36.600041 | 2025-10-14 06:50:36.600195 | TASK [configure-mirrors : Gather needed facts] 2025-10-14 06:50:36.719326 | controller | skipping: Conditional result was False 2025-10-14 06:50:36.731437 | 2025-10-14 06:50:36.731573 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-14 06:50:36.822585 | controller | ok 2025-10-14 06:50:36.871327 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-14 06:50:36.879237 | 2025-10-14 06:50:36.879322 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-14 06:50:37.171108 | controller | ok 2025-10-14 06:50:37.183866 | 2025-10-14 06:50:37.184001 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-14 06:50:37.286305 | controller | ok: "/var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-14 06:50:37.308512 | 2025-10-14 06:50:37.308714 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-14 06:50:38.311737 | controller | changed 2025-10-14 06:50:38.319139 | 2025-10-14 06:50:38.319222 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-14 06:50:38.400075 | controller | ok: "/var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-14 06:50:38.400259 | controller | ok: All items complete 2025-10-14 06:50:38.400285 | 2025-10-14 06:50:38.471540 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-14 06:50:38.479822 | 2025-10-14 06:50:38.479885 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-14 06:50:39.451001 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-14 06:50:40.423996 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-14 06:50:40.438836 | 2025-10-14 06:50:40.438974 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-14 06:50:40.880422 | controller | changed: section and option added 2025-10-14 06:50:40.917286 | 2025-10-14 06:50:40.917402 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-14 06:50:41.697204 | controller | 29 files removed 2025-10-14 06:50:41.697616 | controller | ok: Item: dnf clean all Runtime: 0:00:00.466632 2025-10-14 06:50:41.697831 | controller | changed: All items complete 2025-10-14 06:50:41.697894 | 2025-10-14 06:50:52.462938 | 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-14 06:50:52.463070 | controller | DNF version: 4.14.0 2025-10-14 06:50:52.463103 | controller | cachedir: /var/cache/dnf 2025-10-14 06:50:52.463132 | controller | Making cache files for all metadata files. 2025-10-14 06:50:52.463159 | controller | baseos: has expired and will be refreshed. 2025-10-14 06:50:52.463182 | controller | appstream: has expired and will be refreshed. 2025-10-14 06:50:52.463204 | controller | crb: has expired and will be refreshed. 2025-10-14 06:50:52.463237 | controller | extras-common: has expired and will be refreshed. 2025-10-14 06:50:52.463260 | controller | repo: downloading from remote: baseos 2025-10-14 06:50:52.463282 | controller | CentOS Stream 9 - BaseOS 72 MB/s | 8.8 MB 00:00 2025-10-14 06:50:52.463303 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-14 06:50:52.463325 | controller | repo: downloading from remote: appstream 2025-10-14 06:50:52.463346 | controller | CentOS Stream 9 - AppStream 117 MB/s | 25 MB 00:00 2025-10-14 06:50:52.463367 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-14 06:50:52.463388 | controller | repo: downloading from remote: crb 2025-10-14 06:50:52.463409 | controller | CentOS Stream 9 - CRB 95 MB/s | 7.2 MB 00:00 2025-10-14 06:50:52.463430 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-14 06:50:52.463451 | controller | repo: downloading from remote: extras-common 2025-10-14 06:50:52.463473 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-10-14 06:50:52.463495 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-14 06:50:52.463516 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-14 06:50:52.463537 | controller | Completion plugin: Generating completion cache... 2025-10-14 06:50:52.463558 | controller | Metadata cache created. 2025-10-14 06:50:52.463593 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.475589 2025-10-14 06:50:52.493436 | 2025-10-14 06:50:52.493540 | PLAY RECAP 2025-10-14 06:50:52.493583 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-14 06:50:52.493608 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-14 06:50:52.493626 | 2025-10-14 06:50:52.588359 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-14 06:50:52.589573 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-14 06:50:53.169122 | 2025-10-14 06:50:53.169244 | PLAY [all] 2025-10-14 06:50:53.189949 | 2025-10-14 06:50:53.190035 | TASK [Install binary dependencies] 2025-10-14 06:50:53.271775 | controller | ok 2025-10-14 06:50:53.297789 | 2025-10-14 06:50:53.297916 | TASK [bindep : Include find tasks] 2025-10-14 06:50:53.345234 | controller | ok 2025-10-14 06:50:53.362612 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-14 06:50:53.375981 | 2025-10-14 06:50:53.376125 | TASK [bindep : Look for bindep.txt] 2025-10-14 06:50:53.771315 | controller | ok 2025-10-14 06:50:53.787434 | 2025-10-14 06:50:53.787588 | TASK [bindep : Define bindep_file fact] 2025-10-14 06:50:53.836923 | controller | ok 2025-10-14 06:50:53.848667 | 2025-10-14 06:50:53.848866 | TASK [bindep : Look for other-requirements.txt] 2025-10-14 06:50:53.876802 | controller | skipping: Conditional result was False 2025-10-14 06:50:53.889934 | 2025-10-14 06:50:53.890096 | TASK [bindep : Define bindep_file fact] 2025-10-14 06:50:53.928196 | controller | skipping: Conditional result was False 2025-10-14 06:50:53.941343 | 2025-10-14 06:50:53.941491 | TASK [bindep : Look for bindep fallback file] 2025-10-14 06:50:53.979826 | controller | skipping: Conditional result was False 2025-10-14 06:50:53.992101 | 2025-10-14 06:50:53.992256 | TASK [bindep : Define bindep_file fact] 2025-10-14 06:50:54.030250 | controller | skipping: Conditional result was False 2025-10-14 06:50:54.043325 | 2025-10-14 06:50:54.043463 | TASK [bindep : Include bindep tasks] 2025-10-14 06:50:54.094940 | controller | ok 2025-10-14 06:50:54.109994 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-14 06:50:54.122262 | 2025-10-14 06:50:54.122345 | TASK [bindep : Look for bindep command] 2025-10-14 06:50:54.147715 | controller | skipping: Conditional result was False 2025-10-14 06:50:54.156140 | 2025-10-14 06:50:54.156225 | TASK [bindep : Check for system bindep] 2025-10-14 06:50:54.697414 | controller | ok: Runtime: 0:00:00.006118 2025-10-14 06:50:54.709848 | 2025-10-14 06:50:54.709984 | TASK [bindep : Define bindep_command fact] 2025-10-14 06:50:54.747223 | controller | skipping: Conditional result was False 2025-10-14 06:50:54.759987 | 2025-10-14 06:50:54.760127 | TASK [bindep : Include install tasks] 2025-10-14 06:50:54.809889 | controller | ok 2025-10-14 06:50:54.825077 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-14 06:50:54.836919 | 2025-10-14 06:50:54.837004 | TASK [bindep : Create temp dir for bindep] 2025-10-14 06:50:55.210879 | controller | changed 2025-10-14 06:50:55.222521 | 2025-10-14 06:50:55.222646 | TASK [Ensure we have pip dependencies] 2025-10-14 06:50:55.250816 | controller | ok 2025-10-14 06:50:55.290814 | 2025-10-14 06:50:55.290930 | TASK [ensure-pip : Check if pip is installed] 2025-10-14 02:50:55.599106 | controller | /usr/bin/pip3 2025-10-14 02:50:55.620625 | controller | /usr/bin/python3: No module named wheel 2025-10-14 06:50:55.824927 | controller | ok: Runtime: 0:00:00.029596 2025-10-14 06:50:55.833019 | 2025-10-14 06:50:55.833103 | LOOP [ensure-pip : Install pip from packages] 2025-10-14 06:50:55.890540 | controller | ok: "/var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-14 06:50:55.904558 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-14 06:50:55.918135 | 2025-10-14 06:50:55.918223 | TASK [ensure-pip : Install Python 3 pip] 2025-10-14 06:50:58.091551 | controller | changed 2025-10-14 06:50:58.099370 | 2025-10-14 06:50:58.099457 | TASK [ensure-pip : Check for EPEL repository] 2025-10-14 06:50:58.144990 | controller | skipping: Conditional result was False 2025-10-14 06:50:58.153636 | 2025-10-14 06:50:58.153733 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-14 06:50:58.199735 | controller | skipping: Conditional result was False 2025-10-14 06:50:58.208220 | 2025-10-14 06:50:58.208300 | TASK [ensure-pip : Install Python 2 pip] 2025-10-14 06:50:58.274395 | controller | skipping: Conditional result was False 2025-10-14 06:50:58.283408 | 2025-10-14 06:50:58.283496 | TASK [ensure-pip : Ensure setuptools] 2025-10-14 06:50:58.309248 | controller | skipping: Conditional result was False 2025-10-14 06:50:58.323135 | 2025-10-14 06:50:58.323284 | TASK [ensure-pip : Check for ensurepip module] 2025-10-14 06:50:58.870283 | controller | skipping: Conditional result was False 2025-10-14 06:50:58.884331 | 2025-10-14 06:50:58.884489 | TASK [ensure-pip : Ensure python3-venv] 2025-10-14 06:50:58.911558 | controller | skipping: Conditional result was False 2025-10-14 06:50:58.925817 | 2025-10-14 06:50:58.925958 | TASK [ensure-pip : Install pip from source] 2025-10-14 06:50:58.954955 | controller | skipping: Conditional result was False 2025-10-14 06:50:58.967476 | 2025-10-14 06:50:58.967611 | TASK [ensure-pip : Probe for venv python full path] 2025-10-14 02:50:59.256813 | controller | /usr/bin/python3 2025-10-14 06:50:59.512604 | controller | ok: Runtime: 0:00:00.007182 2025-10-14 06:50:59.526612 | 2025-10-14 06:50:59.526865 | TASK [ensure-pip : Set host default] 2025-10-14 06:50:59.619591 | controller | ok 2025-10-14 06:50:59.633918 | 2025-10-14 06:50:59.634006 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-14 06:50:59.704920 | controller | ok 2025-10-14 06:50:59.715819 | 2025-10-14 06:50:59.715947 | TASK [bindep : Install bindep into temporary venv] 2025-10-14 06:51:03.850190 | controller | changed 2025-10-14 06:51:03.864068 | 2025-10-14 06:51:03.864221 | TASK [bindep : Define bindep_command] 2025-10-14 06:51:03.905204 | controller | ok 2025-10-14 06:51:03.918137 | 2025-10-14 06:51:03.918311 | LOOP [bindep : Include package tasks] 2025-10-14 06:51:03.985714 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-14 06:51:03.985895 | controller | ok: All items complete 2025-10-14 06:51:03.985928 | 2025-10-14 06:51:03.997527 | controller | included: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-14 06:51:04.017095 | 2025-10-14 06:51:04.017295 | TASK [bindep : Define bindep_run fact] 2025-10-14 06:51:04.055295 | controller | ok 2025-10-14 06:51:04.066620 | 2025-10-14 06:51:04.066786 | TASK [bindep : Get list of packages to install from bindep] 2025-10-14 02:51:05.527218 | controller | podman 2025-10-14 02:51:05.567668 | controller | python3-jmespath 2025-10-14 02:51:05.567869 | controller | python3-libvirt 2025-10-14 02:51:05.567896 | controller | python3-lxml 2025-10-14 02:51:05.567920 | controller | python3-netaddr 2025-10-14 06:51:05.616096 | controller | ok: Runtime: 0:00:01.175423 2025-10-14 06:51:05.621383 | 2025-10-14 06:51:05.621448 | TASK [bindep : Install distro packages from bindep] 2025-10-14 06:52:07.305846 | controller | changed 2025-10-14 06:52:07.317519 | 2025-10-14 06:52:07.317648 | TASK [bindep : Check that packages are installed] 2025-10-14 06:52:08.867650 | controller | ok: Runtime: 0:00:01.108138 2025-10-14 06:52:08.880382 | 2025-10-14 06:52:08.880529 | TASK [bindep : Fail if we cannot install all packages] 2025-10-14 06:52:08.928855 | controller | skipping: Conditional result was False 2025-10-14 06:52:08.964806 | 2025-10-14 06:52:08.964930 | TASK [Run test-setup role] 2025-10-14 06:52:08.993209 | controller | ok 2025-10-14 06:52:09.031534 | 2025-10-14 06:52:09.031722 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-14 06:52:09.255830 | controller | ok 2025-10-14 06:52:09.264996 | 2025-10-14 06:52:09.265061 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-14 06:52:09.796591 | controller | skipping: Conditional result was False 2025-10-14 06:52:09.816969 | 2025-10-14 06:52:09.817052 | TASK [bindep : Remove bindep temp dir] 2025-10-14 06:52:10.264462 | controller | ok 2025-10-14 06:52:10.274450 | 2025-10-14 06:52:10.274499 | PLAY RECAP 2025-10-14 06:52:10.274537 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-14 06:52:10.274558 | 2025-10-14 06:52:10.367414 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-14 06:52:10.368292 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-14 06:52:10.926975 | 2025-10-14 06:52:10.927104 | PLAY [all] 2025-10-14 06:52:10.947875 | 2025-10-14 06:52:10.947952 | TASK [Abort when test_command variable is undefined] 2025-10-14 06:52:10.972351 | controller | skipping: Conditional result was False 2025-10-14 06:52:10.977944 | 2025-10-14 06:52:10.978021 | TASK [Convert test_command to list] 2025-10-14 06:52:11.011510 | controller | skipping: Conditional result was False 2025-10-14 06:52:11.018232 | 2025-10-14 06:52:11.018311 | TASK [Use test_command list] 2025-10-14 06:52:11.072763 | controller | ok 2025-10-14 06:52:11.078124 | 2025-10-14 06:52:11.078184 | LOOP [Run test_command] 2025-10-14 06:52:11.467461 | controller | no check to run 2025-10-14 06:52:11.467812 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005993 2025-10-14 06:52:11.506526 | 2025-10-14 06:52:11.506663 | PLAY RECAP 2025-10-14 06:52:11.506748 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-14 06:52:11.506779 | 2025-10-14 06:52:11.637629 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-14 06:52:11.639350 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-14 06:52:12.245899 | 2025-10-14 06:52:12.246003 | PLAY [all] 2025-10-14 06:52:12.266351 | 2025-10-14 06:52:12.266448 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-14 06:52:12.649515 | controller | changed: non-zero return code 2025-10-14 06:52:12.661892 | 2025-10-14 06:52:12.662056 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-14 06:52:12.690065 | controller | skipping: Conditional result was False 2025-10-14 06:52:12.702032 | 2025-10-14 06:52:12.702174 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-14 06:52:12.744909 | 2025-10-14 06:52:12.745193 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-14 06:52:12.785274 | 2025-10-14 06:52:12.785521 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-14 06:52:12.812784 | controller | skipping: Conditional result was False 2025-10-14 06:52:12.826032 | 2025-10-14 06:52:12.826176 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-14 06:52:12.868027 | 2025-10-14 06:52:12.868299 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-14 06:52:12.895459 | controller | skipping: Conditional result was False 2025-10-14 06:52:12.907480 | 2025-10-14 06:52:12.907623 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-14 06:52:12.936092 | controller | skipping: Conditional result was False 2025-10-14 06:52:12.949319 | 2025-10-14 06:52:12.949460 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-14 06:52:12.976601 | controller | skipping: Conditional result was False 2025-10-14 06:52:13.023242 | 2025-10-14 06:52:13.023320 | PLAY RECAP 2025-10-14 06:52:13.023377 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-14 06:52:13.023405 | 2025-10-14 06:52:13.123613 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-14 06:52:13.125413 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-14 06:52:13.739829 | 2025-10-14 06:52:13.739948 | PLAY [all] 2025-10-14 06:52:13.759104 | 2025-10-14 06:52:13.759199 | TASK [include_role : fetch-output] 2025-10-14 06:52:13.802933 | controller | ok 2025-10-14 06:52:13.820036 | 2025-10-14 06:52:13.820122 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-14 06:52:13.885266 | controller | skipping: Conditional result was False 2025-10-14 06:52:13.893052 | 2025-10-14 06:52:13.893147 | TASK [fetch-output : Set log path for single node] 2025-10-14 06:52:13.940405 | controller | ok 2025-10-14 06:52:13.951768 | 2025-10-14 06:52:13.951861 | LOOP [fetch-output : Ensure local output dirs] 2025-10-14 06:52:14.404767 | controller -> localhost | ok: "/var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/logs" 2025-10-14 06:52:14.658969 | controller -> localhost | changed: "/var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/artifacts" 2025-10-14 06:52:14.904810 | controller -> localhost | changed: "/var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/docs" 2025-10-14 06:52:14.913988 | 2025-10-14 06:52:14.914126 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-14 06:52:15.579072 | controller | changed: .d..t...... ./ 2025-10-14 06:52:15.579425 | controller | changed: All items complete 2025-10-14 06:52:15.579487 | 2025-10-14 06:52:16.036892 | controller | changed: .d..t...... ./ 2025-10-14 06:52:16.549929 | controller | changed: .d..t...... ./ 2025-10-14 06:52:16.583969 | 2025-10-14 06:52:16.584163 | TASK [include_role : fetch-output-openshift] 2025-10-14 06:52:16.611071 | controller | skipping: Conditional result was False 2025-10-14 06:52:16.619396 | 2025-10-14 06:52:16.619498 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-14 06:52:17.053782 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008164 2025-10-14 06:52:17.275759 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007556 2025-10-14 06:52:17.306171 | 2025-10-14 06:52:17.306266 | PLAY [all] 2025-10-14 06:52:17.321160 | 2025-10-14 06:52:17.321228 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-14 06:52:17.766301 | controller | changed 2025-10-14 06:52:17.806767 | 2025-10-14 06:52:17.806838 | PLAY RECAP 2025-10-14 06:52:17.806891 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-14 06:52:17.806919 | 2025-10-14 06:52:17.901813 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-14 06:52:17.903523 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-14 06:52:18.543011 | 2025-10-14 06:52:18.543130 | PLAY [localhost] 2025-10-14 06:52:18.560767 | 2025-10-14 06:52:18.560853 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-14 06:52:18.920560 | localhost | changed 2025-10-14 06:52:18.930717 | 2025-10-14 06:52:18.930932 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-14 06:52:18.966501 | localhost | ok 2025-10-14 06:52:18.983585 | 2025-10-14 06:52:18.983752 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-14 06:52:19.360223 | localhost | changed 2025-10-14 06:52:19.365342 | 2025-10-14 06:52:19.365406 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-14 06:52:20.110412 | localhost | changed 2025-10-14 06:52:20.121199 | 2025-10-14 06:52:20.121345 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-14 06:52:20.514123 | localhost | Identity added: /var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/tmp/ansible.8trzg8hs (/var/lib/zuul/builds/63e77819490c435b8d7af79d93327172/work/tmp/ansible.8trzg8hs) 2025-10-14 06:52:20.514426 | localhost | ok: Runtime: 0:00:00.012640 2025-10-14 06:52:20.524290 | 2025-10-14 06:52:20.524465 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-14 06:52:20.789009 | localhost | ok: Runtime: 0:00:00.005272 2025-10-14 06:52:20.794216 | 2025-10-14 06:52:20.794281 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-14 06:52:20.843475 | localhost | changed 2025-10-14 06:52:20.847621 | 2025-10-14 06:52:20.847700 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-14 06:52:21.260234 | localhost | changed 2025-10-14 06:52:21.301843 | 2025-10-14 06:52:21.301925 | PLAY [localhost] 2025-10-14 06:52:21.318249 | 2025-10-14 06:52:21.318734 | TASK [Generate bulk log download script] 2025-10-14 06:52:21.350566 | localhost | ok 2025-10-14 06:52:21.366916 | 2025-10-14 06:52:21.367003 | TASK [local-log-download : Check API endpoint is defined] 2025-10-14 06:52:21.421018 | localhost | ok: All assertions passed 2025-10-14 06:52:21.431347 | 2025-10-14 06:52:21.431474 | TASK [local-log-download : Create download script] 2025-10-14 06:52:21.875453 | localhost -> localhost | changed 2025-10-14 06:52:21.887286 | 2025-10-14 06:52:21.887366 | TASK [Register quick-download link] 2025-10-14 06:52:21.908504 | localhost | ok 2025-10-14 06:52:21.977742 | 2025-10-14 06:52:21.977906 | PLAY [logserver.rdoproject.org] 2025-10-14 06:52:21.999509 | 2025-10-14 06:52:21.999642 | TASK [Set zuul-log-path fact] 2025-10-14 06:52:22.020175 | logserver.rdoproject.org | ok 2025-10-14 06:52:22.032193 | 2025-10-14 06:52:22.032276 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-14 06:52:22.070415 | logserver.rdoproject.org | ok 2025-10-14 06:52:22.077886 | 2025-10-14 06:52:22.077971 | TASK [upload-logs : Create log directories] 2025-10-14 06:52:22.747957 | logserver.rdoproject.org | changed 2025-10-14 06:52:22.751988 | 2025-10-14 06:52:22.752069 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-14 06:52:23.073299 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008630 2025-10-14 06:52:23.084007 | 2025-10-14 06:52:23.084165 | TASK [upload-logs : Upload logs to log server] 2025-10-14 06:52:23.870149 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-14 06:52:23.876636 | 2025-10-14 06:52:23.876811 | LOOP [upload-logs : Compress console log and json output] 2025-10-14 06:52:23.932582 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:52:23.946417 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:52:23.968136 | 2025-10-14 06:52:23.968349 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-14 06:52:24.025703 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:52:24.025957 | 2025-10-14 06:52:24.029212 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:52:24.040341 | 2025-10-14 06:52:24.040455 | LOOP [upload-logs : Upload console log and json output]