2025-12-05 10:04:29.521878 | Job console starting... 2025-12-05 10:04:29.537033 | Updating repositories 2025-12-05 10:04:30.122825 | Preparing job workspace 2025-12-05 10:04:34.610483 | Running Ansible setup... 2025-12-05 10:04:38.236770 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 10:04:38.821528 | 2025-12-05 10:04:38.821639 | PLAY [localhost] 2025-12-05 10:04:38.830035 | 2025-12-05 10:04:38.830105 | TASK [Gathering Facts] 2025-12-05 10:04:39.875503 | localhost | ok 2025-12-05 10:04:39.901231 | 2025-12-05 10:04:39.901345 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 10:04:40.352879 | localhost -> localhost | changed 2025-12-05 10:04:40.358656 | 2025-12-05 10:04:40.358741 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 10:04:41.242496 | localhost -> localhost | changed 2025-12-05 10:04:41.264910 | 2025-12-05 10:04:41.265125 | TASK [Setup log path fact] 2025-12-05 10:04:41.308780 | localhost | ok 2025-12-05 10:04:41.322521 | 2025-12-05 10:04:41.322601 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 10:04:41.381849 | localhost | ok 2025-12-05 10:04:41.390126 | 2025-12-05 10:04:41.390193 | TASK [emit-job-header : Print job information] 2025-12-05 10:04:41.428412 | # Job Information 2025-12-05 10:04:41.428550 | Ansible Version: 2.15.12 2025-12-05 10:04:41.428576 | Job: cifmw-molecule-cleanup_openstack 2025-12-05 10:04:41.428595 | Pipeline: github-check 2025-12-05 10:04:41.428613 | Executor: ze04.softwarefactory-project.io 2025-12-05 10:04:41.428630 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3533 2025-12-05 10:04:41.428648 | Log URL (when completed): https://logserver.rdoproject.org/136/rdoproject.org/136b0435aa46498dba77f2c8b76b07f0/ 2025-12-05 10:04:41.428666 | Event ID: 98ce36f0-d1c1-11f0-9c2f-9a812b5dc860 2025-12-05 10:04:41.432305 | 2025-12-05 10:04:41.432369 | LOOP [emit-job-header : Print node information] 2025-12-05 10:04:41.530342 | localhost | ok: 2025-12-05 10:04:41.530621 | localhost | # Node Information 2025-12-05 10:04:41.530659 | localhost | Inventory Hostname: controller 2025-12-05 10:04:41.530719 | localhost | Hostname: np0005546741 2025-12-05 10:04:41.530750 | localhost | Username: zuul 2025-12-05 10:04:41.530778 | localhost | Distro: CentOS 9 2025-12-05 10:04:41.530803 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 10:04:41.530828 | localhost | Region: RegionOne 2025-12-05 10:04:41.530852 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 10:04:41.530876 | localhost | Product Name: OpenStack Nova 2025-12-05 10:04:41.530900 | localhost | Interface IP: 38.102.83.190 2025-12-05 10:04:41.557666 | 2025-12-05 10:04:41.557762 | PLAY [all] 2025-12-05 10:04:41.566430 | 2025-12-05 10:04:41.566515 | TASK [Gather network facts] 2025-12-05 10:04:42.052564 | controller | ok 2025-12-05 10:04:42.072726 | 2025-12-05 10:04:42.072809 | TASK [include_role : start-zuul-console] 2025-12-05 10:04:42.095591 | controller | ok 2025-12-05 10:04:42.111608 | 2025-12-05 10:04:42.111713 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 10:04:42.516267 | controller | ok 2025-12-05 10:04:42.526966 | 2025-12-05 10:04:42.527025 | TASK [include_role : add-build-sshkey] 2025-12-05 10:04:42.546881 | controller | ok 2025-12-05 10:04:42.562283 | 2025-12-05 10:04:42.562352 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 10:04:42.821582 | controller -> localhost | ok 2025-12-05 10:04:42.836918 | 2025-12-05 10:04:42.837101 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 10:04:42.866957 | controller | ok 2025-12-05 10:04:42.879899 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 10:04:42.885391 | 2025-12-05 10:04:42.885451 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 10:04:43.721829 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 10:04:43.722202 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/136b0435aa46498dba77f2c8b76b07f0_id_rsa. 2025-12-05 10:04:43.722247 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/136b0435aa46498dba77f2c8b76b07f0_id_rsa.pub. 2025-12-05 10:04:43.722279 | controller -> localhost | The key fingerprint is: 2025-12-05 10:04:43.722306 | controller -> localhost | SHA256:YhQxi7wE/0eXJA+IAz8zE+4+WYnHmOVUM2XQKJXVXtY zuul-build-sshkey 2025-12-05 10:04:43.722334 | controller -> localhost | The key's randomart image is: 2025-12-05 10:04:43.722360 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 10:04:43.722385 | controller -> localhost | | o...++OB=. . | 2025-12-05 10:04:43.722412 | controller -> localhost | | *ooo=oO... o E| 2025-12-05 10:04:43.722436 | controller -> localhost | | %.=.. +. o | 2025-12-05 10:04:43.722461 | controller -> localhost | | o ^ o . . | 2025-12-05 10:04:43.722486 | controller -> localhost | | * X S | 2025-12-05 10:04:43.722510 | controller -> localhost | | . = o | 2025-12-05 10:04:43.722563 | controller -> localhost | | + | 2025-12-05 10:04:43.722590 | controller -> localhost | | . | 2025-12-05 10:04:43.722614 | controller -> localhost | | | 2025-12-05 10:04:43.722639 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 10:04:43.722735 | controller -> localhost | ok: Runtime: 0:00:00.395710 2025-12-05 10:04:43.735864 | 2025-12-05 10:04:43.736046 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 10:04:43.779966 | controller | ok 2025-12-05 10:04:43.792171 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 10:04:43.800428 | 2025-12-05 10:04:43.800493 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 10:04:43.828222 | controller | skipping: Conditional result was False 2025-12-05 10:04:43.835162 | 2025-12-05 10:04:43.835239 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 10:04:44.305411 | controller | changed 2025-12-05 10:04:44.316794 | 2025-12-05 10:04:44.316933 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 10:04:44.581630 | controller | ok 2025-12-05 10:04:44.592956 | 2025-12-05 10:04:44.593106 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 10:04:45.491188 | controller | changed 2025-12-05 10:04:45.501884 | 2025-12-05 10:04:45.502022 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 10:04:46.333344 | controller | changed 2025-12-05 10:04:46.338348 | 2025-12-05 10:04:46.338407 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 10:04:46.373029 | controller | skipping: Conditional result was False 2025-12-05 10:04:46.378763 | 2025-12-05 10:04:46.378830 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 10:04:46.832174 | controller -> localhost | changed 2025-12-05 10:04:46.852055 | 2025-12-05 10:04:46.852210 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 10:04:47.172084 | controller -> localhost | Identity added: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/136b0435aa46498dba77f2c8b76b07f0_id_rsa (zuul-build-sshkey) 2025-12-05 10:04:47.172444 | controller -> localhost | ok: Runtime: 0:00:00.014827 2025-12-05 10:04:47.185993 | 2025-12-05 10:04:47.186288 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 10:04:47.562056 | controller | ok 2025-12-05 10:04:47.571962 | 2025-12-05 10:04:47.572093 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 10:04:47.620344 | controller | skipping: Conditional result was False 2025-12-05 10:04:47.641548 | 2025-12-05 10:04:47.641729 | TASK [include_role : validate-host] 2025-12-05 10:04:47.675303 | controller | ok 2025-12-05 10:04:47.701164 | 2025-12-05 10:04:47.701252 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 10:04:47.743329 | controller | ok 2025-12-05 10:04:47.749731 | 2025-12-05 10:04:47.749817 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 10:04:48.019514 | controller -> localhost | ok 2025-12-05 10:04:48.027306 | 2025-12-05 10:04:48.027393 | TASK [validate-host : Collect information about the host] 2025-12-05 10:04:48.864449 | controller | ok 2025-12-05 10:04:48.882577 | 2025-12-05 10:04:48.882716 | TASK [validate-host : Sanitize hostname] 2025-12-05 10:04:48.963318 | controller | ok 2025-12-05 10:04:48.979537 | 2025-12-05 10:04:48.979712 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 10:04:49.469080 | controller -> localhost | changed 2025-12-05 10:04:49.474842 | 2025-12-05 10:04:49.474920 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 10:04:49.882320 | controller | ok 2025-12-05 10:04:49.905289 | 2025-12-05 10:04:49.905549 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 10:04:50.376342 | controller -> localhost | changed 2025-12-05 10:04:50.404087 | 2025-12-05 10:04:50.404238 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 10:04:50.430075 | controller | skipping: Conditional result was False 2025-12-05 10:04:50.442293 | 2025-12-05 10:04:50.442392 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 10:04:50.466941 | controller | skipping: Conditional result was False 2025-12-05 10:04:50.473983 | 2025-12-05 10:04:50.474049 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 10:04:50.715932 | controller | ok: "logs" 2025-12-05 10:04:50.716328 | controller | ok: All items complete 2025-12-05 10:04:50.716384 | 2025-12-05 10:04:50.939030 | controller | ok: "artifacts" 2025-12-05 10:04:51.186468 | controller | ok: "docs" 2025-12-05 10:04:51.204477 | 2025-12-05 10:04:51.204604 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 10:04:51.521304 | controller | changed: "logs" 2025-12-05 10:04:51.763715 | controller | changed: "artifacts" 2025-12-05 10:04:52.058324 | controller | changed: "docs" 2025-12-05 10:04:52.096833 | 2025-12-05 10:04:52.096948 | PLAY RECAP 2025-12-05 10:04:52.097008 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 10:04:52.097043 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 10:04:52.097068 | 2025-12-05 10:04:52.200001 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 10:04:52.201055 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 10:04:52.814917 | 2025-12-05 10:04:52.815024 | PLAY [localhost] 2025-12-05 10:04:52.832881 | 2025-12-05 10:04:52.832968 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 10:04:53.263436 | localhost | ok 2025-12-05 10:04:53.271041 | 2025-12-05 10:04:53.271146 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 10:04:53.965591 | localhost | changed 2025-12-05 10:04:54.003873 | 2025-12-05 10:04:54.003970 | PLAY [all] 2025-12-05 10:04:54.019878 | 2025-12-05 10:04:54.019946 | TASK [include_role : prepare-workspace] 2025-12-05 10:04:54.039535 | controller | ok 2025-12-05 10:04:54.054206 | 2025-12-05 10:04:54.054276 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 10:04:54.479606 | controller | ok 2025-12-05 10:04:54.501445 | 2025-12-05 10:04:54.502521 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 10:04:56.556013 | controller | Output suppressed because no_log was given 2025-12-05 10:04:56.578864 | 2025-12-05 10:04:56.579017 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 10:04:56.840149 | controller | changed: "logs" 2025-12-05 10:04:57.048969 | controller | changed: "artifacts" 2025-12-05 10:04:57.281199 | controller | changed: "docs" 2025-12-05 10:04:57.303091 | 2025-12-05 10:04:57.303299 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 10:04:57.622299 | controller | changed: "logs" 2025-12-05 10:04:57.622760 | controller | changed: All items complete 2025-12-05 10:04:57.622835 | 2025-12-05 10:04:57.840371 | controller | changed: "artifacts" 2025-12-05 10:04:58.106371 | controller | changed: "docs" 2025-12-05 10:04:58.123041 | 2025-12-05 10:04:58.123167 | TASK [Check if worker can sudo] 2025-12-05 10:04:58.651835 | controller | ok: Runtime: 0:00:00.050135 2025-12-05 10:04:58.658913 | 2025-12-05 10:04:58.659053 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 10:04:58.740243 | controller | skipping: Conditional result was False 2025-12-05 10:04:58.747069 | 2025-12-05 10:04:58.747138 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 10:04:58.811913 | controller | ok 2025-12-05 10:04:58.819968 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 10:04:58.853378 | 2025-12-05 10:04:58.853513 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 10:04:59.189280 | controller | ok 2025-12-05 10:04:59.202144 | 2025-12-05 10:04:59.203003 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 10:04:59.256337 | controller | ok: "/var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 10:04:59.265629 | 2025-12-05 10:04:59.265757 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 10:05:00.161147 | controller | changed 2025-12-05 10:05:00.167813 | 2025-12-05 10:05:00.167875 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 10:05:00.221586 | controller | ok: "/var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 10:05:00.221784 | controller | ok: All items complete 2025-12-05 10:05:00.221812 | 2025-12-05 10:05:00.270186 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 10:05:00.282580 | 2025-12-05 10:05:00.282709 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 10:05:01.283562 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 10:05:02.302400 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 10:05:02.317025 | 2025-12-05 10:05:02.317147 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 10:05:02.783160 | controller | changed: section and option added 2025-12-05 10:05:02.822556 | 2025-12-05 10:05:02.822827 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 10:05:03.521972 | controller | 29 files removed 2025-12-05 10:05:03.522186 | controller | ok: Item: dnf clean all Runtime: 0:00:00.322397 2025-12-05 10:05:03.522225 | controller | changed: All items complete 2025-12-05 10:05:03.522246 | 2025-12-05 10:05:14.355753 | 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-12-05 10:05:14.355867 | controller | DNF version: 4.14.0 2025-12-05 10:05:14.355912 | controller | cachedir: /var/cache/dnf 2025-12-05 10:05:14.355935 | controller | Making cache files for all metadata files. 2025-12-05 10:05:14.355955 | controller | baseos: has expired and will be refreshed. 2025-12-05 10:05:14.355973 | controller | appstream: has expired and will be refreshed. 2025-12-05 10:05:14.355990 | controller | crb: has expired and will be refreshed. 2025-12-05 10:05:14.356018 | controller | extras-common: has expired and will be refreshed. 2025-12-05 10:05:14.356036 | controller | repo: downloading from remote: baseos 2025-12-05 10:05:14.356054 | controller | CentOS Stream 9 - BaseOS 59 MB/s | 8.8 MB 00:00 2025-12-05 10:05:14.356070 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 10:05:14.356088 | controller | repo: downloading from remote: appstream 2025-12-05 10:05:14.356104 | controller | CentOS Stream 9 - AppStream 88 MB/s | 25 MB 00:00 2025-12-05 10:05:14.356121 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 10:05:14.356138 | controller | repo: downloading from remote: crb 2025-12-05 10:05:14.356155 | controller | CentOS Stream 9 - CRB 60 MB/s | 7.3 MB 00:00 2025-12-05 10:05:14.356172 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 10:05:14.356190 | controller | repo: downloading from remote: extras-common 2025-12-05 10:05:14.356207 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-12-05 10:05:14.356224 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 10:05:14.356242 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 10:05:14.356259 | controller | Completion plugin: Generating completion cache... 2025-12-05 10:05:14.356276 | controller | Metadata cache created. 2025-12-05 10:05:14.356303 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.564547 2025-12-05 10:05:14.369589 | 2025-12-05 10:05:14.369665 | PLAY RECAP 2025-12-05 10:05:14.369752 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 10:05:14.369781 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 10:05:14.369802 | 2025-12-05 10:05:14.476236 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 10:05:14.477053 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 10:05:15.085867 | 2025-12-05 10:05:15.086025 | PLAY [all] 2025-12-05 10:05:15.110052 | 2025-12-05 10:05:15.110161 | TASK [Install binary dependencies] 2025-12-05 10:05:15.171496 | controller | ok 2025-12-05 10:05:15.199039 | 2025-12-05 10:05:15.199159 | TASK [bindep : Include find tasks] 2025-12-05 10:05:15.227362 | controller | ok 2025-12-05 10:05:15.234921 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 10:05:15.241022 | 2025-12-05 10:05:15.241089 | TASK [bindep : Look for bindep.txt] 2025-12-05 10:05:15.703132 | controller | ok 2025-12-05 10:05:15.715870 | 2025-12-05 10:05:15.716002 | TASK [bindep : Define bindep_file fact] 2025-12-05 10:05:15.748194 | controller | ok 2025-12-05 10:05:15.755545 | 2025-12-05 10:05:15.755635 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 10:05:15.771054 | controller | skipping: Conditional result was False 2025-12-05 10:05:15.780053 | 2025-12-05 10:05:15.780154 | TASK [bindep : Define bindep_file fact] 2025-12-05 10:05:15.805278 | controller | skipping: Conditional result was False 2025-12-05 10:05:15.813994 | 2025-12-05 10:05:15.814175 | TASK [bindep : Look for bindep fallback file] 2025-12-05 10:05:15.848306 | controller | skipping: Conditional result was False 2025-12-05 10:05:15.862020 | 2025-12-05 10:05:15.862147 | TASK [bindep : Define bindep_file fact] 2025-12-05 10:05:15.909860 | controller | skipping: Conditional result was False 2025-12-05 10:05:15.916056 | 2025-12-05 10:05:15.916121 | TASK [bindep : Include bindep tasks] 2025-12-05 10:05:15.976493 | controller | ok 2025-12-05 10:05:15.983053 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 10:05:15.990380 | 2025-12-05 10:05:15.990438 | TASK [bindep : Look for bindep command] 2025-12-05 10:05:16.014314 | controller | skipping: Conditional result was False 2025-12-05 10:05:16.021122 | 2025-12-05 10:05:16.021210 | TASK [bindep : Check for system bindep] 2025-12-05 10:05:16.562209 | controller | ok: Runtime: 0:00:00.007149 2025-12-05 10:05:16.569489 | 2025-12-05 10:05:16.569577 | TASK [bindep : Define bindep_command fact] 2025-12-05 10:05:16.594764 | controller | skipping: Conditional result was False 2025-12-05 10:05:16.602923 | 2025-12-05 10:05:16.603011 | TASK [bindep : Include install tasks] 2025-12-05 10:05:16.655187 | controller | ok 2025-12-05 10:05:16.665521 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 10:05:16.677880 | 2025-12-05 10:05:16.677964 | TASK [bindep : Create temp dir for bindep] 2025-12-05 10:05:17.157493 | controller | changed 2025-12-05 10:05:17.165313 | 2025-12-05 10:05:17.165395 | TASK [Ensure we have pip dependencies] 2025-12-05 10:05:17.199453 | controller | ok 2025-12-05 10:05:17.250278 | 2025-12-05 10:05:17.250412 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 05:05:17.562819 | controller | /usr/bin/pip3 2025-12-05 05:05:17.583308 | controller | /usr/bin/python3: No module named wheel 2025-12-05 10:05:17.788403 | controller | ok: Runtime: 0:00:00.030682 2025-12-05 10:05:17.797856 | 2025-12-05 10:05:17.797968 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 10:05:17.841512 | controller | ok: "/var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 10:05:17.861514 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 10:05:17.873527 | 2025-12-05 10:05:17.873599 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 10:05:19.734899 | controller | changed 2025-12-05 10:05:19.749669 | 2025-12-05 10:05:19.749932 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 10:05:19.818805 | controller | skipping: Conditional result was False 2025-12-05 10:05:19.836829 | 2025-12-05 10:05:19.836979 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 10:05:19.922498 | controller | skipping: Conditional result was False 2025-12-05 10:05:19.931724 | 2025-12-05 10:05:19.931937 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 10:05:19.977596 | controller | skipping: Conditional result was False 2025-12-05 10:05:19.985501 | 2025-12-05 10:05:19.985571 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 10:05:20.012236 | controller | skipping: Conditional result was False 2025-12-05 10:05:20.022973 | 2025-12-05 10:05:20.023155 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 10:05:20.559674 | controller | skipping: Conditional result was False 2025-12-05 10:05:20.574024 | 2025-12-05 10:05:20.574179 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 10:05:20.617926 | controller | skipping: Conditional result was False 2025-12-05 10:05:20.627029 | 2025-12-05 10:05:20.627149 | TASK [ensure-pip : Install pip from source] 2025-12-05 10:05:20.653620 | controller | skipping: Conditional result was False 2025-12-05 10:05:20.668324 | 2025-12-05 10:05:20.668548 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 05:05:20.959777 | controller | /usr/bin/python3 2025-12-05 10:05:21.206054 | controller | ok: Runtime: 0:00:00.007480 2025-12-05 10:05:21.219400 | 2025-12-05 10:05:21.219570 | TASK [ensure-pip : Set host default] 2025-12-05 10:05:21.288593 | controller | ok 2025-12-05 10:05:21.303245 | 2025-12-05 10:05:21.303428 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 10:05:21.383295 | controller | ok 2025-12-05 10:05:21.407513 | 2025-12-05 10:05:21.407642 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 10:05:25.554382 | controller | changed 2025-12-05 10:05:25.573095 | 2025-12-05 10:05:25.573284 | TASK [bindep : Define bindep_command] 2025-12-05 10:05:25.619825 | controller | ok 2025-12-05 10:05:25.628285 | 2025-12-05 10:05:25.628379 | LOOP [bindep : Include package tasks] 2025-12-05 10:05:25.688603 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 10:05:25.688904 | controller | ok: All items complete 2025-12-05 10:05:25.688934 | 2025-12-05 10:05:25.707489 | controller | included: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 10:05:25.736925 | 2025-12-05 10:05:25.737042 | TASK [bindep : Define bindep_run fact] 2025-12-05 10:05:25.782813 | controller | ok 2025-12-05 10:05:25.787999 | 2025-12-05 10:05:25.788063 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 05:05:27.239808 | controller | podman 2025-12-05 05:05:27.275186 | controller | python3-jmespath 2025-12-05 05:05:27.275360 | controller | python3-libvirt 2025-12-05 05:05:27.275380 | controller | python3-lxml 2025-12-05 05:05:27.275400 | controller | python3-netaddr 2025-12-05 10:05:27.331975 | controller | ok: Runtime: 0:00:01.203116 2025-12-05 10:05:27.344498 | 2025-12-05 10:05:27.344634 | TASK [bindep : Install distro packages from bindep] 2025-12-05 10:06:28.699216 | controller | changed 2025-12-05 10:06:28.721557 | 2025-12-05 10:06:28.723137 | TASK [bindep : Check that packages are installed] 2025-12-05 10:06:30.308588 | controller | ok: Runtime: 0:00:01.112285 2025-12-05 10:06:30.314309 | 2025-12-05 10:06:30.314375 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 10:06:30.372959 | controller | skipping: Conditional result was False 2025-12-05 10:06:30.383342 | 2025-12-05 10:06:30.383412 | TASK [Run test-setup role] 2025-12-05 10:06:30.442134 | controller | ok 2025-12-05 10:06:30.467511 | 2025-12-05 10:06:30.467625 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 10:06:30.747783 | controller | ok 2025-12-05 10:06:30.754438 | 2025-12-05 10:06:30.754501 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 10:06:31.288818 | controller | skipping: Conditional result was False 2025-12-05 10:06:31.334892 | 2025-12-05 10:06:31.335008 | TASK [bindep : Remove bindep temp dir] 2025-12-05 10:06:31.681888 | controller | ok 2025-12-05 10:06:31.712864 | 2025-12-05 10:06:31.712953 | PLAY RECAP 2025-12-05 10:06:31.712993 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 10:06:31.713012 | 2025-12-05 10:06:31.913510 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 10:06:31.914384 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 10:06:32.890085 | 2025-12-05 10:06:32.890191 | PLAY [all] 2025-12-05 10:06:32.911169 | 2025-12-05 10:06:32.911247 | TASK [Abort when test_command variable is undefined] 2025-12-05 10:06:32.936073 | controller | skipping: Conditional result was False 2025-12-05 10:06:32.942124 | 2025-12-05 10:06:32.942194 | TASK [Convert test_command to list] 2025-12-05 10:06:32.985834 | controller | skipping: Conditional result was False 2025-12-05 10:06:32.992447 | 2025-12-05 10:06:32.992558 | TASK [Use test_command list] 2025-12-05 10:06:33.094463 | controller | ok 2025-12-05 10:06:33.102213 | 2025-12-05 10:06:33.102298 | LOOP [Run test_command] 2025-12-05 10:06:33.527432 | controller | no check to run 2025-12-05 10:06:33.527654 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005714 2025-12-05 10:06:33.557889 | 2025-12-05 10:06:33.557944 | PLAY RECAP 2025-12-05 10:06:33.557987 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 10:06:33.558007 | 2025-12-05 10:06:33.686526 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 10:06:33.687405 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 10:06:34.340916 | 2025-12-05 10:06:34.341029 | PLAY [all] 2025-12-05 10:06:34.361983 | 2025-12-05 10:06:34.362078 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 10:06:34.738931 | controller | changed: non-zero return code 2025-12-05 10:06:34.744202 | 2025-12-05 10:06:34.744275 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 10:06:34.760999 | controller | skipping: Conditional result was False 2025-12-05 10:06:34.769148 | 2025-12-05 10:06:34.769243 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 10:06:34.792035 | 2025-12-05 10:06:34.792209 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 10:06:34.825566 | 2025-12-05 10:06:34.825767 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 10:06:34.840260 | controller | skipping: Conditional result was False 2025-12-05 10:06:34.847980 | 2025-12-05 10:06:34.848068 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 10:06:34.879771 | 2025-12-05 10:06:34.879935 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 10:06:34.906920 | controller | skipping: Conditional result was False 2025-12-05 10:06:34.913803 | 2025-12-05 10:06:34.913892 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 10:06:34.938498 | controller | skipping: Conditional result was False 2025-12-05 10:06:34.945870 | 2025-12-05 10:06:34.945961 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 10:06:34.961349 | controller | skipping: Conditional result was False 2025-12-05 10:06:34.997815 | 2025-12-05 10:06:34.997899 | PLAY RECAP 2025-12-05 10:06:34.997952 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 10:06:34.997980 | 2025-12-05 10:06:35.123132 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 10:06:35.123968 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 10:06:35.691561 | 2025-12-05 10:06:35.691655 | PLAY [all] 2025-12-05 10:06:35.712187 | 2025-12-05 10:06:35.712258 | TASK [include_role : fetch-output] 2025-12-05 10:06:35.751908 | controller | ok 2025-12-05 10:06:35.768925 | 2025-12-05 10:06:35.769005 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 10:06:35.813186 | controller | skipping: Conditional result was False 2025-12-05 10:06:35.818947 | 2025-12-05 10:06:35.819011 | TASK [fetch-output : Set log path for single node] 2025-12-05 10:06:35.847750 | controller | ok 2025-12-05 10:06:35.852738 | 2025-12-05 10:06:35.852805 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 10:06:36.263815 | controller -> localhost | ok: "/var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/logs" 2025-12-05 10:06:36.508551 | controller -> localhost | changed: "/var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/artifacts" 2025-12-05 10:06:36.754050 | controller -> localhost | changed: "/var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/docs" 2025-12-05 10:06:36.771294 | 2025-12-05 10:06:36.771410 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 10:06:37.494115 | controller | changed: .d..t...... ./ 2025-12-05 10:06:37.494450 | controller | changed: All items complete 2025-12-05 10:06:37.494510 | 2025-12-05 10:06:38.051646 | controller | changed: .d..t...... ./ 2025-12-05 10:06:38.596003 | controller | changed: .d..t...... ./ 2025-12-05 10:06:38.623430 | 2025-12-05 10:06:38.623619 | TASK [include_role : fetch-output-openshift] 2025-12-05 10:06:38.654943 | controller | skipping: Conditional result was False 2025-12-05 10:06:38.663143 | 2025-12-05 10:06:38.663255 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 10:06:39.178260 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012832 2025-12-05 10:06:39.465216 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013630 2025-12-05 10:06:39.492435 | 2025-12-05 10:06:39.492530 | PLAY [all] 2025-12-05 10:06:39.506761 | 2025-12-05 10:06:39.506824 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 10:06:40.030938 | controller | changed 2025-12-05 10:06:40.094499 | 2025-12-05 10:06:40.094622 | PLAY RECAP 2025-12-05 10:06:40.094700 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 10:06:40.094737 | 2025-12-05 10:06:40.196118 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 10:06:40.197186 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 10:06:40.842806 | 2025-12-05 10:06:40.842911 | PLAY [localhost] 2025-12-05 10:06:40.860499 | 2025-12-05 10:06:40.860575 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 10:06:41.279293 | localhost | changed 2025-12-05 10:06:41.283987 | 2025-12-05 10:06:41.284062 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 10:06:41.321496 | localhost | ok 2025-12-05 10:06:41.329336 | 2025-12-05 10:06:41.329404 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 10:06:41.764197 | localhost | changed 2025-12-05 10:06:41.769958 | 2025-12-05 10:06:41.770025 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 10:06:42.451917 | localhost | changed 2025-12-05 10:06:42.462873 | 2025-12-05 10:06:42.462989 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 10:06:42.858278 | localhost | Identity added: /var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/tmp/ansible.ufn7zhas (/var/lib/zuul/builds/136b0435aa46498dba77f2c8b76b07f0/work/tmp/ansible.ufn7zhas) 2025-12-05 10:06:42.858470 | localhost | ok: Runtime: 0:00:00.009847 2025-12-05 10:06:42.863022 | 2025-12-05 10:06:42.863088 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 10:06:43.113900 | localhost | ok: Runtime: 0:00:00.005359 2025-12-05 10:06:43.120566 | 2025-12-05 10:06:43.120629 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 10:06:43.178993 | localhost | changed 2025-12-05 10:06:43.183325 | 2025-12-05 10:06:43.183389 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 10:06:43.545842 | localhost | changed 2025-12-05 10:06:43.566150 | 2025-12-05 10:06:43.566215 | PLAY [localhost] 2025-12-05 10:06:43.581933 | 2025-12-05 10:06:43.582000 | TASK [Generate bulk log download script] 2025-12-05 10:06:43.601798 | localhost | ok 2025-12-05 10:06:43.619093 | 2025-12-05 10:06:43.619175 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 10:06:43.649987 | localhost | ok: All assertions passed 2025-12-05 10:06:43.655488 | 2025-12-05 10:06:43.655550 | TASK [local-log-download : Create download script] 2025-12-05 10:06:44.109786 | localhost -> localhost | changed 2025-12-05 10:06:44.120186 | 2025-12-05 10:06:44.120258 | TASK [Register quick-download link] 2025-12-05 10:06:44.152667 | localhost | ok 2025-12-05 10:06:44.194505 | 2025-12-05 10:06:44.194608 | PLAY [logserver.rdoproject.org] 2025-12-05 10:06:44.204033 | 2025-12-05 10:06:44.204093 | TASK [Set zuul-log-path fact] 2025-12-05 10:06:44.220075 | logserver.rdoproject.org | ok 2025-12-05 10:06:44.231158 | 2025-12-05 10:06:44.231222 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 10:06:44.257646 | logserver.rdoproject.org | ok 2025-12-05 10:06:44.263160 | 2025-12-05 10:06:44.263224 | TASK [upload-logs : Create log directories] 2025-12-05 10:06:44.908453 | logserver.rdoproject.org | changed 2025-12-05 10:06:44.921922 | 2025-12-05 10:06:44.922039 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 10:06:45.211747 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005482 2025-12-05 10:06:45.216868 | 2025-12-05 10:06:45.216945 | TASK [upload-logs : Upload logs to log server] 2025-12-05 10:06:45.898481 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 10:06:45.910429 | 2025-12-05 10:06:45.911252 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 10:06:45.988016 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:06:46.009383 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:06:46.019918 | 2025-12-05 10:06:46.020088 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 10:06:46.070523 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:06:46.070791 | 2025-12-05 10:06:46.073045 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:06:46.082162 | 2025-12-05 10:06:46.082261 | LOOP [upload-logs : Upload console log and json output]