2025-11-25 04:46:04.852060 | Job console starting... 2025-11-25 04:46:04.860634 | Updating repositories 2025-11-25 04:46:04.886482 | Preparing job workspace 2025-11-25 04:46:08.991900 | Running Ansible setup... 2025-11-25 04:46:12.859776 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-25 04:46:13.393047 | 2025-11-25 04:46:13.393217 | PLAY [localhost] 2025-11-25 04:46:13.401852 | 2025-11-25 04:46:13.401930 | TASK [Gathering Facts] 2025-11-25 04:46:14.428593 | localhost | ok 2025-11-25 04:46:14.453705 | 2025-11-25 04:46:14.453806 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-25 04:46:14.906328 | localhost -> localhost | changed 2025-11-25 04:46:14.917276 | 2025-11-25 04:46:14.917415 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-25 04:46:15.748181 | localhost -> localhost | changed 2025-11-25 04:46:15.759394 | 2025-11-25 04:46:15.759477 | TASK [Setup log path fact] 2025-11-25 04:46:15.781630 | localhost | ok 2025-11-25 04:46:15.796485 | 2025-11-25 04:46:15.796586 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-25 04:46:15.826399 | localhost | ok 2025-11-25 04:46:15.837320 | 2025-11-25 04:46:15.837408 | TASK [emit-job-header : Print job information] 2025-11-25 04:46:15.878059 | # Job Information 2025-11-25 04:46:15.878261 | Ansible Version: 2.15.12 2025-11-25 04:46:15.878330 | Job: cifmw-molecule-ovirt 2025-11-25 04:46:15.878360 | Pipeline: github-check 2025-11-25 04:46:15.878419 | Executor: ze01.softwarefactory-project.io 2025-11-25 04:46:15.878443 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3513 2025-11-25 04:46:15.878502 | Log URL (when completed): https://logserver.rdoproject.org/676/rdoproject.org/6766b0946a224f669d6da3f71083249a/ 2025-11-25 04:46:15.878530 | Event ID: 70e56560-c9b9-11f0-9a7b-08818148cbc7 2025-11-25 04:46:15.884045 | 2025-11-25 04:46:15.884126 | LOOP [emit-job-header : Print node information] 2025-11-25 04:46:15.989100 | localhost | ok: 2025-11-25 04:46:15.989288 | localhost | # Node Information 2025-11-25 04:46:15.989324 | localhost | Inventory Hostname: controller 2025-11-25 04:46:15.989354 | localhost | Hostname: np0005534355 2025-11-25 04:46:15.989380 | localhost | Username: zuul 2025-11-25 04:46:15.989406 | localhost | Distro: CentOS 9 2025-11-25 04:46:15.989431 | localhost | Provider: vexxhost-nodepool-tripleo 2025-11-25 04:46:15.989453 | localhost | Region: RegionOne 2025-11-25 04:46:15.989476 | localhost | Label: cloud-centos-9-stream-tripleo 2025-11-25 04:46:15.989499 | localhost | Product Name: OpenStack Nova 2025-11-25 04:46:15.989520 | localhost | Interface IP: 38.102.83.45 2025-11-25 04:46:16.020338 | 2025-11-25 04:46:16.020447 | PLAY [all] 2025-11-25 04:46:16.033107 | 2025-11-25 04:46:16.033214 | TASK [Gather network facts] 2025-11-25 04:46:16.565214 | controller | ok 2025-11-25 04:46:16.584835 | 2025-11-25 04:46:16.584913 | TASK [include_role : start-zuul-console] 2025-11-25 04:46:16.607737 | controller | ok 2025-11-25 04:46:16.623207 | 2025-11-25 04:46:16.623288 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-25 04:46:17.024673 | controller | ok 2025-11-25 04:46:17.043863 | 2025-11-25 04:46:17.043987 | TASK [include_role : add-build-sshkey] 2025-11-25 04:46:17.076892 | controller | ok 2025-11-25 04:46:17.093765 | 2025-11-25 04:46:17.093900 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-25 04:46:17.382870 | controller -> localhost | ok 2025-11-25 04:46:17.390260 | 2025-11-25 04:46:17.390362 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-25 04:46:17.424599 | controller | ok 2025-11-25 04:46:17.441131 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-25 04:46:17.448554 | 2025-11-25 04:46:17.448626 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-25 04:46:18.061640 | controller -> localhost | Generating public/private rsa key pair. 2025-11-25 04:46:18.061841 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/6766b0946a224f669d6da3f71083249a_id_rsa. 2025-11-25 04:46:18.061872 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/6766b0946a224f669d6da3f71083249a_id_rsa.pub. 2025-11-25 04:46:18.061893 | controller -> localhost | The key fingerprint is: 2025-11-25 04:46:18.061911 | controller -> localhost | SHA256:GLZl5/KRHv3WK4/5rUZd6aBp1uN1SkhmeRl2RvbRSIM zuul-build-sshkey 2025-11-25 04:46:18.061930 | controller -> localhost | The key's randomart image is: 2025-11-25 04:46:18.061947 | controller -> localhost | +---[RSA 3072]----+ 2025-11-25 04:46:18.061964 | controller -> localhost | | oo++| 2025-11-25 04:46:18.061982 | controller -> localhost | | E +o*| 2025-11-25 04:46:18.061999 | controller -> localhost | | o o . o =o| 2025-11-25 04:46:18.062142 | controller -> localhost | | . * o o=.o..| 2025-11-25 04:46:18.062174 | controller -> localhost | | o S =+=oo..| 2025-11-25 04:46:18.062194 | controller -> localhost | | + B.+o+o| 2025-11-25 04:46:18.062211 | controller -> localhost | | = .o=.o| 2025-11-25 04:46:18.062230 | controller -> localhost | | += o| 2025-11-25 04:46:18.062247 | controller -> localhost | | +==.| 2025-11-25 04:46:18.062264 | controller -> localhost | +----[SHA256]-----+ 2025-11-25 04:46:18.062309 | controller -> localhost | ok: Runtime: 0:00:00.174840 2025-11-25 04:46:18.067735 | 2025-11-25 04:46:18.067790 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-25 04:46:18.096116 | controller | ok 2025-11-25 04:46:18.105366 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-25 04:46:18.112887 | 2025-11-25 04:46:18.112943 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-25 04:46:18.136949 | controller | skipping: Conditional result was False 2025-11-25 04:46:18.142813 | 2025-11-25 04:46:18.142870 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-25 04:46:18.606889 | controller | changed 2025-11-25 04:46:18.611740 | 2025-11-25 04:46:18.611800 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-25 04:46:18.888381 | controller | ok 2025-11-25 04:46:18.895046 | 2025-11-25 04:46:18.895132 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-25 04:46:19.897374 | controller | changed 2025-11-25 04:46:19.908197 | 2025-11-25 04:46:19.908327 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-25 04:46:20.874586 | controller | changed 2025-11-25 04:46:20.886220 | 2025-11-25 04:46:20.886425 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-25 04:46:20.913163 | controller | skipping: Conditional result was False 2025-11-25 04:46:20.926952 | 2025-11-25 04:46:20.927197 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-25 04:46:21.327460 | controller -> localhost | changed 2025-11-25 04:46:21.342336 | 2025-11-25 04:46:21.342458 | TASK [add-build-sshkey : Add back temp key] 2025-11-25 04:46:21.674121 | controller -> localhost | Identity added: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/6766b0946a224f669d6da3f71083249a_id_rsa (zuul-build-sshkey) 2025-11-25 04:46:21.674502 | controller -> localhost | ok: Runtime: 0:00:00.013846 2025-11-25 04:46:21.686527 | 2025-11-25 04:46:21.686654 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-25 04:46:22.121636 | controller | ok 2025-11-25 04:46:22.132241 | 2025-11-25 04:46:22.132373 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-25 04:46:22.169341 | controller | skipping: Conditional result was False 2025-11-25 04:46:22.189490 | 2025-11-25 04:46:22.189626 | TASK [include_role : validate-host] 2025-11-25 04:46:22.226761 | controller | ok 2025-11-25 04:46:22.262322 | 2025-11-25 04:46:22.262448 | TASK [validate-host : Define zuul_info_dir fact] 2025-11-25 04:46:22.303834 | controller | ok 2025-11-25 04:46:22.310396 | 2025-11-25 04:46:22.310481 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-11-25 04:46:22.579484 | controller -> localhost | ok 2025-11-25 04:46:22.591978 | 2025-11-25 04:46:22.592152 | TASK [validate-host : Collect information about the host] 2025-11-25 04:46:23.442787 | controller | ok 2025-11-25 04:46:23.450843 | 2025-11-25 04:46:23.450916 | TASK [validate-host : Sanitize hostname] 2025-11-25 04:46:23.490374 | controller | ok 2025-11-25 04:46:23.495491 | 2025-11-25 04:46:23.495559 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-11-25 04:46:23.937998 | controller -> localhost | changed 2025-11-25 04:46:23.943552 | 2025-11-25 04:46:23.943614 | TASK [validate-host : Collect information about zuul worker] 2025-11-25 04:46:24.403449 | controller | ok 2025-11-25 04:46:24.413607 | 2025-11-25 04:46:24.413737 | TASK [validate-host : Write out all zuul information for each host] 2025-11-25 04:46:24.889290 | controller -> localhost | changed 2025-11-25 04:46:24.909233 | 2025-11-25 04:46:24.909357 | TASK [include_role : prepare-workspace-openshift] 2025-11-25 04:46:24.936142 | controller | skipping: Conditional result was False 2025-11-25 04:46:24.946418 | 2025-11-25 04:46:24.946546 | TASK [include_role : remove-zuul-sshkey] 2025-11-25 04:46:24.972748 | controller | skipping: Conditional result was False 2025-11-25 04:46:24.983478 | 2025-11-25 04:46:24.983631 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-25 04:46:25.309157 | controller | ok: "logs" 2025-11-25 04:46:25.309617 | controller | ok: All items complete 2025-11-25 04:46:25.309674 | 2025-11-25 04:46:25.552178 | controller | ok: "artifacts" 2025-11-25 04:46:25.826618 | controller | ok: "docs" 2025-11-25 04:46:25.841827 | 2025-11-25 04:46:25.842100 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-25 04:46:26.167696 | controller | changed: "logs" 2025-11-25 04:46:26.436007 | controller | changed: "artifacts" 2025-11-25 04:46:26.665986 | controller | changed: "docs" 2025-11-25 04:46:26.697883 | 2025-11-25 04:46:26.698046 | PLAY RECAP 2025-11-25 04:46:26.698119 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-11-25 04:46:26.698155 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-25 04:46:26.698180 | 2025-11-25 04:46:26.813163 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-25 04:46:26.814042 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-25 04:46:27.373820 | 2025-11-25 04:46:27.373965 | PLAY [localhost] 2025-11-25 04:46:27.390818 | 2025-11-25 04:46:27.390893 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-11-25 04:46:27.830996 | localhost | ok 2025-11-25 04:46:27.841592 | 2025-11-25 04:46:27.841750 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-11-25 04:46:28.593628 | localhost | changed 2025-11-25 04:46:28.634574 | 2025-11-25 04:46:28.634647 | PLAY [all] 2025-11-25 04:46:28.655078 | 2025-11-25 04:46:28.655165 | TASK [include_role : prepare-workspace] 2025-11-25 04:46:28.686368 | controller | ok 2025-11-25 04:46:28.705307 | 2025-11-25 04:46:28.705390 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-25 04:46:29.158054 | controller | ok 2025-11-25 04:46:29.171447 | 2025-11-25 04:46:29.171578 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-25 04:46:30.889731 | controller | Output suppressed because no_log was given 2025-11-25 04:46:30.910553 | 2025-11-25 04:46:30.910688 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-25 04:46:31.211724 | controller | changed: "logs" 2025-11-25 04:46:31.481190 | controller | changed: "artifacts" 2025-11-25 04:46:31.734650 | controller | changed: "docs" 2025-11-25 04:46:31.757718 | 2025-11-25 04:46:31.757869 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-25 04:46:32.093002 | controller | changed: "logs" 2025-11-25 04:46:32.093549 | controller | changed: All items complete 2025-11-25 04:46:32.093616 | 2025-11-25 04:46:32.361586 | controller | changed: "artifacts" 2025-11-25 04:46:32.601648 | controller | changed: "docs" 2025-11-25 04:46:32.632461 | 2025-11-25 04:46:32.632606 | TASK [Check if worker can sudo] 2025-11-25 04:46:33.195417 | controller | ok: Runtime: 0:00:00.051626 2025-11-25 04:46:33.208083 | 2025-11-25 04:46:33.208223 | TASK [configure-mirrors : Gather needed facts] 2025-11-25 04:46:33.288281 | controller | skipping: Conditional result was False 2025-11-25 04:46:33.302088 | 2025-11-25 04:46:33.302241 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-11-25 04:46:33.372350 | controller | ok 2025-11-25 04:46:33.388417 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-11-25 04:46:33.401553 | 2025-11-25 04:46:33.401680 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-11-25 04:46:33.740247 | controller | ok 2025-11-25 04:46:33.751727 | 2025-11-25 04:46:33.751851 | LOOP [configure-mirrors : Include OS-specific variables] 2025-11-25 04:46:33.842550 | controller | ok: "/var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-11-25 04:46:33.857959 | 2025-11-25 04:46:33.858194 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-11-25 04:46:34.913388 | controller | changed 2025-11-25 04:46:34.925698 | 2025-11-25 04:46:34.925898 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-11-25 04:46:35.017880 | controller | ok: "/var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-11-25 04:46:35.018412 | controller | ok: All items complete 2025-11-25 04:46:35.018480 | 2025-11-25 04:46:35.101428 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-11-25 04:46:35.110794 | 2025-11-25 04:46:35.110882 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-11-25 04:46:36.253730 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-11-25 04:46:37.464295 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-11-25 04:46:37.485700 | 2025-11-25 04:46:37.485843 | TASK [configure-mirrors : Disable deltrarpm] 2025-11-25 04:46:38.003943 | controller | changed: section and option added 2025-11-25 04:46:38.046005 | 2025-11-25 04:46:38.046183 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-11-25 04:46:38.876169 | controller | 29 files removed 2025-11-25 04:46:38.876584 | controller | ok: Item: dnf clean all Runtime: 0:00:00.456906 2025-11-25 04:46:38.876669 | controller | changed: All items complete 2025-11-25 04:46:38.876716 | 2025-11-25 04:46:49.007566 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-11-25 04:46:49.007736 | controller | DNF version: 4.14.0 2025-11-25 04:46:49.007797 | controller | cachedir: /var/cache/dnf 2025-11-25 04:46:49.007846 | controller | Making cache files for all metadata files. 2025-11-25 04:46:49.007892 | controller | baseos: has expired and will be refreshed. 2025-11-25 04:46:49.007937 | controller | appstream: has expired and will be refreshed. 2025-11-25 04:46:49.007976 | controller | crb: has expired and will be refreshed. 2025-11-25 04:46:49.008076 | controller | extras-common: has expired and will be refreshed. 2025-11-25 04:46:49.008139 | controller | repo: downloading from remote: baseos 2025-11-25 04:46:49.008184 | controller | CentOS Stream 9 - BaseOS 72 MB/s | 8.8 MB 00:00 2025-11-25 04:46:49.008228 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST. 2025-11-25 04:46:49.008269 | controller | repo: downloading from remote: appstream 2025-11-25 04:46:49.008310 | controller | CentOS Stream 9 - AppStream 106 MB/s | 25 MB 00:00 2025-11-25 04:46:49.008349 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST. 2025-11-25 04:46:49.008388 | controller | repo: downloading from remote: crb 2025-11-25 04:46:49.008427 | controller | CentOS Stream 9 - CRB 84 MB/s | 7.3 MB 00:00 2025-11-25 04:46:49.008468 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST. 2025-11-25 04:46:49.008510 | controller | repo: downloading from remote: extras-common 2025-11-25 04:46:49.008550 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-11-25 04:46:49.008589 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-11-25 04:46:49.008629 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-11-25 04:46:49.008669 | controller | Completion plugin: Generating completion cache... 2025-11-25 04:46:49.008707 | controller | Metadata cache created. 2025-11-25 04:46:49.008763 | controller | ok: Item: dnf makecache -v Runtime: 0:00:09.821144 2025-11-25 04:46:49.041907 | 2025-11-25 04:46:49.042108 | PLAY RECAP 2025-11-25 04:46:49.042201 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-11-25 04:46:49.042259 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-25 04:46:49.042300 | 2025-11-25 04:46:49.151849 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-25 04:46:49.153562 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-25 04:46:49.729700 | 2025-11-25 04:46:49.729804 | PLAY [all] 2025-11-25 04:46:49.750489 | 2025-11-25 04:46:49.750563 | TASK [Install binary dependencies] 2025-11-25 04:46:49.825294 | controller | ok 2025-11-25 04:46:49.858156 | 2025-11-25 04:46:49.858324 | TASK [bindep : Include find tasks] 2025-11-25 04:46:49.889931 | controller | ok 2025-11-25 04:46:49.900098 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-25 04:46:49.908136 | 2025-11-25 04:46:49.908222 | TASK [bindep : Look for bindep.txt] 2025-11-25 04:46:50.323439 | controller | ok 2025-11-25 04:46:50.337298 | 2025-11-25 04:46:50.337446 | TASK [bindep : Define bindep_file fact] 2025-11-25 04:46:50.385732 | controller | ok 2025-11-25 04:46:50.397220 | 2025-11-25 04:46:50.397363 | TASK [bindep : Look for other-requirements.txt] 2025-11-25 04:46:50.424805 | controller | skipping: Conditional result was False 2025-11-25 04:46:50.437275 | 2025-11-25 04:46:50.437424 | TASK [bindep : Define bindep_file fact] 2025-11-25 04:46:50.474734 | controller | skipping: Conditional result was False 2025-11-25 04:46:50.487590 | 2025-11-25 04:46:50.487737 | TASK [bindep : Look for bindep fallback file] 2025-11-25 04:46:50.524908 | controller | skipping: Conditional result was False 2025-11-25 04:46:50.537878 | 2025-11-25 04:46:50.538060 | TASK [bindep : Define bindep_file fact] 2025-11-25 04:46:50.565235 | controller | skipping: Conditional result was False 2025-11-25 04:46:50.578613 | 2025-11-25 04:46:50.578765 | TASK [bindep : Include bindep tasks] 2025-11-25 04:46:50.619615 | controller | ok 2025-11-25 04:46:50.635358 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-11-25 04:46:50.650730 | 2025-11-25 04:46:50.650815 | TASK [bindep : Look for bindep command] 2025-11-25 04:46:50.675342 | controller | skipping: Conditional result was False 2025-11-25 04:46:50.683577 | 2025-11-25 04:46:50.683664 | TASK [bindep : Check for system bindep] 2025-11-25 04:46:51.221922 | controller | ok: Runtime: 0:00:00.008418 2025-11-25 04:46:51.233999 | 2025-11-25 04:46:51.234165 | TASK [bindep : Define bindep_command fact] 2025-11-25 04:46:51.261298 | controller | skipping: Conditional result was False 2025-11-25 04:46:51.274125 | 2025-11-25 04:46:51.274269 | TASK [bindep : Include install tasks] 2025-11-25 04:46:51.311921 | controller | ok 2025-11-25 04:46:51.328620 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-11-25 04:46:51.346363 | 2025-11-25 04:46:51.346447 | TASK [bindep : Create temp dir for bindep] 2025-11-25 04:46:51.748417 | controller | changed 2025-11-25 04:46:51.759874 | 2025-11-25 04:46:51.759998 | TASK [Ensure we have pip dependencies] 2025-11-25 04:46:51.786334 | controller | ok 2025-11-25 04:46:51.829077 | 2025-11-25 04:46:51.829171 | TASK [ensure-pip : Check if pip is installed] 2025-11-24 23:46:52.143312 | controller | /usr/bin/pip3 2025-11-24 23:46:52.186569 | controller | /usr/bin/python3: No module named wheel 2025-11-25 04:46:52.366563 | controller | ok: Runtime: 0:00:00.060142 2025-11-25 04:46:52.378637 | 2025-11-25 04:46:52.378773 | LOOP [ensure-pip : Install pip from packages] 2025-11-25 04:46:52.423549 | controller | ok: "/var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-11-25 04:46:52.446143 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-11-25 04:46:52.467775 | 2025-11-25 04:46:52.467907 | TASK [ensure-pip : Install Python 3 pip] 2025-11-25 04:46:54.694092 | controller | changed 2025-11-25 04:46:54.705248 | 2025-11-25 04:46:54.705373 | TASK [ensure-pip : Check for EPEL repository] 2025-11-25 04:46:54.773270 | controller | skipping: Conditional result was False 2025-11-25 04:46:54.785903 | 2025-11-25 04:46:54.786102 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-11-25 04:46:54.853511 | controller | skipping: Conditional result was False 2025-11-25 04:46:54.866213 | 2025-11-25 04:46:54.866344 | TASK [ensure-pip : Install Python 2 pip] 2025-11-25 04:46:54.923470 | controller | skipping: Conditional result was False 2025-11-25 04:46:54.936860 | 2025-11-25 04:46:54.936994 | TASK [ensure-pip : Ensure setuptools] 2025-11-25 04:46:54.963710 | controller | skipping: Conditional result was False 2025-11-25 04:46:54.975600 | 2025-11-25 04:46:54.975730 | TASK [ensure-pip : Check for ensurepip module] 2025-11-25 04:46:55.522429 | controller | skipping: Conditional result was False 2025-11-25 04:46:55.535203 | 2025-11-25 04:46:55.535347 | TASK [ensure-pip : Ensure python3-venv] 2025-11-25 04:46:55.562305 | controller | skipping: Conditional result was False 2025-11-25 04:46:55.575297 | 2025-11-25 04:46:55.575474 | TASK [ensure-pip : Install pip from source] 2025-11-25 04:46:55.602780 | controller | skipping: Conditional result was False 2025-11-25 04:46:55.615275 | 2025-11-25 04:46:55.615412 | TASK [ensure-pip : Probe for venv python full path] 2025-11-24 23:46:55.939315 | controller | /usr/bin/python3 2025-11-25 04:46:56.163755 | controller | ok: Runtime: 0:00:00.009857 2025-11-25 04:46:56.175822 | 2025-11-25 04:46:56.175965 | TASK [ensure-pip : Set host default] 2025-11-25 04:46:56.230574 | controller | ok 2025-11-25 04:46:56.237844 | 2025-11-25 04:46:56.237927 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-11-25 04:46:56.316634 | controller | ok 2025-11-25 04:46:56.338301 | 2025-11-25 04:46:56.338436 | TASK [bindep : Install bindep into temporary venv] 2025-11-25 04:47:00.432282 | controller | changed 2025-11-25 04:47:00.444929 | 2025-11-25 04:47:00.445168 | TASK [bindep : Define bindep_command] 2025-11-25 04:47:00.485103 | controller | ok 2025-11-25 04:47:00.496455 | 2025-11-25 04:47:00.496584 | LOOP [bindep : Include package tasks] 2025-11-25 04:47:00.569511 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-11-25 04:47:00.569894 | controller | ok: All items complete 2025-11-25 04:47:00.569958 | 2025-11-25 04:47:00.596634 | controller | included: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-11-25 04:47:00.620774 | 2025-11-25 04:47:00.620888 | TASK [bindep : Define bindep_run fact] 2025-11-25 04:47:00.658579 | controller | ok 2025-11-25 04:47:00.669509 | 2025-11-25 04:47:00.669637 | TASK [bindep : Get list of packages to install from bindep] 2025-11-24 23:47:02.027330 | controller | podman 2025-11-24 23:47:02.074391 | controller | python3-jmespath 2025-11-24 23:47:02.074429 | controller | python3-libvirt 2025-11-24 23:47:02.074439 | controller | python3-lxml 2025-11-24 23:47:02.074448 | controller | python3-netaddr 2025-11-25 04:47:02.212222 | controller | ok: Runtime: 0:00:01.104381 2025-11-25 04:47:02.225296 | 2025-11-25 04:47:02.225439 | TASK [bindep : Install distro packages from bindep] 2025-11-25 04:48:04.319606 | controller | changed 2025-11-25 04:48:04.331404 | 2025-11-25 04:48:04.331531 | TASK [bindep : Check that packages are installed] 2025-11-25 04:48:06.380836 | controller | ok: Runtime: 0:00:01.211260 2025-11-25 04:48:06.392677 | 2025-11-25 04:48:06.392808 | TASK [bindep : Fail if we cannot install all packages] 2025-11-25 04:48:06.429876 | controller | skipping: Conditional result was False 2025-11-25 04:48:06.451590 | 2025-11-25 04:48:06.451723 | TASK [Run test-setup role] 2025-11-25 04:48:06.480898 | controller | ok 2025-11-25 04:48:06.508500 | 2025-11-25 04:48:06.508596 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-25 04:48:06.769898 | controller | ok 2025-11-25 04:48:06.780913 | 2025-11-25 04:48:06.781073 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-25 04:48:07.328828 | controller | skipping: Conditional result was False 2025-11-25 04:48:07.369778 | 2025-11-25 04:48:07.369919 | TASK [bindep : Remove bindep temp dir] 2025-11-25 04:48:07.755132 | controller | ok 2025-11-25 04:48:07.776296 | 2025-11-25 04:48:07.776408 | PLAY RECAP 2025-11-25 04:48:07.776490 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-11-25 04:48:07.776534 | 2025-11-25 04:48:07.886984 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-25 04:48:07.887888 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-25 04:48:08.424340 | 2025-11-25 04:48:08.424444 | PLAY [all] 2025-11-25 04:48:08.443885 | 2025-11-25 04:48:08.443957 | TASK [Abort when test_command variable is undefined] 2025-11-25 04:48:08.478372 | controller | skipping: Conditional result was False 2025-11-25 04:48:08.484094 | 2025-11-25 04:48:08.484361 | TASK [Convert test_command to list] 2025-11-25 04:48:08.538476 | controller | skipping: Conditional result was False 2025-11-25 04:48:08.544791 | 2025-11-25 04:48:08.544859 | TASK [Use test_command list] 2025-11-25 04:48:08.603648 | controller | ok 2025-11-25 04:48:08.608950 | 2025-11-25 04:48:08.609010 | LOOP [Run test_command] 2025-11-25 04:48:08.989794 | controller | no check to run 2025-11-25 04:48:08.990120 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.003867 2025-11-25 04:48:09.017397 | 2025-11-25 04:48:09.017506 | PLAY RECAP 2025-11-25 04:48:09.017550 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-25 04:48:09.017570 | 2025-11-25 04:48:09.106090 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-25 04:48:09.107225 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-25 04:48:09.646174 | 2025-11-25 04:48:09.646285 | PLAY [all] 2025-11-25 04:48:09.665738 | 2025-11-25 04:48:09.665812 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-25 04:48:10.098586 | controller | changed: non-zero return code 2025-11-25 04:48:10.110160 | 2025-11-25 04:48:10.110314 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-25 04:48:10.137382 | controller | skipping: Conditional result was False 2025-11-25 04:48:10.149286 | 2025-11-25 04:48:10.149429 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-25 04:48:10.188127 | 2025-11-25 04:48:10.188363 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-25 04:48:10.226283 | 2025-11-25 04:48:10.226524 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-25 04:48:10.253414 | controller | skipping: Conditional result was False 2025-11-25 04:48:10.265900 | 2025-11-25 04:48:10.266161 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-25 04:48:10.306502 | 2025-11-25 04:48:10.306739 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-25 04:48:10.333367 | controller | skipping: Conditional result was False 2025-11-25 04:48:10.345477 | 2025-11-25 04:48:10.345632 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-25 04:48:10.372890 | controller | skipping: Conditional result was False 2025-11-25 04:48:10.384815 | 2025-11-25 04:48:10.384948 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-25 04:48:10.411628 | controller | skipping: Conditional result was False 2025-11-25 04:48:10.457978 | 2025-11-25 04:48:10.458087 | PLAY RECAP 2025-11-25 04:48:10.458147 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-25 04:48:10.458175 | 2025-11-25 04:48:10.555002 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-25 04:48:10.556645 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-25 04:48:11.113764 | 2025-11-25 04:48:11.113869 | PLAY [all] 2025-11-25 04:48:11.132156 | 2025-11-25 04:48:11.132227 | TASK [include_role : fetch-output] 2025-11-25 04:48:11.171239 | controller | ok 2025-11-25 04:48:11.187516 | 2025-11-25 04:48:11.187587 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-25 04:48:11.262523 | controller | skipping: Conditional result was False 2025-11-25 04:48:11.274172 | 2025-11-25 04:48:11.274313 | TASK [fetch-output : Set log path for single node] 2025-11-25 04:48:11.321532 | controller | ok 2025-11-25 04:48:11.332398 | 2025-11-25 04:48:11.332538 | LOOP [fetch-output : Ensure local output dirs] 2025-11-25 04:48:11.807128 | controller -> localhost | ok: "/var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/logs" 2025-11-25 04:48:12.058737 | controller -> localhost | changed: "/var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/artifacts" 2025-11-25 04:48:12.285969 | controller -> localhost | changed: "/var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/docs" 2025-11-25 04:48:12.303836 | 2025-11-25 04:48:12.303949 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-25 04:48:13.013738 | controller | changed: .d..t...... ./ 2025-11-25 04:48:13.014178 | controller | changed: All items complete 2025-11-25 04:48:13.014237 | 2025-11-25 04:48:13.536929 | controller | changed: .d..t...... ./ 2025-11-25 04:48:14.084338 | controller | changed: .d..t...... ./ 2025-11-25 04:48:14.101097 | 2025-11-25 04:48:14.101241 | TASK [include_role : fetch-output-openshift] 2025-11-25 04:48:14.127274 | controller | skipping: Conditional result was False 2025-11-25 04:48:14.135429 | 2025-11-25 04:48:14.135554 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-25 04:48:14.581139 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013074 2025-11-25 04:48:14.864078 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012896 2025-11-25 04:48:14.909169 | 2025-11-25 04:48:14.909290 | PLAY [all] 2025-11-25 04:48:14.927660 | 2025-11-25 04:48:14.927739 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-11-25 04:48:15.412307 | controller | changed 2025-11-25 04:48:15.456089 | 2025-11-25 04:48:15.456157 | PLAY RECAP 2025-11-25 04:48:15.456208 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-25 04:48:15.456234 | 2025-11-25 04:48:15.547870 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-25 04:48:15.548695 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-11-25 04:48:16.113705 | 2025-11-25 04:48:16.113847 | PLAY [localhost] 2025-11-25 04:48:16.131636 | 2025-11-25 04:48:16.131715 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-25 04:48:16.561657 | localhost | changed 2025-11-25 04:48:16.571730 | 2025-11-25 04:48:16.571885 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-25 04:48:16.608476 | localhost | ok 2025-11-25 04:48:16.626785 | 2025-11-25 04:48:16.626941 | TASK [add-fileserver : Create SSH private key tempfile] 2025-11-25 04:48:17.039876 | localhost | changed 2025-11-25 04:48:17.051592 | 2025-11-25 04:48:17.051729 | TASK [add-fileserver : Create SSH private key from secret] 2025-11-25 04:48:17.830138 | localhost | changed 2025-11-25 04:48:17.840968 | 2025-11-25 04:48:17.841146 | TASK [add-fileserver : Add fileserver ssh key] 2025-11-25 04:48:18.299427 | localhost | Identity added: /var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/tmp/ansible.qm_jsir6 (/var/lib/zuul/builds/6766b0946a224f669d6da3f71083249a/work/tmp/ansible.qm_jsir6) 2025-11-25 04:48:18.299614 | localhost | ok: Runtime: 0:00:00.006890 2025-11-25 04:48:18.303821 | 2025-11-25 04:48:18.303882 | TASK [add-fileserver : Remove SSH private key from disk] 2025-11-25 04:48:18.605358 | localhost | ok: Runtime: 0:00:00.007957 2025-11-25 04:48:18.609896 | 2025-11-25 04:48:18.609954 | TASK [add-fileserver : Add fileserver to inventory] 2025-11-25 04:48:18.657907 | localhost | changed 2025-11-25 04:48:18.661950 | 2025-11-25 04:48:18.662010 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-11-25 04:48:19.104344 | localhost | changed 2025-11-25 04:48:19.143994 | 2025-11-25 04:48:19.144107 | PLAY [localhost] 2025-11-25 04:48:19.160259 | 2025-11-25 04:48:19.160338 | TASK [Generate bulk log download script] 2025-11-25 04:48:19.180357 | localhost | ok 2025-11-25 04:48:19.195722 | 2025-11-25 04:48:19.195805 | TASK [local-log-download : Check API endpoint is defined] 2025-11-25 04:48:19.235927 | localhost | ok: All assertions passed 2025-11-25 04:48:19.242078 | 2025-11-25 04:48:19.242162 | TASK [local-log-download : Create download script] 2025-11-25 04:48:19.673223 | localhost -> localhost | changed 2025-11-25 04:48:19.692162 | 2025-11-25 04:48:19.692316 | TASK [Register quick-download link] 2025-11-25 04:48:19.717235 | localhost | ok 2025-11-25 04:48:19.771819 | 2025-11-25 04:48:19.771932 | PLAY [logserver.rdoproject.org] 2025-11-25 04:48:19.782192 | 2025-11-25 04:48:19.782251 | TASK [Set zuul-log-path fact] 2025-11-25 04:48:19.798065 | logserver.rdoproject.org | ok 2025-11-25 04:48:19.806619 | 2025-11-25 04:48:19.806678 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-25 04:48:19.833516 | logserver.rdoproject.org | ok 2025-11-25 04:48:19.840404 | 2025-11-25 04:48:19.840484 | TASK [upload-logs : Create log directories] 2025-11-25 04:48:20.739486 | logserver.rdoproject.org | changed 2025-11-25 04:48:20.745994 | 2025-11-25 04:48:20.746155 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-11-25 04:48:21.069831 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005597 2025-11-25 04:48:21.076610 | 2025-11-25 04:48:21.076733 | TASK [upload-logs : Upload logs to log server] 2025-11-25 04:48:21.852594 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-11-25 04:48:21.859390 | 2025-11-25 04:48:21.859520 | LOOP [upload-logs : Compress console log and json output] 2025-11-25 04:48:21.929767 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 04:48:21.941805 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 04:48:21.956066 | 2025-11-25 04:48:21.956311 | LOOP [upload-logs : Upload compressed console log and json output] 2025-11-25 04:48:22.010222 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 04:48:22.010799 | 2025-11-25 04:48:22.013239 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 04:48:22.023715 | 2025-11-25 04:48:22.023950 | LOOP [upload-logs : Upload console log and json output]