2025-11-21 11:46:57.268573 | Job console starting... 2025-11-21 11:46:57.277271 | Updating repositories 2025-11-21 11:46:57.307891 | Preparing job workspace 2025-11-21 11:47:02.745581 | Running Ansible setup... 2025-11-21 11:47:06.427741 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-21 11:47:07.023965 | 2025-11-21 11:47:07.024137 | PLAY [localhost] 2025-11-21 11:47:07.033811 | 2025-11-21 11:47:07.033919 | TASK [Gathering Facts] 2025-11-21 11:47:08.120594 | localhost | ok 2025-11-21 11:47:08.149998 | 2025-11-21 11:47:08.154178 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-21 11:47:08.566195 | localhost -> localhost | changed 2025-11-21 11:47:08.571604 | 2025-11-21 11:47:08.571675 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-21 11:47:09.407001 | localhost -> localhost | changed 2025-11-21 11:47:09.415289 | 2025-11-21 11:47:09.415352 | TASK [Setup log path fact] 2025-11-21 11:47:09.435315 | localhost | ok 2025-11-21 11:47:09.446489 | 2025-11-21 11:47:09.446551 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-21 11:47:09.474158 | localhost | ok 2025-11-21 11:47:09.486857 | 2025-11-21 11:47:09.486942 | TASK [emit-job-header : Print job information] 2025-11-21 11:47:09.515526 | # Job Information 2025-11-21 11:47:09.515645 | Ansible Version: 2.15.12 2025-11-21 11:47:09.515670 | Job: cifmw-molecule-cifmw_setup 2025-11-21 11:47:09.515689 | Pipeline: github-check 2025-11-21 11:47:09.515707 | Executor: ze01.softwarefactory-project.io 2025-11-21 11:47:09.515724 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451 2025-11-21 11:47:09.515742 | Log URL (when completed): https://logserver.rdoproject.org/896/rdoproject.org/8962c1c486e44067b2d8a09f66002b8c/ 2025-11-21 11:47:09.515760 | Event ID: 89f43be0-c6cf-11f0-848c-8d7059119474 2025-11-21 11:47:09.520421 | 2025-11-21 11:47:09.520483 | LOOP [emit-job-header : Print node information] 2025-11-21 11:47:09.610494 | localhost | ok: 2025-11-21 11:47:09.610699 | localhost | # Node Information 2025-11-21 11:47:09.610726 | localhost | Inventory Hostname: controller 2025-11-21 11:47:09.610748 | localhost | Hostname: np0005530990 2025-11-21 11:47:09.610767 | localhost | Username: zuul 2025-11-21 11:47:09.610787 | localhost | Distro: CentOS 9 2025-11-21 11:47:09.610804 | localhost | Provider: vexxhost-nodepool-tripleo 2025-11-21 11:47:09.610821 | localhost | Region: RegionOne 2025-11-21 11:47:09.610838 | localhost | Label: cloud-centos-9-stream-tripleo 2025-11-21 11:47:09.610854 | localhost | Product Name: OpenStack Nova 2025-11-21 11:47:09.610871 | localhost | Interface IP: 38.102.83.162 2025-11-21 11:47:09.634292 | 2025-11-21 11:47:09.634396 | PLAY [all] 2025-11-21 11:47:09.641270 | 2025-11-21 11:47:09.641332 | TASK [Gather network facts] 2025-11-21 11:47:10.120872 | controller | ok 2025-11-21 11:47:10.161113 | 2025-11-21 11:47:10.161322 | TASK [include_role : start-zuul-console] 2025-11-21 11:47:10.192185 | controller | ok 2025-11-21 11:47:10.213440 | 2025-11-21 11:47:10.213545 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-21 11:47:10.632235 | controller | ok 2025-11-21 11:47:10.644852 | 2025-11-21 11:47:10.644922 | TASK [include_role : add-build-sshkey] 2025-11-21 11:47:10.687578 | controller | ok 2025-11-21 11:47:10.700333 | 2025-11-21 11:47:10.700399 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-21 11:47:11.144244 | controller -> localhost | ok 2025-11-21 11:47:11.150274 | 2025-11-21 11:47:11.150341 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-21 11:47:11.193327 | controller | ok 2025-11-21 11:47:11.208924 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-21 11:47:11.224557 | 2025-11-21 11:47:11.224624 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-21 11:47:12.575907 | controller -> localhost | Generating public/private rsa key pair. 2025-11-21 11:47:12.576191 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/8962c1c486e44067b2d8a09f66002b8c_id_rsa. 2025-11-21 11:47:12.576223 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/8962c1c486e44067b2d8a09f66002b8c_id_rsa.pub. 2025-11-21 11:47:12.576245 | controller -> localhost | The key fingerprint is: 2025-11-21 11:47:12.576264 | controller -> localhost | SHA256:h4yK8CJKDQ38CoEabr52TbtnMgujjtr4b4oObn5StfQ zuul-build-sshkey 2025-11-21 11:47:12.576283 | controller -> localhost | The key's randomart image is: 2025-11-21 11:47:12.576301 | controller -> localhost | +---[RSA 3072]----+ 2025-11-21 11:47:12.576318 | controller -> localhost | | | 2025-11-21 11:47:12.576336 | controller -> localhost | |o | 2025-11-21 11:47:12.576354 | controller -> localhost | |+o | 2025-11-21 11:47:12.576371 | controller -> localhost | |oo+ o o . | 2025-11-21 11:47:12.576389 | controller -> localhost | |++ oo + S . | 2025-11-21 11:47:12.576406 | controller -> localhost | |+o+o + E . | 2025-11-21 11:47:12.576422 | controller -> localhost | |+++++ . | 2025-11-21 11:47:12.576441 | controller -> localhost | |BOoo+= o | 2025-11-21 11:47:12.576459 | controller -> localhost | |&OB+.oB | 2025-11-21 11:47:12.576475 | controller -> localhost | +----[SHA256]-----+ 2025-11-21 11:47:12.576527 | controller -> localhost | ok: Runtime: 0:00:00.821110 2025-11-21 11:47:12.582887 | 2025-11-21 11:47:12.582970 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-21 11:47:12.638160 | controller | ok 2025-11-21 11:47:12.648319 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-21 11:47:12.656447 | 2025-11-21 11:47:12.656508 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-21 11:47:12.681072 | controller | skipping: Conditional result was False 2025-11-21 11:47:12.687436 | 2025-11-21 11:47:12.687509 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-21 11:47:13.152672 | controller | changed 2025-11-21 11:47:13.163897 | 2025-11-21 11:47:13.164104 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-21 11:47:13.436367 | controller | ok 2025-11-21 11:47:13.443929 | 2025-11-21 11:47:13.444043 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-21 11:47:14.227251 | controller | changed 2025-11-21 11:47:14.232185 | 2025-11-21 11:47:14.232246 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-21 11:47:15.031999 | controller | changed 2025-11-21 11:47:15.048540 | 2025-11-21 11:47:15.048742 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-21 11:47:15.091844 | controller | skipping: Conditional result was False 2025-11-21 11:47:15.104418 | 2025-11-21 11:47:15.104558 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-21 11:47:15.499314 | controller -> localhost | changed 2025-11-21 11:47:15.519460 | 2025-11-21 11:47:15.519753 | TASK [add-build-sshkey : Add back temp key] 2025-11-21 11:47:15.796129 | controller -> localhost | Identity added: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/8962c1c486e44067b2d8a09f66002b8c_id_rsa (zuul-build-sshkey) 2025-11-21 11:47:15.796385 | controller -> localhost | ok: Runtime: 0:00:00.007988 2025-11-21 11:47:15.809807 | 2025-11-21 11:47:15.809939 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-21 11:47:16.175858 | controller | ok 2025-11-21 11:47:16.182821 | 2025-11-21 11:47:16.182909 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-21 11:47:16.218373 | controller | skipping: Conditional result was False 2025-11-21 11:47:16.232729 | 2025-11-21 11:47:16.232857 | TASK [include_role : validate-host] 2025-11-21 11:47:16.264345 | controller | ok 2025-11-21 11:47:16.292121 | 2025-11-21 11:47:16.292257 | TASK [validate-host : Define zuul_info_dir fact] 2025-11-21 11:47:16.324533 | controller | ok 2025-11-21 11:47:16.333301 | 2025-11-21 11:47:16.333394 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-11-21 11:47:16.651330 | controller -> localhost | ok 2025-11-21 11:47:16.656849 | 2025-11-21 11:47:16.656917 | TASK [validate-host : Collect information about the host] 2025-11-21 11:47:17.398138 | controller | ok 2025-11-21 11:47:17.411528 | 2025-11-21 11:47:17.411613 | TASK [validate-host : Sanitize hostname] 2025-11-21 11:47:17.487677 | controller | ok 2025-11-21 11:47:17.497247 | 2025-11-21 11:47:17.497331 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-11-21 11:47:18.002418 | controller -> localhost | changed 2025-11-21 11:47:18.008052 | 2025-11-21 11:47:18.008118 | TASK [validate-host : Collect information about zuul worker] 2025-11-21 11:47:18.401785 | controller | ok 2025-11-21 11:47:18.417063 | 2025-11-21 11:47:18.417245 | TASK [validate-host : Write out all zuul information for each host] 2025-11-21 11:47:18.904610 | controller -> localhost | changed 2025-11-21 11:47:18.915912 | 2025-11-21 11:47:18.916068 | TASK [include_role : prepare-workspace-openshift] 2025-11-21 11:47:18.942397 | controller | skipping: Conditional result was False 2025-11-21 11:47:18.948343 | 2025-11-21 11:47:18.948405 | TASK [include_role : remove-zuul-sshkey] 2025-11-21 11:47:18.972243 | controller | skipping: Conditional result was False 2025-11-21 11:47:18.978133 | 2025-11-21 11:47:18.978197 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-21 11:47:19.249170 | controller | ok: "logs" 2025-11-21 11:47:19.249755 | controller | ok: All items complete 2025-11-21 11:47:19.249795 | 2025-11-21 11:47:19.460407 | controller | ok: "artifacts" 2025-11-21 11:47:19.705968 | controller | ok: "docs" 2025-11-21 11:47:19.731493 | 2025-11-21 11:47:19.732987 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-21 11:47:20.015480 | controller | changed: "logs" 2025-11-21 11:47:20.262378 | controller | changed: "artifacts" 2025-11-21 11:47:20.474126 | controller | changed: "docs" 2025-11-21 11:47:20.501974 | 2025-11-21 11:47:20.502083 | PLAY RECAP 2025-11-21 11:47:20.502127 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-11-21 11:47:20.502151 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-21 11:47:20.502169 | 2025-11-21 11:47:20.677674 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-21 11:47:20.678881 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-21 11:47:21.341122 | 2025-11-21 11:47:21.341247 | PLAY [localhost] 2025-11-21 11:47:21.358168 | 2025-11-21 11:47:21.358254 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-11-21 11:47:21.816113 | localhost | ok 2025-11-21 11:47:21.822994 | 2025-11-21 11:47:21.823107 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-11-21 11:47:22.490596 | localhost | changed 2025-11-21 11:47:22.511293 | 2025-11-21 11:47:22.511352 | PLAY [all] 2025-11-21 11:47:22.526652 | 2025-11-21 11:47:22.526716 | TASK [include_role : prepare-workspace] 2025-11-21 11:47:22.545625 | controller | ok 2025-11-21 11:47:22.559884 | 2025-11-21 11:47:22.559976 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-21 11:47:23.017011 | controller | ok 2025-11-21 11:47:23.023996 | 2025-11-21 11:47:23.024081 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-21 11:47:25.216669 | controller | Output suppressed because no_log was given 2025-11-21 11:47:25.231543 | 2025-11-21 11:47:25.231638 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-21 11:47:25.492576 | controller | changed: "logs" 2025-11-21 11:47:25.716637 | controller | changed: "artifacts" 2025-11-21 11:47:25.936054 | controller | changed: "docs" 2025-11-21 11:47:25.947968 | 2025-11-21 11:47:25.948160 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-21 11:47:26.218756 | controller | changed: "logs" 2025-11-21 11:47:26.218982 | controller | changed: All items complete 2025-11-21 11:47:26.219010 | 2025-11-21 11:47:26.440949 | controller | changed: "artifacts" 2025-11-21 11:47:26.683292 | controller | changed: "docs" 2025-11-21 11:47:26.704860 | 2025-11-21 11:47:26.704968 | TASK [Check if worker can sudo] 2025-11-21 11:47:27.237725 | controller | ok: Runtime: 0:00:00.043151 2025-11-21 11:47:27.245736 | 2025-11-21 11:47:27.245828 | TASK [configure-mirrors : Gather needed facts] 2025-11-21 11:47:27.362293 | controller | skipping: Conditional result was False 2025-11-21 11:47:27.368381 | 2025-11-21 11:47:27.368449 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-11-21 11:47:27.472908 | controller | ok 2025-11-21 11:47:27.480192 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-11-21 11:47:27.485476 | 2025-11-21 11:47:27.485702 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-11-21 11:47:27.768737 | controller | ok 2025-11-21 11:47:27.780651 | 2025-11-21 11:47:27.780850 | LOOP [configure-mirrors : Include OS-specific variables] 2025-11-21 11:47:27.906634 | controller | ok: "/var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-11-21 11:47:27.919731 | 2025-11-21 11:47:27.919911 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-11-21 11:47:28.788595 | controller | changed 2025-11-21 11:47:28.795342 | 2025-11-21 11:47:28.795452 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-11-21 11:47:28.851744 | controller | ok: "/var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-11-21 11:47:28.852046 | controller | ok: All items complete 2025-11-21 11:47:28.852083 | 2025-11-21 11:47:28.925432 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-11-21 11:47:28.932080 | 2025-11-21 11:47:28.932145 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-11-21 11:47:29.832869 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-11-21 11:47:30.647139 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-11-21 11:47:30.656771 | 2025-11-21 11:47:30.656849 | TASK [configure-mirrors : Disable deltrarpm] 2025-11-21 11:47:31.129072 | controller | changed: section and option added 2025-11-21 11:47:31.211858 | 2025-11-21 11:47:31.211994 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-11-21 11:47:32.486510 | controller | 29 files removed 2025-11-21 11:47:32.489109 | controller | ok: Item: dnf clean all Runtime: 0:00:00.841680 2025-11-21 11:47:32.489160 | controller | changed: All items complete 2025-11-21 11:47:32.489182 | 2025-11-21 11:47:45.547309 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-11-21 11:47:45.547422 | controller | DNF version: 4.14.0 2025-11-21 11:47:45.547447 | controller | cachedir: /var/cache/dnf 2025-11-21 11:47:45.547466 | controller | Making cache files for all metadata files. 2025-11-21 11:47:45.547483 | controller | baseos: has expired and will be refreshed. 2025-11-21 11:47:45.547500 | controller | appstream: has expired and will be refreshed. 2025-11-21 11:47:45.547517 | controller | crb: has expired and will be refreshed. 2025-11-21 11:47:45.547542 | controller | extras-common: has expired and will be refreshed. 2025-11-21 11:47:45.547559 | controller | repo: downloading from remote: baseos 2025-11-21 11:47:45.547576 | controller | CentOS Stream 9 - BaseOS 45 MB/s | 8.8 MB 00:00 2025-11-21 11:47:45.547593 | controller | baseos: using metadata from Mon 17 Nov 2025 10:24:02 AM EST. 2025-11-21 11:47:45.547609 | controller | repo: downloading from remote: appstream 2025-11-21 11:47:45.547626 | controller | CentOS Stream 9 - AppStream 13 MB/s | 25 MB 00:02 2025-11-21 11:47:45.547642 | controller | appstream: using metadata from Mon 17 Nov 2025 10:27:35 AM EST. 2025-11-21 11:47:45.547658 | controller | repo: downloading from remote: crb 2025-11-21 11:47:45.547674 | controller | CentOS Stream 9 - CRB 66 MB/s | 7.3 MB 00:00 2025-11-21 11:47:45.547690 | controller | crb: using metadata from Mon 17 Nov 2025 10:32:16 AM EST. 2025-11-21 11:47:45.547706 | controller | repo: downloading from remote: extras-common 2025-11-21 11:47:45.547723 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-11-21 11:47:45.547739 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-11-21 11:47:45.547755 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-11-21 11:47:45.547770 | controller | Completion plugin: Generating completion cache... 2025-11-21 11:47:45.547787 | controller | Metadata cache created. 2025-11-21 11:47:45.547811 | controller | ok: Item: dnf makecache -v Runtime: 0:00:12.842015 2025-11-21 11:47:45.574106 | 2025-11-21 11:47:45.574445 | PLAY RECAP 2025-11-21 11:47:45.574524 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-11-21 11:47:45.574580 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-21 11:47:45.574619 | 2025-11-21 11:47:45.706177 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-21 11:47:45.706968 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-21 11:47:46.282955 | 2025-11-21 11:47:46.283092 | PLAY [all] 2025-11-21 11:47:46.303801 | 2025-11-21 11:47:46.303884 | TASK [Install binary dependencies] 2025-11-21 11:47:46.389882 | controller | ok 2025-11-21 11:47:46.424425 | 2025-11-21 11:47:46.424564 | TASK [bindep : Include find tasks] 2025-11-21 11:47:46.467570 | controller | ok 2025-11-21 11:47:46.480464 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-21 11:47:46.490593 | 2025-11-21 11:47:46.490695 | TASK [bindep : Look for bindep.txt] 2025-11-21 11:47:46.885569 | controller | ok 2025-11-21 11:47:46.903010 | 2025-11-21 11:47:46.903185 | TASK [bindep : Define bindep_file fact] 2025-11-21 11:47:46.934419 | controller | ok 2025-11-21 11:47:46.944048 | 2025-11-21 11:47:46.944177 | TASK [bindep : Look for other-requirements.txt] 2025-11-21 11:47:46.968007 | controller | skipping: Conditional result was False 2025-11-21 11:47:46.976924 | 2025-11-21 11:47:46.977037 | TASK [bindep : Define bindep_file fact] 2025-11-21 11:47:47.002958 | controller | skipping: Conditional result was False 2025-11-21 11:47:47.012711 | 2025-11-21 11:47:47.012847 | TASK [bindep : Look for bindep fallback file] 2025-11-21 11:47:47.038828 | controller | skipping: Conditional result was False 2025-11-21 11:47:47.049652 | 2025-11-21 11:47:47.049795 | TASK [bindep : Define bindep_file fact] 2025-11-21 11:47:47.073944 | controller | skipping: Conditional result was False 2025-11-21 11:47:47.081207 | 2025-11-21 11:47:47.081315 | TASK [bindep : Include bindep tasks] 2025-11-21 11:47:47.110054 | controller | ok 2025-11-21 11:47:47.117276 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-11-21 11:47:47.129710 | 2025-11-21 11:47:47.129856 | TASK [bindep : Look for bindep command] 2025-11-21 11:47:47.155721 | controller | skipping: Conditional result was False 2025-11-21 11:47:47.169222 | 2025-11-21 11:47:47.169370 | TASK [bindep : Check for system bindep] 2025-11-21 11:47:47.717297 | controller | ok: Runtime: 0:00:00.005088 2025-11-21 11:47:47.723667 | 2025-11-21 11:47:47.723734 | TASK [bindep : Define bindep_command fact] 2025-11-21 11:47:47.758280 | controller | skipping: Conditional result was False 2025-11-21 11:47:47.764392 | 2025-11-21 11:47:47.764462 | TASK [bindep : Include install tasks] 2025-11-21 11:47:47.811499 | controller | ok 2025-11-21 11:47:47.830662 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-11-21 11:47:47.851872 | 2025-11-21 11:47:47.852069 | TASK [bindep : Create temp dir for bindep] 2025-11-21 11:47:48.219433 | controller | changed 2025-11-21 11:47:48.225075 | 2025-11-21 11:47:48.225194 | TASK [Ensure we have pip dependencies] 2025-11-21 11:47:48.244940 | controller | ok 2025-11-21 11:47:48.272300 | 2025-11-21 11:47:48.272432 | TASK [ensure-pip : Check if pip is installed] 2025-11-21 06:47:48.542870 | controller | /usr/bin/pip3 2025-11-21 06:47:48.564296 | controller | /usr/bin/python3: No module named wheel 2025-11-21 11:47:48.802786 | controller | ok: Runtime: 0:00:00.030279 2025-11-21 11:47:48.811298 | 2025-11-21 11:47:48.811392 | LOOP [ensure-pip : Install pip from packages] 2025-11-21 11:47:48.842678 | controller | ok: "/var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-11-21 11:47:48.858702 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-11-21 11:47:48.869174 | 2025-11-21 11:47:48.869235 | TASK [ensure-pip : Install Python 3 pip] 2025-11-21 11:47:51.943073 | controller | changed 2025-11-21 11:47:51.948319 | 2025-11-21 11:47:51.948385 | TASK [ensure-pip : Check for EPEL repository] 2025-11-21 11:47:52.025141 | controller | skipping: Conditional result was False 2025-11-21 11:47:52.031419 | 2025-11-21 11:47:52.031533 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-11-21 11:47:52.067388 | controller | skipping: Conditional result was False 2025-11-21 11:47:52.073620 | 2025-11-21 11:47:52.073707 | TASK [ensure-pip : Install Python 2 pip] 2025-11-21 11:47:52.108901 | controller | skipping: Conditional result was False 2025-11-21 11:47:52.114936 | 2025-11-21 11:47:52.115005 | TASK [ensure-pip : Ensure setuptools] 2025-11-21 11:47:52.128941 | controller | skipping: Conditional result was False 2025-11-21 11:47:52.135442 | 2025-11-21 11:47:52.135515 | TASK [ensure-pip : Check for ensurepip module] 2025-11-21 11:47:52.691653 | controller | skipping: Conditional result was False 2025-11-21 11:47:52.704448 | 2025-11-21 11:47:52.704605 | TASK [ensure-pip : Ensure python3-venv] 2025-11-21 11:47:52.731510 | controller | skipping: Conditional result was False 2025-11-21 11:47:52.744930 | 2025-11-21 11:47:52.745131 | TASK [ensure-pip : Install pip from source] 2025-11-21 11:47:52.772417 | controller | skipping: Conditional result was False 2025-11-21 11:47:52.784878 | 2025-11-21 11:47:52.785200 | TASK [ensure-pip : Probe for venv python full path] 2025-11-21 06:47:53.076949 | controller | /usr/bin/python3 2025-11-21 11:47:53.333701 | controller | ok: Runtime: 0:00:00.005162 2025-11-21 11:47:53.355071 | 2025-11-21 11:47:53.355249 | TASK [ensure-pip : Set host default] 2025-11-21 11:47:53.437528 | controller | ok 2025-11-21 11:47:53.443323 | 2025-11-21 11:47:53.443446 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-11-21 11:47:53.507726 | controller | ok 2025-11-21 11:47:53.519212 | 2025-11-21 11:47:53.519345 | TASK [bindep : Install bindep into temporary venv] 2025-11-21 11:47:59.348975 | controller | changed 2025-11-21 11:47:59.362401 | 2025-11-21 11:47:59.362578 | TASK [bindep : Define bindep_command] 2025-11-21 11:47:59.398683 | controller | ok 2025-11-21 11:47:59.408166 | 2025-11-21 11:47:59.408299 | LOOP [bindep : Include package tasks] 2025-11-21 11:47:59.475912 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-11-21 11:47:59.476466 | controller | ok: All items complete 2025-11-21 11:47:59.476505 | 2025-11-21 11:47:59.495461 | controller | included: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-11-21 11:47:59.505709 | 2025-11-21 11:47:59.505777 | TASK [bindep : Define bindep_run fact] 2025-11-21 11:47:59.544897 | controller | ok 2025-11-21 11:47:59.553359 | 2025-11-21 11:47:59.553420 | TASK [bindep : Get list of packages to install from bindep] 2025-11-21 06:48:00.971959 | controller | podman 2025-11-21 06:48:01.013042 | controller | python3-jmespath 2025-11-21 06:48:01.013189 | controller | python3-libvirt 2025-11-21 06:48:01.013201 | controller | python3-lxml 2025-11-21 06:48:01.013210 | controller | python3-netaddr 2025-11-21 11:48:01.098341 | controller | ok: Runtime: 0:00:01.132654 2025-11-21 11:48:01.108443 | 2025-11-21 11:48:01.108558 | TASK [bindep : Install distro packages from bindep] 2025-11-21 11:49:21.776624 | controller | changed 2025-11-21 11:49:21.789048 | 2025-11-21 11:49:21.789229 | TASK [bindep : Check that packages are installed] 2025-11-21 11:49:23.335525 | controller | ok: Runtime: 0:00:01.161237 2025-11-21 11:49:23.349162 | 2025-11-21 11:49:23.349352 | TASK [bindep : Fail if we cannot install all packages] 2025-11-21 11:49:23.386949 | controller | skipping: Conditional result was False 2025-11-21 11:49:23.415047 | 2025-11-21 11:49:23.415239 | TASK [Run test-setup role] 2025-11-21 11:49:23.439746 | controller | ok 2025-11-21 11:49:23.467548 | 2025-11-21 11:49:23.467692 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-21 11:49:23.710084 | controller | ok 2025-11-21 11:49:23.735340 | 2025-11-21 11:49:23.735522 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-21 11:49:24.274379 | controller | skipping: Conditional result was False 2025-11-21 11:49:24.328265 | 2025-11-21 11:49:24.328418 | TASK [bindep : Remove bindep temp dir] 2025-11-21 11:49:24.737501 | controller | ok 2025-11-21 11:49:24.761406 | 2025-11-21 11:49:24.761528 | PLAY RECAP 2025-11-21 11:49:24.761581 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-11-21 11:49:24.761608 | 2025-11-21 11:49:24.885123 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-21 11:49:24.885990 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-21 11:49:25.490539 | 2025-11-21 11:49:25.490669 | PLAY [all] 2025-11-21 11:49:25.511650 | 2025-11-21 11:49:25.511779 | TASK [Abort when test_command variable is undefined] 2025-11-21 11:49:25.547440 | controller | skipping: Conditional result was False 2025-11-21 11:49:25.554565 | 2025-11-21 11:49:25.554662 | TASK [Convert test_command to list] 2025-11-21 11:49:25.628971 | controller | skipping: Conditional result was False 2025-11-21 11:49:25.641000 | 2025-11-21 11:49:25.641192 | TASK [Use test_command list] 2025-11-21 11:49:25.720902 | controller | ok 2025-11-21 11:49:25.733284 | 2025-11-21 11:49:25.733437 | LOOP [Run test_command] 2025-11-21 11:49:26.157610 | controller | no check to run 2025-11-21 11:49:26.157943 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004431 2025-11-21 11:49:26.206464 | 2025-11-21 11:49:26.206638 | PLAY RECAP 2025-11-21 11:49:26.206722 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-21 11:49:26.206766 | 2025-11-21 11:49:26.337518 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-21 11:49:26.339518 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-21 11:49:26.989105 | 2025-11-21 11:49:26.989230 | PLAY [all] 2025-11-21 11:49:27.009276 | 2025-11-21 11:49:27.009369 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-21 11:49:27.376791 | controller | changed: non-zero return code 2025-11-21 11:49:27.393305 | 2025-11-21 11:49:27.393568 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-21 11:49:27.421803 | controller | skipping: Conditional result was False 2025-11-21 11:49:27.434156 | 2025-11-21 11:49:27.434301 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-21 11:49:27.475668 | 2025-11-21 11:49:27.475961 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-21 11:49:27.516001 | 2025-11-21 11:49:27.516295 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-21 11:49:27.543390 | controller | skipping: Conditional result was False 2025-11-21 11:49:27.556766 | 2025-11-21 11:49:27.556976 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-21 11:49:27.600913 | 2025-11-21 11:49:27.601338 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-21 11:49:27.629299 | controller | skipping: Conditional result was False 2025-11-21 11:49:27.641462 | 2025-11-21 11:49:27.641597 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-21 11:49:27.669418 | controller | skipping: Conditional result was False 2025-11-21 11:49:27.683000 | 2025-11-21 11:49:27.683173 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-21 11:49:27.710462 | controller | skipping: Conditional result was False 2025-11-21 11:49:27.756716 | 2025-11-21 11:49:27.756804 | PLAY RECAP 2025-11-21 11:49:27.756857 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-21 11:49:27.756884 | 2025-11-21 11:49:27.867853 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-21 11:49:27.868685 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-21 11:49:28.469086 | 2025-11-21 11:49:28.469217 | PLAY [all] 2025-11-21 11:49:28.489070 | 2025-11-21 11:49:28.489182 | TASK [include_role : fetch-output] 2025-11-21 11:49:28.528467 | controller | ok 2025-11-21 11:49:28.546662 | 2025-11-21 11:49:28.546776 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-21 11:49:28.621897 | controller | skipping: Conditional result was False 2025-11-21 11:49:28.627830 | 2025-11-21 11:49:28.627909 | TASK [fetch-output : Set log path for single node] 2025-11-21 11:49:28.677206 | controller | ok 2025-11-21 11:49:28.682755 | 2025-11-21 11:49:28.682827 | LOOP [fetch-output : Ensure local output dirs] 2025-11-21 11:49:29.096748 | controller -> localhost | ok: "/var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/logs" 2025-11-21 11:49:29.331788 | controller -> localhost | changed: "/var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/artifacts" 2025-11-21 11:49:29.543410 | controller -> localhost | changed: "/var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/docs" 2025-11-21 11:49:29.562254 | 2025-11-21 11:49:29.562399 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-21 11:49:30.194684 | controller | changed: .d..t...... ./ 2025-11-21 11:49:30.195077 | controller | changed: All items complete 2025-11-21 11:49:30.195174 | 2025-11-21 11:49:30.722159 | controller | changed: .d..t...... ./ 2025-11-21 11:49:31.213136 | controller | changed: .d..t...... ./ 2025-11-21 11:49:31.239587 | 2025-11-21 11:49:31.239715 | TASK [include_role : fetch-output-openshift] 2025-11-21 11:49:31.256964 | controller | skipping: Conditional result was False 2025-11-21 11:49:31.267980 | 2025-11-21 11:49:31.268181 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-21 11:49:31.713662 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.011447 2025-11-21 11:49:32.005311 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013032 2025-11-21 11:49:32.045125 | 2025-11-21 11:49:32.045249 | PLAY [all] 2025-11-21 11:49:32.059762 | 2025-11-21 11:49:32.059836 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-11-21 11:49:32.553815 | controller | changed 2025-11-21 11:49:32.583273 | 2025-11-21 11:49:32.583382 | PLAY RECAP 2025-11-21 11:49:32.583425 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-21 11:49:32.583447 | 2025-11-21 11:49:32.695884 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-21 11:49:32.696880 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-11-21 11:49:33.355728 | 2025-11-21 11:49:33.355825 | PLAY [localhost] 2025-11-21 11:49:33.374062 | 2025-11-21 11:49:33.374177 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-21 11:49:33.768934 | localhost | changed 2025-11-21 11:49:33.773658 | 2025-11-21 11:49:33.773736 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-21 11:49:33.815817 | localhost | ok 2025-11-21 11:49:33.824819 | 2025-11-21 11:49:33.824916 | TASK [add-fileserver : Create SSH private key tempfile] 2025-11-21 11:49:34.200939 | localhost | changed 2025-11-21 11:49:34.206999 | 2025-11-21 11:49:34.207108 | TASK [add-fileserver : Create SSH private key from secret] 2025-11-21 11:49:34.883886 | localhost | changed 2025-11-21 11:49:34.894741 | 2025-11-21 11:49:34.894885 | TASK [add-fileserver : Add fileserver ssh key] 2025-11-21 11:49:35.311812 | localhost | Identity added: /var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/tmp/ansible.h98mfb_b (/var/lib/zuul/builds/8962c1c486e44067b2d8a09f66002b8c/work/tmp/ansible.h98mfb_b) 2025-11-21 11:49:35.312086 | localhost | ok: Runtime: 0:00:00.012693 2025-11-21 11:49:35.316389 | 2025-11-21 11:49:35.316456 | TASK [add-fileserver : Remove SSH private key from disk] 2025-11-21 11:49:35.673374 | localhost | ok: Runtime: 0:00:00.009261 2025-11-21 11:49:35.680902 | 2025-11-21 11:49:35.680993 | TASK [add-fileserver : Add fileserver to inventory] 2025-11-21 11:49:35.731912 | localhost | changed 2025-11-21 11:49:35.738506 | 2025-11-21 11:49:35.738601 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-11-21 11:49:36.132803 | localhost | changed 2025-11-21 11:49:36.153368 | 2025-11-21 11:49:36.153457 | PLAY [localhost] 2025-11-21 11:49:36.165819 | 2025-11-21 11:49:36.165894 | TASK [Generate bulk log download script] 2025-11-21 11:49:36.185576 | localhost | ok 2025-11-21 11:49:36.197962 | 2025-11-21 11:49:36.198058 | TASK [local-log-download : Check API endpoint is defined] 2025-11-21 11:49:36.245869 | localhost | ok: All assertions passed 2025-11-21 11:49:36.250448 | 2025-11-21 11:49:36.250512 | TASK [local-log-download : Create download script] 2025-11-21 11:49:36.702394 | localhost -> localhost | changed 2025-11-21 11:49:36.713356 | 2025-11-21 11:49:36.713475 | TASK [Register quick-download link] 2025-11-21 11:49:36.732134 | localhost | ok 2025-11-21 11:49:36.773040 | 2025-11-21 11:49:36.773150 | PLAY [logserver.rdoproject.org] 2025-11-21 11:49:36.782646 | 2025-11-21 11:49:36.782709 | TASK [Set zuul-log-path fact] 2025-11-21 11:49:36.799158 | logserver.rdoproject.org | ok 2025-11-21 11:49:36.808652 | 2025-11-21 11:49:36.808720 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-21 11:49:36.844541 | logserver.rdoproject.org | ok 2025-11-21 11:49:36.850132 | 2025-11-21 11:49:36.850194 | TASK [upload-logs : Create log directories] 2025-11-21 11:49:37.839271 | logserver.rdoproject.org | changed 2025-11-21 11:49:37.846558 | 2025-11-21 11:49:37.846698 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-11-21 11:49:38.195626 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008730 2025-11-21 11:49:38.205365 | 2025-11-21 11:49:38.205515 | TASK [upload-logs : Upload logs to log server] 2025-11-21 11:49:38.972594 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-11-21 11:49:38.976746 | 2025-11-21 11:49:38.976833 | LOOP [upload-logs : Compress console log and json output] 2025-11-21 11:49:39.032738 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-21 11:49:39.044724 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-21 11:49:39.058902 | 2025-11-21 11:49:39.059084 | LOOP [upload-logs : Upload compressed console log and json output] 2025-11-21 11:49:39.103073 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-21 11:49:39.103529 | 2025-11-21 11:49:39.106503 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-21 11:49:39.117933 | 2025-11-21 11:49:39.118082 | LOOP [upload-logs : Upload console log and json output]