2025-10-10 06:53:08.492083 | Job console starting... 2025-10-10 06:53:08.505397 | Updating repositories 2025-10-10 06:53:08.536938 | Preparing job workspace 2025-10-10 06:53:13.273289 | Running Ansible setup... 2025-10-10 06:53:17.800538 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-10 06:53:18.445349 | 2025-10-10 06:53:18.445532 | PLAY [localhost] 2025-10-10 06:53:18.456035 | 2025-10-10 06:53:18.456134 | TASK [Gathering Facts] 2025-10-10 06:53:19.542585 | localhost | ok 2025-10-10 06:53:19.562041 | 2025-10-10 06:53:19.562151 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-10 06:53:20.006839 | localhost -> localhost | changed 2025-10-10 06:53:20.013753 | 2025-10-10 06:53:20.013825 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-10 06:53:20.902868 | localhost -> localhost | changed 2025-10-10 06:53:20.912769 | 2025-10-10 06:53:20.914840 | TASK [Setup log path fact] 2025-10-10 06:53:20.936843 | localhost | ok 2025-10-10 06:53:20.949393 | 2025-10-10 06:53:20.949464 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-10 06:53:20.978695 | localhost | ok 2025-10-10 06:53:20.986843 | 2025-10-10 06:53:20.986915 | TASK [emit-job-header : Print job information] 2025-10-10 06:53:21.026329 | # Job Information 2025-10-10 06:53:21.026466 | Ansible Version: 2.15.12 2025-10-10 06:53:21.026491 | Job: cifmw-molecule-cifmw_setup 2025-10-10 06:53:21.026510 | Pipeline: github-check 2025-10-10 06:53:21.026527 | Executor: ze04.softwarefactory-project.io 2025-10-10 06:53:21.026544 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368 2025-10-10 06:53:21.026575 | Log URL (when completed): https://logserver.rdoproject.org/7f4/rdoproject.org/7f4022e0b68a43f3b995acc8a4afe4d2/ 2025-10-10 06:53:21.026593 | Event ID: 8a4e75b0-a5a5-11f0-9ecc-7c01429874ad 2025-10-10 06:53:21.030284 | 2025-10-10 06:53:21.030348 | LOOP [emit-job-header : Print node information] 2025-10-10 06:53:21.150855 | localhost | ok: 2025-10-10 06:53:21.151160 | localhost | # Node Information 2025-10-10 06:53:21.151198 | localhost | Inventory Hostname: controller 2025-10-10 06:53:21.151229 | localhost | Hostname: np0005479463 2025-10-10 06:53:21.151254 | localhost | Username: zuul 2025-10-10 06:53:21.151281 | localhost | Distro: CentOS 9 2025-10-10 06:53:21.151305 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-10 06:53:21.151327 | localhost | Region: RegionOne 2025-10-10 06:53:21.151349 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-10 06:53:21.151371 | localhost | Product Name: OpenStack Nova 2025-10-10 06:53:21.151393 | localhost | Interface IP: 38.129.56.111 2025-10-10 06:53:21.178291 | 2025-10-10 06:53:21.178485 | PLAY [all] 2025-10-10 06:53:21.185487 | 2025-10-10 06:53:21.185552 | TASK [Gather network facts] 2025-10-10 06:53:21.711825 | controller | ok 2025-10-10 06:53:21.733631 | 2025-10-10 06:53:21.733730 | TASK [include_role : start-zuul-console] 2025-10-10 06:53:21.765385 | controller | ok 2025-10-10 06:53:21.777969 | 2025-10-10 06:53:21.778042 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-10 06:53:22.240042 | controller | ok 2025-10-10 06:53:22.250184 | 2025-10-10 06:53:22.250250 | TASK [include_role : add-build-sshkey] 2025-10-10 06:53:22.279026 | controller | ok 2025-10-10 06:53:22.292839 | 2025-10-10 06:53:22.292926 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-10 06:53:22.544140 | controller -> localhost | ok 2025-10-10 06:53:22.550115 | 2025-10-10 06:53:22.550193 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-10 06:53:22.599339 | controller | ok 2025-10-10 06:53:22.617474 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-10 06:53:22.624018 | 2025-10-10 06:53:22.624083 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-10 06:53:23.329207 | controller -> localhost | Generating public/private rsa key pair. 2025-10-10 06:53:23.329631 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/7f4022e0b68a43f3b995acc8a4afe4d2_id_rsa. 2025-10-10 06:53:23.329735 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/7f4022e0b68a43f3b995acc8a4afe4d2_id_rsa.pub. 2025-10-10 06:53:23.329807 | controller -> localhost | The key fingerprint is: 2025-10-10 06:53:23.329860 | controller -> localhost | SHA256:V/whp1Y6GaM9hTgvXmlsfW1ruKzz6Cu2N9SoZq2LEj8 zuul-build-sshkey 2025-10-10 06:53:23.329904 | controller -> localhost | The key's randomart image is: 2025-10-10 06:53:23.329947 | controller -> localhost | +---[RSA 3072]----+ 2025-10-10 06:53:23.329988 | controller -> localhost | | | 2025-10-10 06:53:23.330032 | controller -> localhost | | o . | 2025-10-10 06:53:23.330074 | controller -> localhost | | o B = | 2025-10-10 06:53:23.330132 | controller -> localhost | | B # ..| 2025-10-10 06:53:23.330180 | controller -> localhost | | S + ^ o +| 2025-10-10 06:53:23.330220 | controller -> localhost | | . o O +.o.| 2025-10-10 06:53:23.330386 | controller -> localhost | | o = . o | 2025-10-10 06:53:23.330475 | controller -> localhost | | . E.* =o o | 2025-10-10 06:53:23.330528 | controller -> localhost | | ..=+B=*+ | 2025-10-10 06:53:23.330572 | controller -> localhost | +----[SHA256]-----+ 2025-10-10 06:53:23.330771 | controller -> localhost | ok: Runtime: 0:00:00.308668 2025-10-10 06:53:23.344064 | 2025-10-10 06:53:23.344222 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-10 06:53:23.382101 | controller | ok 2025-10-10 06:53:23.406063 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-10 06:53:23.418378 | 2025-10-10 06:53:23.418475 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-10 06:53:23.456143 | controller | skipping: Conditional result was False 2025-10-10 06:53:23.467289 | 2025-10-10 06:53:23.467395 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-10 06:53:24.028135 | controller | changed 2025-10-10 06:53:24.038074 | 2025-10-10 06:53:24.038172 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-10 06:53:24.314288 | controller | ok 2025-10-10 06:53:24.329396 | 2025-10-10 06:53:24.329570 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-10 06:53:25.226278 | controller | changed 2025-10-10 06:53:25.234099 | 2025-10-10 06:53:25.234554 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-10 06:53:26.242671 | controller | changed 2025-10-10 06:53:26.250986 | 2025-10-10 06:53:26.251055 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-10 06:53:26.280944 | controller | skipping: Conditional result was False 2025-10-10 06:53:26.289258 | 2025-10-10 06:53:26.289467 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-10 06:53:26.746794 | controller -> localhost | changed 2025-10-10 06:53:26.757359 | 2025-10-10 06:53:26.757431 | TASK [add-build-sshkey : Add back temp key] 2025-10-10 06:53:27.077434 | controller -> localhost | Identity added: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/7f4022e0b68a43f3b995acc8a4afe4d2_id_rsa (zuul-build-sshkey) 2025-10-10 06:53:27.077771 | controller -> localhost | ok: Runtime: 0:00:00.016990 2025-10-10 06:53:27.083935 | 2025-10-10 06:53:27.084104 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-10 06:53:27.555652 | controller | ok 2025-10-10 06:53:27.566091 | 2025-10-10 06:53:27.566233 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-10 06:53:27.616616 | controller | skipping: Conditional result was False 2025-10-10 06:53:27.637765 | 2025-10-10 06:53:27.637907 | TASK [include_role : validate-host] 2025-10-10 06:53:27.679637 | controller | ok 2025-10-10 06:53:27.723315 | 2025-10-10 06:53:27.723491 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-10 06:53:27.769194 | controller | ok 2025-10-10 06:53:27.776036 | 2025-10-10 06:53:27.776131 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-10 06:53:28.101296 | controller -> localhost | ok 2025-10-10 06:53:28.118827 | 2025-10-10 06:53:28.119017 | TASK [validate-host : Collect information about the host] 2025-10-10 06:53:28.977852 | controller | ok 2025-10-10 06:53:28.996221 | 2025-10-10 06:53:28.996355 | TASK [validate-host : Sanitize hostname] 2025-10-10 06:53:29.097450 | controller | ok 2025-10-10 06:53:29.110155 | 2025-10-10 06:53:29.110302 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-10 06:53:29.669188 | controller -> localhost | changed 2025-10-10 06:53:29.679070 | 2025-10-10 06:53:29.679168 | TASK [validate-host : Collect information about zuul worker] 2025-10-10 06:53:30.217629 | controller | ok 2025-10-10 06:53:30.228613 | 2025-10-10 06:53:30.228784 | TASK [validate-host : Write out all zuul information for each host] 2025-10-10 06:53:30.759073 | controller -> localhost | changed 2025-10-10 06:53:30.769028 | 2025-10-10 06:53:30.769093 | TASK [include_role : prepare-workspace-openshift] 2025-10-10 06:53:30.793634 | controller | skipping: Conditional result was False 2025-10-10 06:53:30.798637 | 2025-10-10 06:53:30.798717 | TASK [include_role : remove-zuul-sshkey] 2025-10-10 06:53:30.822590 | controller | skipping: Conditional result was False 2025-10-10 06:53:30.827807 | 2025-10-10 06:53:30.827873 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-10 06:53:31.145011 | controller | ok: "logs" 2025-10-10 06:53:31.145468 | controller | ok: All items complete 2025-10-10 06:53:31.145531 | 2025-10-10 06:53:31.402452 | controller | ok: "artifacts" 2025-10-10 06:53:31.711346 | controller | ok: "docs" 2025-10-10 06:53:31.727465 | 2025-10-10 06:53:31.727623 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-10 06:53:32.001803 | controller | changed: "logs" 2025-10-10 06:53:32.262832 | controller | changed: "artifacts" 2025-10-10 06:53:32.525523 | controller | changed: "docs" 2025-10-10 06:53:32.572538 | 2025-10-10 06:53:32.572617 | PLAY RECAP 2025-10-10 06:53:32.572668 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-10 06:53:32.572745 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-10 06:53:32.572771 | 2025-10-10 06:53:32.690097 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-10 06:53:32.692289 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-10 06:53:33.293982 | 2025-10-10 06:53:33.294108 | PLAY [localhost] 2025-10-10 06:53:33.310150 | 2025-10-10 06:53:33.310226 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-10 06:53:33.704004 | localhost | ok 2025-10-10 06:53:33.709561 | 2025-10-10 06:53:33.709640 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-10 06:53:34.451825 | localhost | changed 2025-10-10 06:53:34.497843 | 2025-10-10 06:53:34.498082 | PLAY [all] 2025-10-10 06:53:34.527824 | 2025-10-10 06:53:34.527893 | TASK [include_role : prepare-workspace] 2025-10-10 06:53:34.560004 | controller | ok 2025-10-10 06:53:34.579861 | 2025-10-10 06:53:34.579959 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-10 06:53:35.057584 | controller | ok 2025-10-10 06:53:35.067771 | 2025-10-10 06:53:35.067846 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-10 06:53:37.462505 | controller | Output suppressed because no_log was given 2025-10-10 06:53:37.477488 | 2025-10-10 06:53:37.477564 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-10 06:53:37.826405 | controller | changed: "logs" 2025-10-10 06:53:38.062452 | controller | changed: "artifacts" 2025-10-10 06:53:38.292129 | controller | changed: "docs" 2025-10-10 06:53:38.299163 | 2025-10-10 06:53:38.299228 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-10 06:53:38.598830 | controller | changed: "logs" 2025-10-10 06:53:38.599355 | controller | changed: All items complete 2025-10-10 06:53:38.600023 | 2025-10-10 06:53:38.830201 | controller | changed: "artifacts" 2025-10-10 06:53:39.068852 | controller | changed: "docs" 2025-10-10 06:53:39.089589 | 2025-10-10 06:53:39.089741 | TASK [Check if worker can sudo] 2025-10-10 06:53:40.128772 | controller | ok: Runtime: 0:00:00.066133 2025-10-10 06:53:40.134501 | 2025-10-10 06:53:40.134564 | TASK [configure-mirrors : Gather needed facts] 2025-10-10 06:53:40.231251 | controller | skipping: Conditional result was False 2025-10-10 06:53:40.237272 | 2025-10-10 06:53:40.237336 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-10 06:53:40.328196 | controller | ok 2025-10-10 06:53:40.394930 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-10 06:53:40.401114 | 2025-10-10 06:53:40.401185 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-10 06:53:40.728273 | controller | ok 2025-10-10 06:53:40.734293 | 2025-10-10 06:53:40.734358 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-10 06:53:40.859569 | controller | ok: "/var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-10 06:53:40.877877 | 2025-10-10 06:53:40.878017 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-10 06:53:41.850515 | controller | changed 2025-10-10 06:53:41.859507 | 2025-10-10 06:53:41.859572 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-10 06:53:41.908814 | controller | ok: "/var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-10 06:53:41.909037 | controller | ok: All items complete 2025-10-10 06:53:41.909066 | 2025-10-10 06:53:41.958635 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-10 06:53:41.965166 | 2025-10-10 06:53:41.965231 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-10 06:53:42.999839 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-10 06:53:43.927453 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-10 06:53:43.943245 | 2025-10-10 06:53:43.943388 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-10 06:53:44.440130 | controller | changed: section and option added 2025-10-10 06:53:44.460358 | 2025-10-10 06:53:44.460425 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-10 06:53:45.379597 | controller | 29 files removed 2025-10-10 06:53:45.379931 | controller | ok: Item: dnf clean all Runtime: 0:00:00.540432 2025-10-10 06:53:45.379989 | controller | changed: All items complete 2025-10-10 06:53:45.380019 | 2025-10-10 06:53:56.092558 | 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-10 06:53:56.092740 | controller | DNF version: 4.14.0 2025-10-10 06:53:56.092774 | controller | cachedir: /var/cache/dnf 2025-10-10 06:53:56.092826 | controller | Making cache files for all metadata files. 2025-10-10 06:53:56.092848 | controller | baseos: has expired and will be refreshed. 2025-10-10 06:53:56.092866 | controller | appstream: has expired and will be refreshed. 2025-10-10 06:53:56.092883 | controller | crb: has expired and will be refreshed. 2025-10-10 06:53:56.092910 | controller | extras-common: has expired and will be refreshed. 2025-10-10 06:53:56.092926 | controller | repo: downloading from remote: baseos 2025-10-10 06:53:56.092970 | controller | CentOS Stream 9 - BaseOS 67 MB/s | 8.8 MB 00:00 2025-10-10 06:53:56.092990 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-10 06:53:56.093007 | controller | repo: downloading from remote: appstream 2025-10-10 06:53:56.093024 | controller | CentOS Stream 9 - AppStream 65 MB/s | 25 MB 00:00 2025-10-10 06:53:56.093040 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-10 06:53:56.093057 | controller | repo: downloading from remote: crb 2025-10-10 06:53:56.093073 | controller | CentOS Stream 9 - CRB 57 MB/s | 7.2 MB 00:00 2025-10-10 06:53:56.093089 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-10 06:53:56.093105 | controller | repo: downloading from remote: extras-common 2025-10-10 06:53:56.093122 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-10 06:53:56.093138 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-10 06:53:56.093154 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-10 06:53:56.093198 | controller | Completion plugin: Generating completion cache... 2025-10-10 06:53:56.093217 | controller | Metadata cache created. 2025-10-10 06:53:56.093249 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.397108 2025-10-10 06:53:56.117394 | 2025-10-10 06:53:56.117500 | PLAY RECAP 2025-10-10 06:53:56.117586 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-10 06:53:56.117641 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-10 06:53:56.117713 | 2025-10-10 06:53:56.244706 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-10 06:53:56.246377 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-10 06:53:56.835647 | 2025-10-10 06:53:56.835974 | PLAY [all] 2025-10-10 06:53:56.863612 | 2025-10-10 06:53:56.863791 | TASK [Install binary dependencies] 2025-10-10 06:53:56.914574 | controller | ok 2025-10-10 06:53:56.935507 | 2025-10-10 06:53:56.935654 | TASK [bindep : Include find tasks] 2025-10-10 06:53:56.977897 | controller | ok 2025-10-10 06:53:56.985293 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-10 06:53:56.991333 | 2025-10-10 06:53:56.991398 | TASK [bindep : Look for bindep.txt] 2025-10-10 06:53:57.454660 | controller | ok 2025-10-10 06:53:57.473901 | 2025-10-10 06:53:57.474057 | TASK [bindep : Define bindep_file fact] 2025-10-10 06:53:57.506120 | controller | ok 2025-10-10 06:53:57.513150 | 2025-10-10 06:53:57.513242 | TASK [bindep : Look for other-requirements.txt] 2025-10-10 06:53:57.528950 | controller | skipping: Conditional result was False 2025-10-10 06:53:57.537053 | 2025-10-10 06:53:57.537149 | TASK [bindep : Define bindep_file fact] 2025-10-10 06:53:57.562029 | controller | skipping: Conditional result was False 2025-10-10 06:53:57.569825 | 2025-10-10 06:53:57.569915 | TASK [bindep : Look for bindep fallback file] 2025-10-10 06:53:57.594496 | controller | skipping: Conditional result was False 2025-10-10 06:53:57.602891 | 2025-10-10 06:53:57.602984 | TASK [bindep : Define bindep_file fact] 2025-10-10 06:53:57.627909 | controller | skipping: Conditional result was False 2025-10-10 06:53:57.636090 | 2025-10-10 06:53:57.636176 | TASK [bindep : Include bindep tasks] 2025-10-10 06:53:57.670663 | controller | ok 2025-10-10 06:53:57.680025 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-10 06:53:57.691186 | 2025-10-10 06:53:57.691273 | TASK [bindep : Look for bindep command] 2025-10-10 06:53:57.730806 | controller | skipping: Conditional result was False 2025-10-10 06:53:57.737783 | 2025-10-10 06:53:57.737872 | TASK [bindep : Check for system bindep] 2025-10-10 06:53:58.279074 | controller | ok: Runtime: 0:00:00.008545 2025-10-10 06:53:58.285241 | 2025-10-10 06:53:58.285309 | TASK [bindep : Define bindep_command fact] 2025-10-10 06:53:58.310172 | controller | skipping: Conditional result was False 2025-10-10 06:53:58.323794 | 2025-10-10 06:53:58.323937 | TASK [bindep : Include install tasks] 2025-10-10 06:53:58.372402 | controller | ok 2025-10-10 06:53:58.388519 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-10 06:53:58.404435 | 2025-10-10 06:53:58.404520 | TASK [bindep : Create temp dir for bindep] 2025-10-10 06:53:58.831858 | controller | changed 2025-10-10 06:53:58.837268 | 2025-10-10 06:53:58.837330 | TASK [Ensure we have pip dependencies] 2025-10-10 06:53:58.857184 | controller | ok 2025-10-10 06:53:58.881541 | 2025-10-10 06:53:58.881612 | TASK [ensure-pip : Check if pip is installed] 2025-10-10 02:53:59.174433 | controller | /usr/bin/pip3 2025-10-10 02:53:59.220162 | controller | /usr/bin/python3: No module named wheel 2025-10-10 06:53:59.412315 | controller | ok: Runtime: 0:00:00.059290 2025-10-10 06:53:59.422386 | 2025-10-10 06:53:59.422477 | LOOP [ensure-pip : Install pip from packages] 2025-10-10 06:53:59.472216 | controller | ok: "/var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-10 06:53:59.498292 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-10 06:53:59.512908 | 2025-10-10 06:53:59.513001 | TASK [ensure-pip : Install Python 3 pip] 2025-10-10 06:54:01.894869 | controller | changed 2025-10-10 06:54:01.900164 | 2025-10-10 06:54:01.900225 | TASK [ensure-pip : Check for EPEL repository] 2025-10-10 06:54:01.945865 | controller | skipping: Conditional result was False 2025-10-10 06:54:01.952229 | 2025-10-10 06:54:01.952297 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-10 06:54:01.986406 | controller | skipping: Conditional result was False 2025-10-10 06:54:01.992620 | 2025-10-10 06:54:01.992699 | TASK [ensure-pip : Install Python 2 pip] 2025-10-10 06:54:02.036893 | controller | skipping: Conditional result was False 2025-10-10 06:54:02.044442 | 2025-10-10 06:54:02.044525 | TASK [ensure-pip : Ensure setuptools] 2025-10-10 06:54:02.057626 | controller | skipping: Conditional result was False 2025-10-10 06:54:02.063784 | 2025-10-10 06:54:02.063848 | TASK [ensure-pip : Check for ensurepip module] 2025-10-10 06:54:02.595829 | controller | skipping: Conditional result was False 2025-10-10 06:54:02.602567 | 2025-10-10 06:54:02.602643 | TASK [ensure-pip : Ensure python3-venv] 2025-10-10 06:54:02.626836 | controller | skipping: Conditional result was False 2025-10-10 06:54:02.636351 | 2025-10-10 06:54:02.636475 | TASK [ensure-pip : Install pip from source] 2025-10-10 06:54:02.653959 | controller | skipping: Conditional result was False 2025-10-10 06:54:02.660800 | 2025-10-10 06:54:02.660888 | TASK [ensure-pip : Probe for venv python full path] 2025-10-10 02:54:02.913910 | controller | /usr/bin/python3 2025-10-10 06:54:03.199045 | controller | ok: Runtime: 0:00:00.007899 2025-10-10 06:54:03.204939 | 2025-10-10 06:54:03.205007 | TASK [ensure-pip : Set host default] 2025-10-10 06:54:03.284395 | controller | ok 2025-10-10 06:54:03.289402 | 2025-10-10 06:54:03.289468 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-10 06:54:03.344634 | controller | ok 2025-10-10 06:54:03.355766 | 2025-10-10 06:54:03.355838 | TASK [bindep : Install bindep into temporary venv] 2025-10-10 06:54:07.699988 | controller | changed 2025-10-10 06:54:07.712261 | 2025-10-10 06:54:07.712395 | TASK [bindep : Define bindep_command] 2025-10-10 06:54:07.741422 | controller | ok 2025-10-10 06:54:07.753391 | 2025-10-10 06:54:07.753519 | LOOP [bindep : Include package tasks] 2025-10-10 06:54:07.800121 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-10 06:54:07.800430 | controller | ok: All items complete 2025-10-10 06:54:07.800625 | 2025-10-10 06:54:07.822517 | controller | included: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-10 06:54:07.839646 | 2025-10-10 06:54:07.839803 | TASK [bindep : Define bindep_run fact] 2025-10-10 06:54:07.874648 | controller | ok 2025-10-10 06:54:07.884296 | 2025-10-10 06:54:07.884393 | TASK [bindep : Get list of packages to install from bindep] 2025-10-10 02:54:09.367180 | controller | podman 2025-10-10 02:54:09.406276 | controller | python3-jmespath 2025-10-10 02:54:09.406556 | controller | python3-libvirt 2025-10-10 02:54:09.406582 | controller | python3-lxml 2025-10-10 02:54:09.406596 | controller | python3-netaddr 2025-10-10 06:54:09.452402 | controller | ok: Runtime: 0:00:01.234549 2025-10-10 06:54:09.464556 | 2025-10-10 06:54:09.464851 | TASK [bindep : Install distro packages from bindep] 2025-10-10 06:55:14.838477 | controller | changed 2025-10-10 06:55:14.851182 | 2025-10-10 06:55:14.851315 | TASK [bindep : Check that packages are installed] 2025-10-10 06:55:16.400751 | controller | ok: Runtime: 0:00:01.110299 2025-10-10 06:55:16.415805 | 2025-10-10 06:55:16.415950 | TASK [bindep : Fail if we cannot install all packages] 2025-10-10 06:55:16.454292 | controller | skipping: Conditional result was False 2025-10-10 06:55:16.478994 | 2025-10-10 06:55:16.479152 | TASK [Run test-setup role] 2025-10-10 06:55:16.511851 | controller | ok 2025-10-10 06:55:16.543191 | 2025-10-10 06:55:16.543433 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-10 06:55:16.748641 | controller | ok 2025-10-10 06:55:16.755897 | 2025-10-10 06:55:16.755983 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-10 06:55:17.295515 | controller | skipping: Conditional result was False 2025-10-10 06:55:17.341360 | 2025-10-10 06:55:17.341495 | TASK [bindep : Remove bindep temp dir] 2025-10-10 06:55:17.770657 | controller | ok 2025-10-10 06:55:17.796657 | 2025-10-10 06:55:17.796802 | PLAY RECAP 2025-10-10 06:55:17.797025 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-10 06:55:17.797085 | 2025-10-10 06:55:17.925439 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-10 06:55:17.926370 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-10 06:55:18.483648 | 2025-10-10 06:55:18.483794 | PLAY [all] 2025-10-10 06:55:18.502640 | 2025-10-10 06:55:18.502728 | TASK [Abort when test_command variable is undefined] 2025-10-10 06:55:18.526931 | controller | skipping: Conditional result was False 2025-10-10 06:55:18.532269 | 2025-10-10 06:55:18.532339 | TASK [Convert test_command to list] 2025-10-10 06:55:18.566697 | controller | skipping: Conditional result was False 2025-10-10 06:55:18.575246 | 2025-10-10 06:55:18.575331 | TASK [Use test_command list] 2025-10-10 06:55:18.650544 | controller | ok 2025-10-10 06:55:18.661760 | 2025-10-10 06:55:18.661897 | LOOP [Run test_command] 2025-10-10 06:55:19.062888 | controller | no check to run 2025-10-10 06:55:19.063245 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006827 2025-10-10 06:55:19.109411 | 2025-10-10 06:55:19.109663 | PLAY RECAP 2025-10-10 06:55:19.109811 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-10 06:55:19.109857 | 2025-10-10 06:55:19.225052 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-10 06:55:19.226855 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-10 06:55:19.813820 | 2025-10-10 06:55:19.813947 | PLAY [all] 2025-10-10 06:55:19.833746 | 2025-10-10 06:55:19.833821 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-10 06:55:20.182089 | controller | changed: non-zero return code 2025-10-10 06:55:20.194338 | 2025-10-10 06:55:20.194498 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-10 06:55:20.221816 | controller | skipping: Conditional result was False 2025-10-10 06:55:20.233947 | 2025-10-10 06:55:20.234099 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-10 06:55:20.273223 | 2025-10-10 06:55:20.273497 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-10 06:55:20.312749 | 2025-10-10 06:55:20.313031 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-10 06:55:20.339961 | controller | skipping: Conditional result was False 2025-10-10 06:55:20.352366 | 2025-10-10 06:55:20.352510 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-10 06:55:20.390858 | 2025-10-10 06:55:20.391130 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-10 06:55:20.421264 | controller | skipping: Conditional result was False 2025-10-10 06:55:20.432804 | 2025-10-10 06:55:20.432949 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-10 06:55:20.459521 | controller | skipping: Conditional result was False 2025-10-10 06:55:20.471360 | 2025-10-10 06:55:20.471497 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-10 06:55:20.498193 | controller | skipping: Conditional result was False 2025-10-10 06:55:20.546098 | 2025-10-10 06:55:20.546258 | PLAY RECAP 2025-10-10 06:55:20.546319 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-10 06:55:20.546347 | 2025-10-10 06:55:20.650675 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-10 06:55:20.652396 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-10 06:55:21.229996 | 2025-10-10 06:55:21.230121 | PLAY [all] 2025-10-10 06:55:21.249205 | 2025-10-10 06:55:21.249287 | TASK [include_role : fetch-output] 2025-10-10 06:55:21.279260 | controller | ok 2025-10-10 06:55:21.296032 | 2025-10-10 06:55:21.296122 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-10 06:55:21.361317 | controller | skipping: Conditional result was False 2025-10-10 06:55:21.374549 | 2025-10-10 06:55:21.374738 | TASK [fetch-output : Set log path for single node] 2025-10-10 06:55:21.422740 | controller | ok 2025-10-10 06:55:21.434560 | 2025-10-10 06:55:21.434760 | LOOP [fetch-output : Ensure local output dirs] 2025-10-10 06:55:21.878589 | controller -> localhost | ok: "/var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/logs" 2025-10-10 06:55:22.161623 | controller -> localhost | changed: "/var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/artifacts" 2025-10-10 06:55:22.425012 | controller -> localhost | changed: "/var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/docs" 2025-10-10 06:55:22.440758 | 2025-10-10 06:55:22.440896 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-10 06:55:23.125180 | controller | changed: .d..t...... ./ 2025-10-10 06:55:23.125573 | controller | changed: All items complete 2025-10-10 06:55:23.125606 | 2025-10-10 06:55:23.626009 | controller | changed: .d..t...... ./ 2025-10-10 06:55:24.135865 | controller | changed: .d..t...... ./ 2025-10-10 06:55:24.159269 | 2025-10-10 06:55:24.159378 | TASK [include_role : fetch-output-openshift] 2025-10-10 06:55:24.184407 | controller | skipping: Conditional result was False 2025-10-10 06:55:24.192046 | 2025-10-10 06:55:24.192135 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-10 06:55:24.642268 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008348 2025-10-10 06:55:24.911053 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013386 2025-10-10 06:55:24.962057 | 2025-10-10 06:55:24.962209 | PLAY [all] 2025-10-10 06:55:24.983172 | 2025-10-10 06:55:24.983343 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-10 06:55:25.478842 | controller | changed 2025-10-10 06:55:25.524448 | 2025-10-10 06:55:25.524531 | PLAY RECAP 2025-10-10 06:55:25.524585 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-10 06:55:25.524612 | 2025-10-10 06:55:25.639547 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-10 06:55:25.641306 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-10 06:55:26.262924 | 2025-10-10 06:55:26.263042 | PLAY [localhost] 2025-10-10 06:55:26.281576 | 2025-10-10 06:55:26.281661 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-10 06:55:26.712437 | localhost | changed 2025-10-10 06:55:26.722642 | 2025-10-10 06:55:26.722867 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-10 06:55:26.759249 | localhost | ok 2025-10-10 06:55:26.777324 | 2025-10-10 06:55:26.777498 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-10 06:55:27.202221 | localhost | changed 2025-10-10 06:55:27.214786 | 2025-10-10 06:55:27.214931 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-10 06:55:27.928066 | localhost | changed 2025-10-10 06:55:27.933117 | 2025-10-10 06:55:27.933186 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-10 06:55:28.353954 | localhost | Identity added: /var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/tmp/ansible.wznxljn8 (/var/lib/zuul/builds/7f4022e0b68a43f3b995acc8a4afe4d2/work/tmp/ansible.wznxljn8) 2025-10-10 06:55:28.354272 | localhost | ok: Runtime: 0:00:00.007369 2025-10-10 06:55:28.364005 | 2025-10-10 06:55:28.364143 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-10 06:55:28.634011 | localhost | ok: Runtime: 0:00:00.008815 2025-10-10 06:55:28.644650 | 2025-10-10 06:55:28.644818 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-10 06:55:28.702246 | localhost | changed 2025-10-10 06:55:28.711651 | 2025-10-10 06:55:28.711817 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-10 06:55:29.110291 | localhost | changed 2025-10-10 06:55:29.138208 | 2025-10-10 06:55:29.138282 | PLAY [localhost] 2025-10-10 06:55:29.155466 | 2025-10-10 06:55:29.155546 | TASK [Generate bulk log download script] 2025-10-10 06:55:29.175417 | localhost | ok 2025-10-10 06:55:29.191290 | 2025-10-10 06:55:29.191374 | TASK [local-log-download : Check API endpoint is defined] 2025-10-10 06:55:29.221725 | localhost | ok: All assertions passed 2025-10-10 06:55:29.227866 | 2025-10-10 06:55:29.227948 | TASK [local-log-download : Create download script] 2025-10-10 06:55:29.618858 | localhost -> localhost | changed 2025-10-10 06:55:29.638605 | 2025-10-10 06:55:29.638791 | TASK [Register quick-download link] 2025-10-10 06:55:29.674390 | localhost | ok 2025-10-10 06:55:29.734921 | 2025-10-10 06:55:29.735060 | PLAY [logserver.rdoproject.org] 2025-10-10 06:55:29.748176 | 2025-10-10 06:55:29.748257 | TASK [Set zuul-log-path fact] 2025-10-10 06:55:29.766907 | logserver.rdoproject.org | ok 2025-10-10 06:55:29.779014 | 2025-10-10 06:55:29.779099 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-10 06:55:29.817046 | logserver.rdoproject.org | ok 2025-10-10 06:55:29.824488 | 2025-10-10 06:55:29.824570 | TASK [upload-logs : Create log directories] 2025-10-10 06:55:30.602546 | logserver.rdoproject.org | changed 2025-10-10 06:55:30.610432 | 2025-10-10 06:55:30.610567 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-10 06:55:30.954769 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004872 2025-10-10 06:55:30.964791 | 2025-10-10 06:55:30.964933 | TASK [upload-logs : Upload logs to log server] 2025-10-10 06:55:31.768803 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-10 06:55:31.772853 | 2025-10-10 06:55:31.772937 | LOOP [upload-logs : Compress console log and json output] 2025-10-10 06:55:31.840081 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-10 06:55:31.851502 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-10 06:55:31.860294 | 2025-10-10 06:55:31.860437 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-10 06:55:31.913391 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-10 06:55:31.913822 | 2025-10-10 06:55:31.914869 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-10 06:55:31.924438 | 2025-10-10 06:55:31.924577 | LOOP [upload-logs : Upload console log and json output]