2025-10-14 06:51:01.814290 | Job console starting... 2025-10-14 06:51:01.824620 | Updating repositories 2025-10-14 06:51:01.845622 | Preparing job workspace 2025-10-14 06:51:05.322305 | Running Ansible setup... 2025-10-14 06:51:09.547389 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-14 06:51:10.177629 | 2025-10-14 06:51:10.177749 | PLAY [localhost] 2025-10-14 06:51:10.186924 | 2025-10-14 06:51:10.186993 | TASK [Gathering Facts] 2025-10-14 06:51:11.174473 | localhost | ok 2025-10-14 06:51:11.187724 | 2025-10-14 06:51:11.187819 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-14 06:51:11.549506 | localhost -> localhost | changed 2025-10-14 06:51:11.555702 | 2025-10-14 06:51:11.555808 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-14 06:51:12.355890 | localhost -> localhost | changed 2025-10-14 06:51:12.370225 | 2025-10-14 06:51:12.370384 | TASK [Setup log path fact] 2025-10-14 06:51:12.396841 | localhost | ok 2025-10-14 06:51:12.414260 | 2025-10-14 06:51:12.414407 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-14 06:51:12.445202 | localhost | ok 2025-10-14 06:51:12.457249 | 2025-10-14 06:51:12.457436 | TASK [emit-job-header : Print job information] 2025-10-14 06:51:12.508474 | # Job Information 2025-10-14 06:51:12.508633 | Ansible Version: 2.15.12 2025-10-14 06:51:12.508659 | Job: cifmw-molecule-cifmw_helpers 2025-10-14 06:51:12.508681 | Pipeline: github-check 2025-10-14 06:51:12.508699 | Executor: ze01.softwarefactory-project.io 2025-10-14 06:51:12.508716 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3404 2025-10-14 06:51:12.508735 | Log URL (when completed): https://logserver.rdoproject.org/267/rdoproject.org/267512a9039f49fdb7800ec9df3e255b/ 2025-10-14 06:51:12.508753 | Event ID: 3008c7a0-a8c9-11f0-9823-95af8b57c5c3 2025-10-14 06:51:12.512459 | 2025-10-14 06:51:12.512521 | LOOP [emit-job-header : Print node information] 2025-10-14 06:51:12.620048 | localhost | ok: 2025-10-14 06:51:12.620294 | localhost | # Node Information 2025-10-14 06:51:12.620330 | localhost | Inventory Hostname: controller 2025-10-14 06:51:12.620376 | localhost | Hostname: np0005486787 2025-10-14 06:51:12.620412 | localhost | Username: zuul 2025-10-14 06:51:12.620438 | localhost | Distro: CentOS 9 2025-10-14 06:51:12.620463 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-14 06:51:12.620488 | localhost | Region: RegionOne 2025-10-14 06:51:12.620511 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-14 06:51:12.620529 | localhost | Product Name: OpenStack Nova 2025-10-14 06:51:12.620552 | localhost | Interface IP: 38.102.83.193 2025-10-14 06:51:12.657529 | 2025-10-14 06:51:12.657639 | PLAY [all] 2025-10-14 06:51:12.665165 | 2025-10-14 06:51:12.665256 | TASK [Gather network facts] 2025-10-14 06:51:13.215471 | controller | ok 2025-10-14 06:51:13.231266 | 2025-10-14 06:51:13.231365 | TASK [include_role : start-zuul-console] 2025-10-14 06:51:13.249778 | controller | ok 2025-10-14 06:51:13.262822 | 2025-10-14 06:51:13.262905 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-14 06:51:13.697184 | controller | ok 2025-10-14 06:51:13.720568 | 2025-10-14 06:51:13.720718 | TASK [include_role : add-build-sshkey] 2025-10-14 06:51:13.755830 | controller | ok 2025-10-14 06:51:13.780954 | 2025-10-14 06:51:13.781099 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-14 06:51:14.079334 | controller -> localhost | ok 2025-10-14 06:51:14.085720 | 2025-10-14 06:51:14.085828 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-14 06:51:14.125852 | controller | ok 2025-10-14 06:51:14.141177 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-14 06:51:14.147743 | 2025-10-14 06:51:14.147832 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-14 06:51:15.085734 | controller -> localhost | Generating public/private rsa key pair. 2025-10-14 06:51:15.085944 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/267512a9039f49fdb7800ec9df3e255b_id_rsa. 2025-10-14 06:51:15.085976 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/267512a9039f49fdb7800ec9df3e255b_id_rsa.pub. 2025-10-14 06:51:15.085998 | controller -> localhost | The key fingerprint is: 2025-10-14 06:51:15.086043 | controller -> localhost | SHA256:+hfb0wIxzHas+z5u/jeF6WyB7YEJ7EJsPKNNswZqOSQ zuul-build-sshkey 2025-10-14 06:51:15.086067 | controller -> localhost | The key's randomart image is: 2025-10-14 06:51:15.086087 | controller -> localhost | +---[RSA 3072]----+ 2025-10-14 06:51:15.086105 | controller -> localhost | | | 2025-10-14 06:51:15.086123 | controller -> localhost | | | 2025-10-14 06:51:15.086141 | controller -> localhost | | o + . | 2025-10-14 06:51:15.086193 | controller -> localhost | | E . . X O o | 2025-10-14 06:51:15.086215 | controller -> localhost | | o o BSB * = o | 2025-10-14 06:51:15.086233 | controller -> localhost | | = ..= = + * .| 2025-10-14 06:51:15.086250 | controller -> localhost | | . ... . * = o.| 2025-10-14 06:51:15.086268 | controller -> localhost | | . + * *..| 2025-10-14 06:51:15.086285 | controller -> localhost | | .. *=*...| 2025-10-14 06:51:15.086301 | controller -> localhost | +----[SHA256]-----+ 2025-10-14 06:51:15.086353 | controller -> localhost | ok: Runtime: 0:00:00.481591 2025-10-14 06:51:15.093267 | 2025-10-14 06:51:15.093342 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-14 06:51:15.129526 | controller | ok 2025-10-14 06:51:15.141858 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-14 06:51:15.152531 | 2025-10-14 06:51:15.152624 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-14 06:51:15.166296 | controller | skipping: Conditional result was False 2025-10-14 06:51:15.174648 | 2025-10-14 06:51:15.174773 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-14 06:51:15.661590 | controller | changed 2025-10-14 06:51:15.678047 | 2025-10-14 06:51:15.678198 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-14 06:51:15.940255 | controller | ok 2025-10-14 06:51:15.964069 | 2025-10-14 06:51:15.964267 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-14 06:51:16.821916 | controller | changed 2025-10-14 06:51:16.833291 | 2025-10-14 06:51:16.833427 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-14 06:51:17.747377 | controller | changed 2025-10-14 06:51:17.754603 | 2025-10-14 06:51:17.754689 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-14 06:51:17.780731 | controller | skipping: Conditional result was False 2025-10-14 06:51:17.791507 | 2025-10-14 06:51:17.791654 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-14 06:51:18.258272 | controller -> localhost | changed 2025-10-14 06:51:18.278842 | 2025-10-14 06:51:18.278955 | TASK [add-build-sshkey : Add back temp key] 2025-10-14 06:51:18.558691 | controller -> localhost | Identity added: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/267512a9039f49fdb7800ec9df3e255b_id_rsa (zuul-build-sshkey) 2025-10-14 06:51:18.559214 | controller -> localhost | ok: Runtime: 0:00:00.017553 2025-10-14 06:51:18.571595 | 2025-10-14 06:51:18.571757 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-14 06:51:18.984419 | controller | ok 2025-10-14 06:51:18.997312 | 2025-10-14 06:51:18.997457 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-14 06:51:19.046106 | controller | skipping: Conditional result was False 2025-10-14 06:51:19.068392 | 2025-10-14 06:51:19.068549 | TASK [include_role : validate-host] 2025-10-14 06:51:19.108331 | controller | ok 2025-10-14 06:51:19.143123 | 2025-10-14 06:51:19.143262 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-14 06:51:19.185823 | controller | ok 2025-10-14 06:51:19.192680 | 2025-10-14 06:51:19.192800 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-14 06:51:19.516880 | controller -> localhost | ok 2025-10-14 06:51:19.522966 | 2025-10-14 06:51:19.523174 | TASK [validate-host : Collect information about the host] 2025-10-14 06:51:20.342002 | controller | ok 2025-10-14 06:51:20.356111 | 2025-10-14 06:51:20.356242 | TASK [validate-host : Sanitize hostname] 2025-10-14 06:51:20.407438 | controller | ok 2025-10-14 06:51:20.412883 | 2025-10-14 06:51:20.412967 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-14 06:51:20.994602 | controller -> localhost | changed 2025-10-14 06:51:21.000158 | 2025-10-14 06:51:21.000224 | TASK [validate-host : Collect information about zuul worker] 2025-10-14 06:51:21.466431 | controller | ok 2025-10-14 06:51:21.471505 | 2025-10-14 06:51:21.471577 | TASK [validate-host : Write out all zuul information for each host] 2025-10-14 06:51:22.036123 | controller -> localhost | changed 2025-10-14 06:51:22.045594 | 2025-10-14 06:51:22.045664 | TASK [include_role : prepare-workspace-openshift] 2025-10-14 06:51:22.059414 | controller | skipping: Conditional result was False 2025-10-14 06:51:22.064481 | 2025-10-14 06:51:22.064549 | TASK [include_role : remove-zuul-sshkey] 2025-10-14 06:51:22.077958 | controller | skipping: Conditional result was False 2025-10-14 06:51:22.083909 | 2025-10-14 06:51:22.083992 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-14 06:51:22.333845 | controller | ok: "logs" 2025-10-14 06:51:22.334121 | controller | ok: All items complete 2025-10-14 06:51:22.334150 | 2025-10-14 06:51:22.583641 | controller | ok: "artifacts" 2025-10-14 06:51:22.783715 | controller | ok: "docs" 2025-10-14 06:51:22.796936 | 2025-10-14 06:51:22.797066 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-14 06:51:23.104146 | controller | changed: "logs" 2025-10-14 06:51:23.323411 | controller | changed: "artifacts" 2025-10-14 06:51:23.591380 | controller | changed: "docs" 2025-10-14 06:51:23.626428 | 2025-10-14 06:51:23.626536 | PLAY RECAP 2025-10-14 06:51:23.626593 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-14 06:51:23.626630 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-14 06:51:23.626658 | 2025-10-14 06:51:23.749943 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-14 06:51:23.750725 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-14 06:51:24.329389 | 2025-10-14 06:51:24.329574 | PLAY [localhost] 2025-10-14 06:51:24.351972 | 2025-10-14 06:51:24.352121 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-14 06:51:24.749429 | localhost | ok 2025-10-14 06:51:24.757491 | 2025-10-14 06:51:24.757628 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-14 06:51:25.481363 | localhost | changed 2025-10-14 06:51:25.506839 | 2025-10-14 06:51:25.506995 | PLAY [all] 2025-10-14 06:51:25.526233 | 2025-10-14 06:51:25.526396 | TASK [include_role : prepare-workspace] 2025-10-14 06:51:25.556073 | controller | ok 2025-10-14 06:51:25.572773 | 2025-10-14 06:51:25.572899 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-14 06:51:26.062067 | controller | ok 2025-10-14 06:51:26.070866 | 2025-10-14 06:51:26.070979 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-14 06:51:27.882475 | controller | Output suppressed because no_log was given 2025-10-14 06:51:27.903294 | 2025-10-14 06:51:27.903406 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-14 06:51:28.218130 | controller | changed: "logs" 2025-10-14 06:51:28.500097 | controller | changed: "artifacts" 2025-10-14 06:51:28.739587 | controller | changed: "docs" 2025-10-14 06:51:28.755660 | 2025-10-14 06:51:28.755816 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-14 06:51:29.041359 | controller | changed: "logs" 2025-10-14 06:51:29.041753 | controller | changed: All items complete 2025-10-14 06:51:29.041818 | 2025-10-14 06:51:29.291045 | controller | changed: "artifacts" 2025-10-14 06:51:29.572590 | controller | changed: "docs" 2025-10-14 06:51:29.597989 | 2025-10-14 06:51:29.598136 | TASK [Check if worker can sudo] 2025-10-14 06:51:30.631365 | controller | ok: Runtime: 0:00:00.154087 2025-10-14 06:51:30.638041 | 2025-10-14 06:51:30.638129 | TASK [configure-mirrors : Gather needed facts] 2025-10-14 06:51:30.714892 | controller | skipping: Conditional result was False 2025-10-14 06:51:30.728995 | 2025-10-14 06:51:30.729240 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-14 06:51:30.810628 | controller | ok 2025-10-14 06:51:30.828691 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-14 06:51:30.874294 | 2025-10-14 06:51:30.874422 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-14 06:51:31.207484 | controller | ok 2025-10-14 06:51:31.220924 | 2025-10-14 06:51:31.221103 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-14 06:51:31.315276 | controller | ok: "/var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-14 06:51:31.340465 | 2025-10-14 06:51:31.340649 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-14 06:51:32.396080 | controller | changed 2025-10-14 06:51:32.401595 | 2025-10-14 06:51:32.401656 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-14 06:51:32.455448 | controller | ok: "/var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-14 06:51:32.455644 | controller | ok: All items complete 2025-10-14 06:51:32.455681 | 2025-10-14 06:51:32.498698 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-14 06:51:32.505573 | 2025-10-14 06:51:32.505638 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-14 06:51:33.587527 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-14 06:51:34.504261 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-14 06:51:34.517728 | 2025-10-14 06:51:34.517888 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-14 06:51:35.049591 | controller | changed: section and option added 2025-10-14 06:51:35.078201 | 2025-10-14 06:51:35.078357 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-14 06:51:37.149775 | controller | 29 files removed 2025-10-14 06:51:37.150080 | controller | ok: Item: dnf clean all Runtime: 0:00:01.655843 2025-10-14 06:51:37.150145 | controller | changed: All items complete 2025-10-14 06:51:37.150177 | 2025-10-14 06:51:49.510672 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-10-14 06:51:49.510803 | controller | DNF version: 4.14.0 2025-10-14 06:51:49.510829 | controller | cachedir: /var/cache/dnf 2025-10-14 06:51:49.510854 | controller | Making cache files for all metadata files. 2025-10-14 06:51:49.510877 | controller | baseos: has expired and will be refreshed. 2025-10-14 06:51:49.510898 | controller | appstream: has expired and will be refreshed. 2025-10-14 06:51:49.510919 | controller | crb: has expired and will be refreshed. 2025-10-14 06:51:49.511063 | controller | extras-common: has expired and will be refreshed. 2025-10-14 06:51:49.511094 | controller | repo: downloading from remote: baseos 2025-10-14 06:51:49.511113 | controller | CentOS Stream 9 - BaseOS 10 MB/s | 8.8 MB 00:00 2025-10-14 06:51:49.511169 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-14 06:51:49.511193 | controller | repo: downloading from remote: appstream 2025-10-14 06:51:49.511210 | controller | CentOS Stream 9 - AppStream 116 MB/s | 25 MB 00:00 2025-10-14 06:51:49.511226 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-14 06:51:49.511242 | controller | repo: downloading from remote: crb 2025-10-14 06:51:49.511258 | controller | CentOS Stream 9 - CRB 48 MB/s | 7.2 MB 00:00 2025-10-14 06:51:49.511274 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-14 06:51:49.511290 | controller | repo: downloading from remote: extras-common 2025-10-14 06:51:49.511306 | controller | CentOS Stream 9 - Extras packages 807 kB/s | 20 kB 00:00 2025-10-14 06:51:49.511322 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-14 06:51:49.511338 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-14 06:51:49.511354 | controller | Completion plugin: Generating completion cache... 2025-10-14 06:51:49.511370 | controller | Metadata cache created. 2025-10-14 06:51:49.511399 | controller | ok: Item: dnf makecache -v Runtime: 0:00:12.044620 2025-10-14 06:51:49.566407 | 2025-10-14 06:51:49.566514 | PLAY RECAP 2025-10-14 06:51:49.566555 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-14 06:51:49.566579 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-14 06:51:49.566597 | 2025-10-14 06:51:49.690186 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-14 06:51:49.690976 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-14 06:51:50.291580 | 2025-10-14 06:51:50.291740 | PLAY [all] 2025-10-14 06:51:50.319844 | 2025-10-14 06:51:50.319985 | TASK [Install binary dependencies] 2025-10-14 06:51:50.379687 | controller | ok 2025-10-14 06:51:50.399459 | 2025-10-14 06:51:50.399596 | TASK [bindep : Include find tasks] 2025-10-14 06:51:50.428537 | controller | ok 2025-10-14 06:51:50.436121 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-14 06:51:50.442115 | 2025-10-14 06:51:50.442178 | TASK [bindep : Look for bindep.txt] 2025-10-14 06:51:50.908829 | controller | ok 2025-10-14 06:51:50.915339 | 2025-10-14 06:51:50.915409 | TASK [bindep : Define bindep_file fact] 2025-10-14 06:51:50.954746 | controller | ok 2025-10-14 06:51:50.960190 | 2025-10-14 06:51:50.960255 | TASK [bindep : Look for other-requirements.txt] 2025-10-14 06:51:50.984108 | controller | skipping: Conditional result was False 2025-10-14 06:51:50.989840 | 2025-10-14 06:51:50.989909 | TASK [bindep : Define bindep_file fact] 2025-10-14 06:51:51.024183 | controller | skipping: Conditional result was False 2025-10-14 06:51:51.030366 | 2025-10-14 06:51:51.030435 | TASK [bindep : Look for bindep fallback file] 2025-10-14 06:51:51.054835 | controller | skipping: Conditional result was False 2025-10-14 06:51:51.061681 | 2025-10-14 06:51:51.061768 | TASK [bindep : Define bindep_file fact] 2025-10-14 06:51:51.086204 | controller | skipping: Conditional result was False 2025-10-14 06:51:51.094586 | 2025-10-14 06:51:51.094687 | TASK [bindep : Include bindep tasks] 2025-10-14 06:51:51.130496 | controller | ok 2025-10-14 06:51:51.141113 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-14 06:51:51.150099 | 2025-10-14 06:51:51.150164 | TASK [bindep : Look for bindep command] 2025-10-14 06:51:51.174595 | controller | skipping: Conditional result was False 2025-10-14 06:51:51.181552 | 2025-10-14 06:51:51.181624 | TASK [bindep : Check for system bindep] 2025-10-14 06:51:51.736284 | controller | ok: Runtime: 0:00:00.006979 2025-10-14 06:51:51.743909 | 2025-10-14 06:51:51.744077 | TASK [bindep : Define bindep_command fact] 2025-10-14 06:51:51.790413 | controller | skipping: Conditional result was False 2025-10-14 06:51:51.799382 | 2025-10-14 06:51:51.799504 | TASK [bindep : Include install tasks] 2025-10-14 06:51:51.842549 | controller | ok 2025-10-14 06:51:51.853985 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-14 06:51:51.868671 | 2025-10-14 06:51:51.868789 | TASK [bindep : Create temp dir for bindep] 2025-10-14 06:51:52.258147 | controller | changed 2025-10-14 06:51:52.264888 | 2025-10-14 06:51:52.264995 | TASK [Ensure we have pip dependencies] 2025-10-14 06:51:52.291152 | controller | ok 2025-10-14 06:51:52.325517 | 2025-10-14 06:51:52.325661 | TASK [ensure-pip : Check if pip is installed] 2025-10-14 02:51:52.653517 | controller | /usr/bin/pip3 2025-10-14 02:51:52.699918 | controller | /usr/bin/python3: No module named wheel 2025-10-14 06:51:52.862886 | controller | ok: Runtime: 0:00:00.064665 2025-10-14 06:51:52.875453 | 2025-10-14 06:51:52.875606 | LOOP [ensure-pip : Install pip from packages] 2025-10-14 06:51:52.924805 | controller | ok: "/var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-14 06:51:52.942626 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-14 06:51:52.965839 | 2025-10-14 06:51:52.965984 | TASK [ensure-pip : Install Python 3 pip] 2025-10-14 06:51:56.013649 | controller | changed 2025-10-14 06:51:56.027204 | 2025-10-14 06:51:56.027385 | TASK [ensure-pip : Check for EPEL repository] 2025-10-14 06:51:56.085340 | controller | skipping: Conditional result was False 2025-10-14 06:51:56.099921 | 2025-10-14 06:51:56.100130 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-14 06:51:56.148309 | controller | skipping: Conditional result was False 2025-10-14 06:51:56.164151 | 2025-10-14 06:51:56.164345 | TASK [ensure-pip : Install Python 2 pip] 2025-10-14 06:51:56.245821 | controller | skipping: Conditional result was False 2025-10-14 06:51:56.254490 | 2025-10-14 06:51:56.254609 | TASK [ensure-pip : Ensure setuptools] 2025-10-14 06:51:56.289659 | controller | skipping: Conditional result was False 2025-10-14 06:51:56.298463 | 2025-10-14 06:51:56.298567 | TASK [ensure-pip : Check for ensurepip module] 2025-10-14 06:51:56.830572 | controller | skipping: Conditional result was False 2025-10-14 06:51:56.844122 | 2025-10-14 06:51:56.844303 | TASK [ensure-pip : Ensure python3-venv] 2025-10-14 06:51:56.871459 | controller | skipping: Conditional result was False 2025-10-14 06:51:56.884776 | 2025-10-14 06:51:56.884940 | TASK [ensure-pip : Install pip from source] 2025-10-14 06:51:56.901502 | controller | skipping: Conditional result was False 2025-10-14 06:51:56.917961 | 2025-10-14 06:51:56.918197 | TASK [ensure-pip : Probe for venv python full path] 2025-10-14 02:51:57.209735 | controller | /usr/bin/python3 2025-10-14 06:51:57.476072 | controller | ok: Runtime: 0:00:00.007904 2025-10-14 06:51:57.482696 | 2025-10-14 06:51:57.482772 | TASK [ensure-pip : Set host default] 2025-10-14 06:51:57.523467 | controller | ok 2025-10-14 06:51:57.529119 | 2025-10-14 06:51:57.529200 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-14 06:51:57.580704 | controller | ok 2025-10-14 06:51:57.591396 | 2025-10-14 06:51:57.591486 | TASK [bindep : Install bindep into temporary venv] 2025-10-14 06:52:02.043521 | controller | changed 2025-10-14 06:52:02.048868 | 2025-10-14 06:52:02.048950 | TASK [bindep : Define bindep_command] 2025-10-14 06:52:02.075387 | controller | ok 2025-10-14 06:52:02.080781 | 2025-10-14 06:52:02.080873 | LOOP [bindep : Include package tasks] 2025-10-14 06:52:02.149365 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-14 06:52:02.149611 | controller | ok: All items complete 2025-10-14 06:52:02.149639 | 2025-10-14 06:52:02.166705 | controller | included: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-14 06:52:02.180384 | 2025-10-14 06:52:02.180507 | TASK [bindep : Define bindep_run fact] 2025-10-14 06:52:02.210590 | controller | ok 2025-10-14 06:52:02.216408 | 2025-10-14 06:52:02.216510 | TASK [bindep : Get list of packages to install from bindep] 2025-10-14 02:52:03.602760 | controller | podman 2025-10-14 02:52:03.643133 | controller | python3-jmespath 2025-10-14 02:52:03.643252 | controller | python3-libvirt 2025-10-14 02:52:03.643270 | controller | python3-lxml 2025-10-14 02:52:03.643284 | controller | python3-netaddr 2025-10-14 06:52:03.750601 | controller | ok: Runtime: 0:00:01.153181 2025-10-14 06:52:03.759737 | 2025-10-14 06:52:03.759878 | TASK [bindep : Install distro packages from bindep] 2025-10-14 06:53:05.146631 | controller | changed 2025-10-14 06:53:05.162335 | 2025-10-14 06:53:05.162530 | TASK [bindep : Check that packages are installed] 2025-10-14 06:53:06.712262 | controller | ok: Runtime: 0:00:01.101945 2025-10-14 06:53:06.718538 | 2025-10-14 06:53:06.718625 | TASK [bindep : Fail if we cannot install all packages] 2025-10-14 06:53:06.743454 | controller | skipping: Conditional result was False 2025-10-14 06:53:06.755257 | 2025-10-14 06:53:06.755384 | TASK [Run test-setup role] 2025-10-14 06:53:06.775586 | controller | ok 2025-10-14 06:53:06.791622 | 2025-10-14 06:53:06.791694 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-14 06:53:07.038487 | controller | ok 2025-10-14 06:53:07.047199 | 2025-10-14 06:53:07.047291 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-14 06:53:07.586443 | controller | skipping: Conditional result was False 2025-10-14 06:53:07.609456 | 2025-10-14 06:53:07.609537 | TASK [bindep : Remove bindep temp dir] 2025-10-14 06:53:08.014676 | controller | ok 2025-10-14 06:53:08.025686 | 2025-10-14 06:53:08.025756 | PLAY RECAP 2025-10-14 06:53:08.025804 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-14 06:53:08.025830 | 2025-10-14 06:53:08.142894 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-14 06:53:08.143963 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-14 06:53:08.698918 | 2025-10-14 06:53:08.699071 | PLAY [all] 2025-10-14 06:53:08.719113 | 2025-10-14 06:53:08.719256 | TASK [Abort when test_command variable is undefined] 2025-10-14 06:53:08.753902 | controller | skipping: Conditional result was False 2025-10-14 06:53:08.759471 | 2025-10-14 06:53:08.759550 | TASK [Convert test_command to list] 2025-10-14 06:53:08.793460 | controller | skipping: Conditional result was False 2025-10-14 06:53:08.800186 | 2025-10-14 06:53:08.800271 | TASK [Use test_command list] 2025-10-14 06:53:08.849146 | controller | ok 2025-10-14 06:53:08.854633 | 2025-10-14 06:53:08.854695 | LOOP [Run test_command] 2025-10-14 06:53:09.325639 | controller | no check to run 2025-10-14 06:53:09.325875 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006192 2025-10-14 06:53:09.359615 | 2025-10-14 06:53:09.359726 | PLAY RECAP 2025-10-14 06:53:09.359780 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-14 06:53:09.359809 | 2025-10-14 06:53:09.455291 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-14 06:53:09.456590 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-14 06:53:10.082665 | 2025-10-14 06:53:10.082780 | PLAY [all] 2025-10-14 06:53:10.103845 | 2025-10-14 06:53:10.103937 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-14 06:53:10.550581 | controller | changed: non-zero return code 2025-10-14 06:53:10.556204 | 2025-10-14 06:53:10.556279 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-14 06:53:10.580254 | controller | skipping: Conditional result was False 2025-10-14 06:53:10.586712 | 2025-10-14 06:53:10.586795 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-14 06:53:10.618788 | 2025-10-14 06:53:10.619051 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-14 06:53:10.650553 | 2025-10-14 06:53:10.650715 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-14 06:53:10.675079 | controller | skipping: Conditional result was False 2025-10-14 06:53:10.681920 | 2025-10-14 06:53:10.682038 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-14 06:53:10.714374 | 2025-10-14 06:53:10.714650 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-14 06:53:10.743344 | controller | skipping: Conditional result was False 2025-10-14 06:53:10.749672 | 2025-10-14 06:53:10.749750 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-14 06:53:10.774427 | controller | skipping: Conditional result was False 2025-10-14 06:53:10.782116 | 2025-10-14 06:53:10.782184 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-14 06:53:10.806295 | controller | skipping: Conditional result was False 2025-10-14 06:53:10.840819 | 2025-10-14 06:53:10.840918 | PLAY RECAP 2025-10-14 06:53:10.840964 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-14 06:53:10.840984 | 2025-10-14 06:53:10.951010 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-14 06:53:10.951848 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-14 06:53:11.557900 | 2025-10-14 06:53:11.558098 | PLAY [all] 2025-10-14 06:53:11.584360 | 2025-10-14 06:53:11.584491 | TASK [include_role : fetch-output] 2025-10-14 06:53:11.616432 | controller | ok 2025-10-14 06:53:11.646636 | 2025-10-14 06:53:11.646776 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-14 06:53:11.701456 | controller | skipping: Conditional result was False 2025-10-14 06:53:11.707965 | 2025-10-14 06:53:11.708123 | TASK [fetch-output : Set log path for single node] 2025-10-14 06:53:11.737646 | controller | ok 2025-10-14 06:53:11.742931 | 2025-10-14 06:53:11.743030 | LOOP [fetch-output : Ensure local output dirs] 2025-10-14 06:53:12.119806 | controller -> localhost | ok: "/var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/logs" 2025-10-14 06:53:12.357904 | controller -> localhost | changed: "/var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/artifacts" 2025-10-14 06:53:12.568519 | controller -> localhost | changed: "/var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/docs" 2025-10-14 06:53:12.578851 | 2025-10-14 06:53:12.578956 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-14 06:53:13.361389 | controller | changed: .d..t...... ./ 2025-10-14 06:53:13.361718 | controller | changed: All items complete 2025-10-14 06:53:13.361779 | 2025-10-14 06:53:13.850755 | controller | changed: .d..t...... ./ 2025-10-14 06:53:14.343673 | controller | changed: .d..t...... ./ 2025-10-14 06:53:14.357480 | 2025-10-14 06:53:14.357546 | TASK [include_role : fetch-output-openshift] 2025-10-14 06:53:14.371812 | controller | skipping: Conditional result was False 2025-10-14 06:53:14.379305 | 2025-10-14 06:53:14.379411 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-14 06:53:14.815217 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.021186 2025-10-14 06:53:15.020769 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007645 2025-10-14 06:53:15.057343 | 2025-10-14 06:53:15.057462 | PLAY [all] 2025-10-14 06:53:15.072369 | 2025-10-14 06:53:15.072450 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-14 06:53:15.521219 | controller | changed 2025-10-14 06:53:15.543864 | 2025-10-14 06:53:15.543919 | PLAY RECAP 2025-10-14 06:53:15.543959 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-14 06:53:15.543979 | 2025-10-14 06:53:15.639874 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-14 06:53:15.640701 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-14 06:53:16.299886 | 2025-10-14 06:53:16.300057 | PLAY [localhost] 2025-10-14 06:53:16.328169 | 2025-10-14 06:53:16.328310 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-14 06:53:16.815228 | localhost | changed 2025-10-14 06:53:16.819892 | 2025-10-14 06:53:16.819965 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-14 06:53:16.849030 | localhost | ok 2025-10-14 06:53:16.858222 | 2025-10-14 06:53:16.858294 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-14 06:53:17.203199 | localhost | changed 2025-10-14 06:53:17.212185 | 2025-10-14 06:53:17.212305 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-14 06:53:17.871976 | localhost | changed 2025-10-14 06:53:17.877397 | 2025-10-14 06:53:17.877479 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-14 06:53:18.272803 | localhost | Identity added: /var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/tmp/ansible.2ktg4xtf (/var/lib/zuul/builds/267512a9039f49fdb7800ec9df3e255b/work/tmp/ansible.2ktg4xtf) 2025-10-14 06:53:18.272986 | localhost | ok: Runtime: 0:00:00.015671 2025-10-14 06:53:18.278134 | 2025-10-14 06:53:18.278201 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-14 06:53:18.557323 | localhost | ok: Runtime: 0:00:00.012560 2025-10-14 06:53:18.563747 | 2025-10-14 06:53:18.563887 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-14 06:53:18.631738 | localhost | changed 2025-10-14 06:53:18.636073 | 2025-10-14 06:53:18.636143 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-14 06:53:19.050492 | localhost | changed 2025-10-14 06:53:19.086630 | 2025-10-14 06:53:19.086730 | PLAY [localhost] 2025-10-14 06:53:19.101944 | 2025-10-14 06:53:19.102084 | TASK [Generate bulk log download script] 2025-10-14 06:53:19.121348 | localhost | ok 2025-10-14 06:53:19.133605 | 2025-10-14 06:53:19.133675 | TASK [local-log-download : Check API endpoint is defined] 2025-10-14 06:53:19.162967 | localhost | ok: All assertions passed 2025-10-14 06:53:19.167707 | 2025-10-14 06:53:19.167771 | TASK [local-log-download : Create download script] 2025-10-14 06:53:19.603753 | localhost -> localhost | changed 2025-10-14 06:53:19.613734 | 2025-10-14 06:53:19.613819 | TASK [Register quick-download link] 2025-10-14 06:53:19.643468 | localhost | ok 2025-10-14 06:53:19.692868 | 2025-10-14 06:53:19.692987 | PLAY [logserver.rdoproject.org] 2025-10-14 06:53:19.707192 | 2025-10-14 06:53:19.707260 | TASK [Set zuul-log-path fact] 2025-10-14 06:53:19.724138 | logserver.rdoproject.org | ok 2025-10-14 06:53:19.734122 | 2025-10-14 06:53:19.734190 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-14 06:53:19.760351 | logserver.rdoproject.org | ok 2025-10-14 06:53:19.766012 | 2025-10-14 06:53:19.766093 | TASK [upload-logs : Create log directories] 2025-10-14 06:53:20.508384 | logserver.rdoproject.org | changed 2025-10-14 06:53:20.512088 | 2025-10-14 06:53:20.512167 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-14 06:53:20.793749 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006445 2025-10-14 06:53:20.798508 | 2025-10-14 06:53:20.798577 | TASK [upload-logs : Upload logs to log server] 2025-10-14 06:53:21.499983 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-14 06:53:21.506166 | 2025-10-14 06:53:21.506247 | LOOP [upload-logs : Compress console log and json output] 2025-10-14 06:53:21.559741 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:53:21.568730 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:53:21.578274 | 2025-10-14 06:53:21.578370 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-14 06:53:21.643628 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:53:21.643855 | 2025-10-14 06:53:21.647279 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 06:53:21.651757 | 2025-10-14 06:53:21.651854 | LOOP [upload-logs : Upload console log and json output]