2025-10-03 04:00:11.055674 | Job console starting... 2025-10-03 04:00:11.073213 | Updating repositories 2025-10-03 04:00:11.108965 | Preparing job workspace 2025-10-03 04:00:15.252805 | Running Ansible setup... 2025-10-03 04:00:20.262995 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 04:00:20.942824 | 2025-10-03 04:00:20.942998 | PLAY [localhost] 2025-10-03 04:00:20.964405 | 2025-10-03 04:00:20.964516 | TASK [Gathering Facts] 2025-10-03 04:00:21.990761 | localhost | ok 2025-10-03 04:00:22.016529 | 2025-10-03 04:00:22.016697 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-03 04:00:22.432024 | localhost -> localhost | changed 2025-10-03 04:00:22.437809 | 2025-10-03 04:00:22.437929 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-03 04:00:23.342054 | localhost -> localhost | changed 2025-10-03 04:00:23.357033 | 2025-10-03 04:00:23.357149 | TASK [Setup log path fact] 2025-10-03 04:00:23.377177 | localhost | ok 2025-10-03 04:00:23.389224 | 2025-10-03 04:00:23.389306 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 04:00:23.417236 | localhost | ok 2025-10-03 04:00:23.425471 | 2025-10-03 04:00:23.425567 | TASK [emit-job-header : Print job information] 2025-10-03 04:00:23.463677 | # Job Information 2025-10-03 04:00:23.463854 | Ansible Version: 2.15.12 2025-10-03 04:00:23.463881 | Job: cifmw-molecule-ipa 2025-10-03 04:00:23.463900 | Pipeline: github-check 2025-10-03 04:00:23.463918 | Executor: ze03.softwarefactory-project.io 2025-10-03 04:00:23.463935 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-03 04:00:23.463953 | Log URL (when completed): https://logserver.rdoproject.org/228/rdoproject.org/2289a5a7f52b4c5299ae5d2acf93aaa1/ 2025-10-03 04:00:23.463970 | Event ID: 3daecbd0-a00d-11f0-93f4-31ce34c57105 2025-10-03 04:00:23.469463 | 2025-10-03 04:00:23.470065 | LOOP [emit-job-header : Print node information] 2025-10-03 04:00:23.584016 | localhost | ok: 2025-10-03 04:00:23.584173 | localhost | # Node Information 2025-10-03 04:00:23.584200 | localhost | Inventory Hostname: controller 2025-10-03 04:00:23.584224 | localhost | Hostname: np0005467697 2025-10-03 04:00:23.584243 | localhost | Username: zuul 2025-10-03 04:00:23.584263 | localhost | Distro: CentOS 9 2025-10-03 04:00:23.584281 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-03 04:00:23.584298 | localhost | Region: RegionOne 2025-10-03 04:00:23.584314 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-03 04:00:23.584330 | localhost | Product Name: OpenStack Nova 2025-10-03 04:00:23.584346 | localhost | Interface IP: 38.102.83.201 2025-10-03 04:00:23.610148 | 2025-10-03 04:00:23.610257 | PLAY [all] 2025-10-03 04:00:23.616895 | 2025-10-03 04:00:23.616959 | TASK [Gather network facts] 2025-10-03 04:00:24.102283 | controller | ok 2025-10-03 04:00:24.118087 | 2025-10-03 04:00:24.118211 | TASK [include_role : start-zuul-console] 2025-10-03 04:00:24.138139 | controller | ok 2025-10-03 04:00:24.150515 | 2025-10-03 04:00:24.150626 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-03 04:00:24.546295 | controller | ok 2025-10-03 04:00:24.555708 | 2025-10-03 04:00:24.555838 | TASK [include_role : add-build-sshkey] 2025-10-03 04:00:24.585107 | controller | ok 2025-10-03 04:00:24.612591 | 2025-10-03 04:00:24.612713 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-03 04:00:24.918167 | controller -> localhost | ok 2025-10-03 04:00:24.931779 | 2025-10-03 04:00:24.932909 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-03 04:00:25.004993 | controller | ok 2025-10-03 04:00:25.021297 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-03 04:00:25.029236 | 2025-10-03 04:00:25.029332 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-03 04:00:25.504407 | controller -> localhost | Generating public/private rsa key pair. 2025-10-03 04:00:25.504581 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/2289a5a7f52b4c5299ae5d2acf93aaa1_id_rsa. 2025-10-03 04:00:25.504612 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/2289a5a7f52b4c5299ae5d2acf93aaa1_id_rsa.pub. 2025-10-03 04:00:25.504634 | controller -> localhost | The key fingerprint is: 2025-10-03 04:00:25.504653 | controller -> localhost | SHA256:qwj72cE8JmMb+T8UBz+Q9eB3BzpuDbnSES10uaAYM4c zuul-build-sshkey 2025-10-03 04:00:25.504671 | controller -> localhost | The key's randomart image is: 2025-10-03 04:00:25.504690 | controller -> localhost | +---[RSA 3072]----+ 2025-10-03 04:00:25.504706 | controller -> localhost | | +o.o.o. | 2025-10-03 04:00:25.504740 | controller -> localhost | | E..oo=o. | 2025-10-03 04:00:25.504763 | controller -> localhost | | X..Oo...| 2025-10-03 04:00:25.504782 | controller -> localhost | | o =+ B.. | 2025-10-03 04:00:25.504799 | controller -> localhost | | So..= . | 2025-10-03 04:00:25.504816 | controller -> localhost | | + .. o | 2025-10-03 04:00:25.504833 | controller -> localhost | | . * *.. | 2025-10-03 04:00:25.504850 | controller -> localhost | | + @ +. | 2025-10-03 04:00:25.504867 | controller -> localhost | | ..= +... | 2025-10-03 04:00:25.504884 | controller -> localhost | +----[SHA256]-----+ 2025-10-03 04:00:25.504927 | controller -> localhost | ok: Runtime: 0:00:00.097869 2025-10-03 04:00:25.510524 | 2025-10-03 04:00:25.510587 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-03 04:00:25.529188 | controller | ok 2025-10-03 04:00:25.540798 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-03 04:00:25.549951 | 2025-10-03 04:00:25.550012 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-03 04:00:25.565862 | controller | skipping: Conditional result was False 2025-10-03 04:00:25.571250 | 2025-10-03 04:00:25.571315 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-03 04:00:26.027165 | controller | changed 2025-10-03 04:00:26.037096 | 2025-10-03 04:00:26.037305 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-03 04:00:26.310484 | controller | ok 2025-10-03 04:00:26.315573 | 2025-10-03 04:00:26.315639 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-03 04:00:27.176833 | controller | changed 2025-10-03 04:00:27.182910 | 2025-10-03 04:00:27.183000 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-03 04:00:28.063938 | controller | changed 2025-10-03 04:00:28.069484 | 2025-10-03 04:00:28.069631 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-03 04:00:28.093551 | controller | skipping: Conditional result was False 2025-10-03 04:00:28.108592 | 2025-10-03 04:00:28.108686 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-03 04:00:28.552484 | controller -> localhost | changed 2025-10-03 04:00:28.564317 | 2025-10-03 04:00:28.564429 | TASK [add-build-sshkey : Add back temp key] 2025-10-03 04:00:28.848153 | controller -> localhost | Identity added: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/2289a5a7f52b4c5299ae5d2acf93aaa1_id_rsa (zuul-build-sshkey) 2025-10-03 04:00:28.848485 | controller -> localhost | ok: Runtime: 0:00:00.008199 2025-10-03 04:00:28.861135 | 2025-10-03 04:00:28.861288 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-03 04:00:29.332929 | controller | ok 2025-10-03 04:00:29.338773 | 2025-10-03 04:00:29.338838 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-03 04:00:29.362873 | controller | skipping: Conditional result was False 2025-10-03 04:00:29.382374 | 2025-10-03 04:00:29.382491 | TASK [include_role : validate-host] 2025-10-03 04:00:29.425990 | controller | ok 2025-10-03 04:00:29.456054 | 2025-10-03 04:00:29.456169 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-03 04:00:29.512187 | controller | ok 2025-10-03 04:00:29.516926 | 2025-10-03 04:00:29.516987 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-03 04:00:29.735109 | controller -> localhost | ok 2025-10-03 04:00:29.741112 | 2025-10-03 04:00:29.741199 | TASK [validate-host : Collect information about the host] 2025-10-03 04:00:30.589653 | controller | ok 2025-10-03 04:00:30.597839 | 2025-10-03 04:00:30.597900 | TASK [validate-host : Sanitize hostname] 2025-10-03 04:00:30.646450 | controller | ok 2025-10-03 04:00:30.651255 | 2025-10-03 04:00:30.651315 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-03 04:00:31.063295 | controller -> localhost | changed 2025-10-03 04:00:31.071248 | 2025-10-03 04:00:31.071369 | TASK [validate-host : Collect information about zuul worker] 2025-10-03 04:00:31.567398 | controller | ok 2025-10-03 04:00:31.572443 | 2025-10-03 04:00:31.572517 | TASK [validate-host : Write out all zuul information for each host] 2025-10-03 04:00:32.030038 | controller -> localhost | changed 2025-10-03 04:00:32.039337 | 2025-10-03 04:00:32.039401 | TASK [include_role : prepare-workspace-openshift] 2025-10-03 04:00:32.063983 | controller | skipping: Conditional result was False 2025-10-03 04:00:32.069130 | 2025-10-03 04:00:32.069193 | TASK [include_role : remove-zuul-sshkey] 2025-10-03 04:00:32.083126 | controller | skipping: Conditional result was False 2025-10-03 04:00:32.088379 | 2025-10-03 04:00:32.088453 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 04:00:32.363961 | controller | ok: "logs" 2025-10-03 04:00:32.364264 | controller | ok: All items complete 2025-10-03 04:00:32.364304 | 2025-10-03 04:00:32.602194 | controller | ok: "artifacts" 2025-10-03 04:00:32.824803 | controller | ok: "docs" 2025-10-03 04:00:32.839378 | 2025-10-03 04:00:32.839566 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 04:00:33.144630 | controller | changed: "logs" 2025-10-03 04:00:34.206613 | controller | changed: "artifacts" 2025-10-03 04:00:34.442817 | controller | changed: "docs" 2025-10-03 04:00:34.470443 | 2025-10-03 04:00:34.470538 | PLAY RECAP 2025-10-03 04:00:34.470577 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-03 04:00:34.470602 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 04:00:34.470620 | 2025-10-03 04:00:34.592637 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 04:00:34.593844 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 04:00:35.270579 | 2025-10-03 04:00:35.270717 | PLAY [localhost] 2025-10-03 04:00:35.309906 | 2025-10-03 04:00:35.310046 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-03 04:00:35.740846 | localhost | ok 2025-10-03 04:00:35.748701 | 2025-10-03 04:00:35.748872 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-03 04:00:36.478424 | localhost | changed 2025-10-03 04:00:36.508025 | 2025-10-03 04:00:36.508127 | PLAY [all] 2025-10-03 04:00:36.523809 | 2025-10-03 04:00:36.523919 | TASK [include_role : prepare-workspace] 2025-10-03 04:00:36.543301 | controller | ok 2025-10-03 04:00:36.557861 | 2025-10-03 04:00:36.557975 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-03 04:00:36.929394 | controller | ok 2025-10-03 04:00:36.941565 | 2025-10-03 04:00:36.941630 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-03 04:00:38.771415 | controller | Output suppressed because no_log was given 2025-10-03 04:00:38.780696 | 2025-10-03 04:00:38.780795 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 04:00:39.064653 | controller | changed: "logs" 2025-10-03 04:00:39.291927 | controller | changed: "artifacts" 2025-10-03 04:00:39.508330 | controller | changed: "docs" 2025-10-03 04:00:39.527085 | 2025-10-03 04:00:39.527268 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 04:00:39.841570 | controller | changed: "logs" 2025-10-03 04:00:39.842099 | controller | changed: All items complete 2025-10-03 04:00:39.842169 | 2025-10-03 04:00:40.069552 | controller | changed: "artifacts" 2025-10-03 04:00:40.325350 | controller | changed: "docs" 2025-10-03 04:00:40.342334 | 2025-10-03 04:00:40.342524 | TASK [Check if worker can sudo] 2025-10-03 04:00:40.892092 | controller | ok: Runtime: 0:00:00.051075 2025-10-03 04:00:40.903956 | 2025-10-03 04:00:40.904094 | TASK [configure-mirrors : Gather needed facts] 2025-10-03 04:00:40.982637 | controller | skipping: Conditional result was False 2025-10-03 04:00:40.995454 | 2025-10-03 04:00:40.995611 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-03 04:00:41.074850 | controller | ok 2025-10-03 04:00:41.092116 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-03 04:00:41.105305 | 2025-10-03 04:00:41.105447 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-03 04:00:41.493652 | controller | ok 2025-10-03 04:00:41.501813 | 2025-10-03 04:00:41.501910 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-03 04:00:41.565124 | controller | ok: "/var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-03 04:00:41.578621 | 2025-10-03 04:00:41.578769 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-03 04:00:42.605996 | controller | changed 2025-10-03 04:00:42.619889 | 2025-10-03 04:00:42.620062 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-03 04:00:42.703190 | controller | ok: "/var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-03 04:00:42.703513 | controller | ok: All items complete 2025-10-03 04:00:42.703570 | 2025-10-03 04:00:42.777332 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-03 04:00:42.784257 | 2025-10-03 04:00:42.784343 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-03 04:00:43.682090 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-03 04:00:44.493483 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-03 04:00:44.513884 | 2025-10-03 04:00:44.514053 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-03 04:00:45.016574 | controller | changed: section and option added 2025-10-03 04:00:45.059981 | 2025-10-03 04:00:45.060176 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-03 04:00:46.388611 | controller | 29 files removed 2025-10-03 04:00:46.389081 | controller | ok: Item: dnf clean all Runtime: 0:00:00.982663 2025-10-03 04:00:46.389172 | controller | changed: All items complete 2025-10-03 04:00:46.389220 | 2025-10-03 04:00:57.450296 | 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-03 04:00:57.450460 | controller | DNF version: 4.14.0 2025-10-03 04:00:57.450521 | controller | cachedir: /var/cache/dnf 2025-10-03 04:00:57.450567 | controller | Making cache files for all metadata files. 2025-10-03 04:00:57.450608 | controller | baseos: has expired and will be refreshed. 2025-10-03 04:00:57.450646 | controller | appstream: has expired and will be refreshed. 2025-10-03 04:00:57.450683 | controller | crb: has expired and will be refreshed. 2025-10-03 04:00:57.450766 | controller | extras-common: has expired and will be refreshed. 2025-10-03 04:00:57.450815 | controller | repo: downloading from remote: baseos 2025-10-03 04:00:57.450853 | controller | CentOS Stream 9 - BaseOS 62 MB/s | 8.8 MB 00:00 2025-10-03 04:00:57.450889 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-03 04:00:57.450924 | controller | repo: downloading from remote: appstream 2025-10-03 04:00:57.450959 | controller | CentOS Stream 9 - AppStream 68 MB/s | 25 MB 00:00 2025-10-03 04:00:57.450994 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-03 04:00:57.451028 | controller | repo: downloading from remote: crb 2025-10-03 04:00:57.451063 | controller | CentOS Stream 9 - CRB 30 MB/s | 7.1 MB 00:00 2025-10-03 04:00:57.451098 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-03 04:00:57.451133 | controller | repo: downloading from remote: extras-common 2025-10-03 04:00:57.451169 | controller | CentOS Stream 9 - Extras packages 1.7 MB/s | 20 kB 00:00 2025-10-03 04:00:57.451204 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-03 04:00:57.451237 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-03 04:00:57.451271 | controller | Completion plugin: Generating completion cache... 2025-10-03 04:00:57.451306 | controller | Metadata cache created. 2025-10-03 04:00:57.451359 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.827257 2025-10-03 04:00:57.482251 | 2025-10-03 04:00:57.482423 | PLAY RECAP 2025-10-03 04:00:57.482504 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-03 04:00:57.482558 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 04:00:57.482596 | 2025-10-03 04:00:57.609128 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 04:00:57.609989 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 04:00:58.189205 | 2025-10-03 04:00:58.189326 | PLAY [all] 2025-10-03 04:00:58.209245 | 2025-10-03 04:00:58.209323 | TASK [Install binary dependencies] 2025-10-03 04:00:58.268259 | controller | ok 2025-10-03 04:00:58.286303 | 2025-10-03 04:00:58.286379 | TASK [bindep : Include find tasks] 2025-10-03 04:00:58.324961 | controller | ok 2025-10-03 04:00:58.338258 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-03 04:00:58.343970 | 2025-10-03 04:00:58.344033 | TASK [bindep : Look for bindep.txt] 2025-10-03 04:00:58.784579 | controller | ok 2025-10-03 04:00:58.798214 | 2025-10-03 04:00:58.798357 | TASK [bindep : Define bindep_file fact] 2025-10-03 04:00:58.845277 | controller | ok 2025-10-03 04:00:58.856200 | 2025-10-03 04:00:58.856332 | TASK [bindep : Look for other-requirements.txt] 2025-10-03 04:00:58.883240 | controller | skipping: Conditional result was False 2025-10-03 04:00:58.894902 | 2025-10-03 04:00:58.895039 | TASK [bindep : Define bindep_file fact] 2025-10-03 04:00:58.921863 | controller | skipping: Conditional result was False 2025-10-03 04:00:58.933664 | 2025-10-03 04:00:58.933847 | TASK [bindep : Look for bindep fallback file] 2025-10-03 04:00:58.960775 | controller | skipping: Conditional result was False 2025-10-03 04:00:58.974189 | 2025-10-03 04:00:58.974341 | TASK [bindep : Define bindep_file fact] 2025-10-03 04:00:59.001101 | controller | skipping: Conditional result was False 2025-10-03 04:00:59.012909 | 2025-10-03 04:00:59.013033 | TASK [bindep : Include bindep tasks] 2025-10-03 04:00:59.052590 | controller | ok 2025-10-03 04:00:59.066089 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-03 04:00:59.079131 | 2025-10-03 04:00:59.079213 | TASK [bindep : Look for bindep command] 2025-10-03 04:00:59.104289 | controller | skipping: Conditional result was False 2025-10-03 04:00:59.116857 | 2025-10-03 04:00:59.116991 | TASK [bindep : Check for system bindep] 2025-10-03 04:00:59.660097 | controller | ok: Runtime: 0:00:00.005434 2025-10-03 04:00:59.671540 | 2025-10-03 04:00:59.671673 | TASK [bindep : Define bindep_command fact] 2025-10-03 04:00:59.708050 | controller | skipping: Conditional result was False 2025-10-03 04:00:59.720132 | 2025-10-03 04:00:59.720262 | TASK [bindep : Include install tasks] 2025-10-03 04:00:59.767293 | controller | ok 2025-10-03 04:00:59.783666 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-03 04:00:59.799712 | 2025-10-03 04:00:59.799822 | TASK [bindep : Create temp dir for bindep] 2025-10-03 04:01:00.212103 | controller | changed 2025-10-03 04:01:00.223590 | 2025-10-03 04:01:00.223709 | TASK [Ensure we have pip dependencies] 2025-10-03 04:01:00.252090 | controller | ok 2025-10-03 04:01:00.293178 | 2025-10-03 04:01:00.293274 | TASK [ensure-pip : Check if pip is installed] 2025-10-03 00:01:00.562063 | controller | /usr/bin/pip3 2025-10-03 00:01:00.593057 | controller | /usr/bin/python3: No module named wheel 2025-10-03 04:01:00.827362 | controller | ok: Runtime: 0:00:00.042129 2025-10-03 04:01:00.840013 | 2025-10-03 04:01:00.840212 | LOOP [ensure-pip : Install pip from packages] 2025-10-03 04:01:00.871397 | controller | ok: "/var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-03 04:01:00.892958 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-03 04:01:00.914823 | 2025-10-03 04:01:00.914983 | TASK [ensure-pip : Install Python 3 pip] 2025-10-03 04:01:03.122152 | controller | changed 2025-10-03 04:01:03.135792 | 2025-10-03 04:01:03.135918 | TASK [ensure-pip : Check for EPEL repository] 2025-10-03 04:01:03.182084 | controller | skipping: Conditional result was False 2025-10-03 04:01:03.188222 | 2025-10-03 04:01:03.188288 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-03 04:01:03.232738 | controller | skipping: Conditional result was False 2025-10-03 04:01:03.238778 | 2025-10-03 04:01:03.238854 | TASK [ensure-pip : Install Python 2 pip] 2025-10-03 04:01:03.273926 | controller | skipping: Conditional result was False 2025-10-03 04:01:03.280205 | 2025-10-03 04:01:03.280542 | TASK [ensure-pip : Ensure setuptools] 2025-10-03 04:01:03.306668 | controller | skipping: Conditional result was False 2025-10-03 04:01:03.314869 | 2025-10-03 04:01:03.324804 | TASK [ensure-pip : Check for ensurepip module] 2025-10-03 04:01:03.862599 | controller | skipping: Conditional result was False 2025-10-03 04:01:03.868594 | 2025-10-03 04:01:03.868662 | TASK [ensure-pip : Ensure python3-venv] 2025-10-03 04:01:03.892350 | controller | skipping: Conditional result was False 2025-10-03 04:01:03.898640 | 2025-10-03 04:01:03.898707 | TASK [ensure-pip : Install pip from source] 2025-10-03 04:01:03.915686 | controller | skipping: Conditional result was False 2025-10-03 04:01:03.921438 | 2025-10-03 04:01:03.921503 | TASK [ensure-pip : Probe for venv python full path] 2025-10-03 00:01:04.153213 | controller | /usr/bin/python3 2025-10-03 04:01:04.457619 | controller | ok: Runtime: 0:00:00.006496 2025-10-03 04:01:04.463802 | 2025-10-03 04:01:04.463873 | TASK [ensure-pip : Set host default] 2025-10-03 04:01:04.543839 | controller | ok 2025-10-03 04:01:04.549299 | 2025-10-03 04:01:04.549368 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-03 04:01:04.599645 | controller | ok 2025-10-03 04:01:04.609902 | 2025-10-03 04:01:04.609966 | TASK [bindep : Install bindep into temporary venv] 2025-10-03 04:01:08.848926 | controller | changed 2025-10-03 04:01:08.854260 | 2025-10-03 04:01:08.854333 | TASK [bindep : Define bindep_command] 2025-10-03 04:01:08.884314 | controller | ok 2025-10-03 04:01:08.889893 | 2025-10-03 04:01:08.889960 | LOOP [bindep : Include package tasks] 2025-10-03 04:01:08.939542 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-03 04:01:08.939774 | controller | ok: All items complete 2025-10-03 04:01:08.939833 | 2025-10-03 04:01:08.956873 | controller | included: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-03 04:01:08.968924 | 2025-10-03 04:01:08.969043 | TASK [bindep : Define bindep_run fact] 2025-10-03 04:01:08.998443 | controller | ok 2025-10-03 04:01:09.003648 | 2025-10-03 04:01:09.003717 | TASK [bindep : Get list of packages to install from bindep] 2025-10-03 00:01:10.417767 | controller | podman 2025-10-03 00:01:10.458074 | controller | python3-jmespath 2025-10-03 00:01:10.458269 | controller | python3-libvirt 2025-10-03 00:01:10.458286 | controller | python3-lxml 2025-10-03 00:01:10.458296 | controller | python3-netaddr 2025-10-03 04:01:10.567878 | controller | ok: Runtime: 0:00:01.096667 2025-10-03 04:01:10.576828 | 2025-10-03 04:01:10.576998 | TASK [bindep : Install distro packages from bindep] 2025-10-03 04:02:12.761091 | controller | changed 2025-10-03 04:02:12.773062 | 2025-10-03 04:02:12.773195 | TASK [bindep : Check that packages are installed] 2025-10-03 04:02:14.317654 | controller | ok: Runtime: 0:00:01.034957 2025-10-03 04:02:14.331062 | 2025-10-03 04:02:14.331199 | TASK [bindep : Fail if we cannot install all packages] 2025-10-03 04:02:14.366650 | controller | skipping: Conditional result was False 2025-10-03 04:02:14.383604 | 2025-10-03 04:02:14.383773 | TASK [Run test-setup role] 2025-10-03 04:02:14.441427 | controller | ok 2025-10-03 04:02:14.459300 | 2025-10-03 04:02:14.459390 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-03 04:02:14.694581 | controller | ok 2025-10-03 04:02:14.699680 | 2025-10-03 04:02:14.702777 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-03 04:02:15.255802 | controller | skipping: Conditional result was False 2025-10-03 04:02:15.282739 | 2025-10-03 04:02:15.282879 | TASK [bindep : Remove bindep temp dir] 2025-10-03 04:02:15.649087 | controller | ok 2025-10-03 04:02:15.686511 | 2025-10-03 04:02:15.686784 | PLAY RECAP 2025-10-03 04:02:15.686867 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-03 04:02:15.686896 | 2025-10-03 04:02:15.906910 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 04:02:15.908085 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 04:02:16.570042 | 2025-10-03 04:02:16.570219 | PLAY [all] 2025-10-03 04:02:16.631963 | 2025-10-03 04:02:16.632227 | TASK [Abort when test_command variable is undefined] 2025-10-03 04:02:16.679126 | controller | skipping: Conditional result was False 2025-10-03 04:02:16.687109 | 2025-10-03 04:02:16.687200 | TASK [Convert test_command to list] 2025-10-03 04:02:16.740446 | controller | skipping: Conditional result was False 2025-10-03 04:02:16.748526 | 2025-10-03 04:02:16.748602 | TASK [Use test_command list] 2025-10-03 04:02:16.800367 | controller | ok 2025-10-03 04:02:16.815266 | 2025-10-03 04:02:16.815396 | LOOP [Run test_command] 2025-10-03 04:02:17.309575 | controller | no check to run 2025-10-03 04:02:17.309789 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005180 2025-10-03 04:02:17.367432 | 2025-10-03 04:02:17.367818 | PLAY RECAP 2025-10-03 04:02:17.367872 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 04:02:17.367899 | 2025-10-03 04:02:17.583778 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 04:02:17.584876 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 04:02:18.229797 | 2025-10-03 04:02:18.229901 | PLAY [all] 2025-10-03 04:02:18.253975 | 2025-10-03 04:02:18.254058 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-03 04:02:18.578119 | controller | changed: non-zero return code 2025-10-03 04:02:18.583557 | 2025-10-03 04:02:18.583629 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-03 04:02:18.614886 | controller | skipping: Conditional result was False 2025-10-03 04:02:18.624877 | 2025-10-03 04:02:18.625009 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-03 04:02:18.647600 | 2025-10-03 04:02:18.647882 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-03 04:02:18.679656 | 2025-10-03 04:02:18.679826 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-03 04:02:18.693110 | controller | skipping: Conditional result was False 2025-10-03 04:02:18.698894 | 2025-10-03 04:02:18.698960 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-03 04:02:18.718217 | 2025-10-03 04:02:18.718388 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-03 04:02:18.743136 | controller | skipping: Conditional result was False 2025-10-03 04:02:18.750099 | 2025-10-03 04:02:18.750166 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-03 04:02:18.781243 | controller | skipping: Conditional result was False 2025-10-03 04:02:18.786922 | 2025-10-03 04:02:18.786985 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-03 04:02:18.812548 | controller | skipping: Conditional result was False 2025-10-03 04:02:18.850877 | 2025-10-03 04:02:18.850970 | PLAY RECAP 2025-10-03 04:02:18.851016 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-03 04:02:18.851042 | 2025-10-03 04:02:18.964862 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 04:02:18.965702 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 04:02:19.591494 | 2025-10-03 04:02:19.591684 | PLAY [all] 2025-10-03 04:02:19.624456 | 2025-10-03 04:02:19.624580 | TASK [include_role : fetch-output] 2025-10-03 04:02:19.689652 | controller | ok 2025-10-03 04:02:19.725297 | 2025-10-03 04:02:19.725436 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-03 04:02:19.790189 | controller | skipping: Conditional result was False 2025-10-03 04:02:19.796212 | 2025-10-03 04:02:19.796280 | TASK [fetch-output : Set log path for single node] 2025-10-03 04:02:19.849270 | controller | ok 2025-10-03 04:02:19.854425 | 2025-10-03 04:02:19.854492 | LOOP [fetch-output : Ensure local output dirs] 2025-10-03 04:02:20.308125 | controller -> localhost | ok: "/var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/logs" 2025-10-03 04:02:20.535045 | controller -> localhost | changed: "/var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/artifacts" 2025-10-03 04:02:20.778529 | controller -> localhost | changed: "/var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/docs" 2025-10-03 04:02:20.801045 | 2025-10-03 04:02:20.801149 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-03 04:02:21.546802 | controller | changed: .d..t...... ./ 2025-10-03 04:02:21.547016 | controller | changed: All items complete 2025-10-03 04:02:21.547054 | 2025-10-03 04:02:22.094150 | controller | changed: .d..t...... ./ 2025-10-03 04:02:22.719568 | controller | changed: .d..t...... ./ 2025-10-03 04:02:22.733512 | 2025-10-03 04:02:22.733629 | TASK [include_role : fetch-output-openshift] 2025-10-03 04:02:22.782031 | controller | skipping: Conditional result was False 2025-10-03 04:02:22.789047 | 2025-10-03 04:02:22.789121 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-03 04:02:23.467898 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009654 2025-10-03 04:02:23.909195 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015839 2025-10-03 04:02:23.954464 | 2025-10-03 04:02:23.954567 | PLAY [all] 2025-10-03 04:02:23.981697 | 2025-10-03 04:02:23.981811 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-03 04:02:24.553362 | controller | changed 2025-10-03 04:02:24.601840 | 2025-10-03 04:02:24.601945 | PLAY RECAP 2025-10-03 04:02:24.601989 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 04:02:24.602010 | 2025-10-03 04:02:24.794800 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 04:02:24.795619 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-03 04:02:25.523397 | 2025-10-03 04:02:25.523561 | PLAY [localhost] 2025-10-03 04:02:25.541531 | 2025-10-03 04:02:25.541609 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-03 04:02:26.015231 | localhost | changed 2025-10-03 04:02:26.020184 | 2025-10-03 04:02:26.020257 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-03 04:02:26.048111 | localhost | ok 2025-10-03 04:02:26.056358 | 2025-10-03 04:02:26.056424 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-03 04:02:26.547612 | localhost | changed 2025-10-03 04:02:26.553375 | 2025-10-03 04:02:26.553445 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-03 04:02:27.263177 | localhost | changed 2025-10-03 04:02:27.268247 | 2025-10-03 04:02:27.268307 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-03 04:02:27.654516 | localhost | Identity added: /var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/tmp/ansible.5a0vaxb0 (/var/lib/zuul/builds/2289a5a7f52b4c5299ae5d2acf93aaa1/work/tmp/ansible.5a0vaxb0) 2025-10-03 04:02:27.654699 | localhost | ok: Runtime: 0:00:00.014655 2025-10-03 04:02:27.659011 | 2025-10-03 04:02:27.659079 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-03 04:02:27.924410 | localhost | ok: Runtime: 0:00:00.004972 2025-10-03 04:02:27.931709 | 2025-10-03 04:02:27.931793 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-03 04:02:27.980544 | localhost | changed 2025-10-03 04:02:27.984689 | 2025-10-03 04:02:27.984825 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-03 04:02:28.400049 | localhost | changed 2025-10-03 04:02:28.425169 | 2025-10-03 04:02:28.425270 | PLAY [localhost] 2025-10-03 04:02:28.437359 | 2025-10-03 04:02:28.437416 | TASK [Generate bulk log download script] 2025-10-03 04:02:28.455092 | localhost | ok 2025-10-03 04:02:28.466992 | 2025-10-03 04:02:28.467055 | TASK [local-log-download : Check API endpoint is defined] 2025-10-03 04:02:28.494699 | localhost | ok: All assertions passed 2025-10-03 04:02:28.499284 | 2025-10-03 04:02:28.499349 | TASK [local-log-download : Create download script] 2025-10-03 04:02:28.985863 | localhost -> localhost | changed 2025-10-03 04:02:28.994557 | 2025-10-03 04:02:28.994619 | TASK [Register quick-download link] 2025-10-03 04:02:29.034322 | localhost | ok 2025-10-03 04:02:29.079892 | 2025-10-03 04:02:29.079996 | PLAY [logserver.rdoproject.org] 2025-10-03 04:02:29.090367 | 2025-10-03 04:02:29.090474 | TASK [Set zuul-log-path fact] 2025-10-03 04:02:29.106756 | logserver.rdoproject.org | ok 2025-10-03 04:02:29.116169 | 2025-10-03 04:02:29.116272 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 04:02:29.143689 | logserver.rdoproject.org | ok 2025-10-03 04:02:29.150211 | 2025-10-03 04:02:29.150342 | TASK [upload-logs : Create log directories] 2025-10-03 04:02:29.861967 | logserver.rdoproject.org | changed 2025-10-03 04:02:29.865503 | 2025-10-03 04:02:29.865580 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-03 04:02:30.154246 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006493 2025-10-03 04:02:30.159225 | 2025-10-03 04:02:30.159302 | TASK [upload-logs : Upload logs to log server] 2025-10-03 04:02:30.796251 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-03 04:02:30.799312 | 2025-10-03 04:02:30.799377 | LOOP [upload-logs : Compress console log and json output] 2025-10-03 04:02:30.851968 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 04:02:30.852751 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 04:02:30.857657 | 2025-10-03 04:02:30.857798 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-03 04:02:30.915833 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 04:02:30.916067 | 2025-10-03 04:02:30.916960 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 04:02:30.926721 | 2025-10-03 04:02:30.926852 | LOOP [upload-logs : Upload console log and json output]