2025-12-01 11:48:23.899548 | Job console starting... 2025-12-01 11:48:23.912179 | Updating repositories 2025-12-01 11:48:23.949412 | Preparing job workspace 2025-12-01 11:48:33.649479 | Running Ansible setup... 2025-12-01 11:48:37.493519 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-01 11:48:38.073213 | 2025-12-01 11:48:38.073332 | PLAY [localhost] 2025-12-01 11:48:38.082231 | 2025-12-01 11:48:38.082309 | TASK [Gathering Facts] 2025-12-01 11:48:39.077480 | localhost | ok 2025-12-01 11:48:39.112620 | 2025-12-01 11:48:39.112876 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-01 11:48:39.569144 | localhost -> localhost | changed 2025-12-01 11:48:39.575675 | 2025-12-01 11:48:39.575762 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-01 11:48:40.443342 | localhost -> localhost | changed 2025-12-01 11:48:40.463465 | 2025-12-01 11:48:40.463596 | TASK [Setup log path fact] 2025-12-01 11:48:40.487784 | localhost | ok 2025-12-01 11:48:40.503163 | 2025-12-01 11:48:40.503249 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 11:48:40.533482 | localhost | ok 2025-12-01 11:48:40.544193 | 2025-12-01 11:48:40.544284 | TASK [emit-job-header : Print job information] 2025-12-01 11:48:40.583696 | # Job Information 2025-12-01 11:48:40.583866 | Ansible Version: 2.15.12 2025-12-01 11:48:40.583903 | Job: cifmw-molecule-cifmw_setup 2025-12-01 11:48:40.583932 | Pipeline: github-check 2025-12-01 11:48:40.583959 | Executor: ze03.softwarefactory-project.io 2025-12-01 11:48:40.583986 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3505 2025-12-01 11:48:40.584013 | Log URL (when completed): https://logserver.rdoproject.org/67e/rdoproject.org/67e68b7e80ab4c71bc60afd86099a155/ 2025-12-01 11:48:40.584040 | Event ID: 7d6e1060-ceab-11f0-849c-6a034ea3071d 2025-12-01 11:48:40.589477 | 2025-12-01 11:48:40.589561 | LOOP [emit-job-header : Print node information] 2025-12-01 11:48:40.689921 | localhost | ok: 2025-12-01 11:48:40.690272 | localhost | # Node Information 2025-12-01 11:48:40.690333 | localhost | Inventory Hostname: controller 2025-12-01 11:48:40.690382 | localhost | Hostname: np0005541059 2025-12-01 11:48:40.690424 | localhost | Username: zuul 2025-12-01 11:48:40.690469 | localhost | Distro: CentOS 9 2025-12-01 11:48:40.690507 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-01 11:48:40.690546 | localhost | Region: RegionOne 2025-12-01 11:48:40.690582 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-01 11:48:40.690618 | localhost | Product Name: OpenStack Nova 2025-12-01 11:48:40.690654 | localhost | Interface IP: 38.102.83.70 2025-12-01 11:48:40.721091 | 2025-12-01 11:48:40.721203 | PLAY [all] 2025-12-01 11:48:40.729875 | 2025-12-01 11:48:40.729959 | TASK [Gather network facts] 2025-12-01 11:48:41.276234 | controller | ok 2025-12-01 11:48:41.307690 | 2025-12-01 11:48:41.307866 | TASK [include_role : start-zuul-console] 2025-12-01 11:48:41.335722 | controller | ok 2025-12-01 11:48:41.362999 | 2025-12-01 11:48:41.363140 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-01 11:48:41.846598 | controller | ok 2025-12-01 11:48:41.865127 | 2025-12-01 11:48:41.865257 | TASK [include_role : add-build-sshkey] 2025-12-01 11:48:41.902559 | controller | ok 2025-12-01 11:48:41.928455 | 2025-12-01 11:48:41.928546 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-01 11:48:42.220837 | controller -> localhost | ok 2025-12-01 11:48:42.232902 | 2025-12-01 11:48:42.233039 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-01 11:48:42.281273 | controller | ok 2025-12-01 11:48:42.308651 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-01 11:48:42.319127 | 2025-12-01 11:48:42.319221 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-01 11:48:43.162045 | controller -> localhost | Generating public/private rsa key pair. 2025-12-01 11:48:43.162372 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/67e68b7e80ab4c71bc60afd86099a155_id_rsa. 2025-12-01 11:48:43.162472 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/67e68b7e80ab4c71bc60afd86099a155_id_rsa.pub. 2025-12-01 11:48:43.162520 | controller -> localhost | The key fingerprint is: 2025-12-01 11:48:43.162563 | controller -> localhost | SHA256:VP117RBNRNOxWjrVZqyvyZeCST15lQe9367u9Pd1jAw zuul-build-sshkey 2025-12-01 11:48:43.162603 | controller -> localhost | The key's randomart image is: 2025-12-01 11:48:43.162643 | controller -> localhost | +---[RSA 3072]----+ 2025-12-01 11:48:43.162680 | controller -> localhost | | .. .XB| 2025-12-01 11:48:43.162719 | controller -> localhost | | . . o.@| 2025-12-01 11:48:43.162804 | controller -> localhost | | . . OO| 2025-12-01 11:48:43.162846 | controller -> localhost | | . **+| 2025-12-01 11:48:43.162883 | controller -> localhost | | S E+o =| 2025-12-01 11:48:43.162920 | controller -> localhost | | . *.=o| 2025-12-01 11:48:43.162957 | controller -> localhost | | . o *.*| 2025-12-01 11:48:43.162994 | controller -> localhost | | o + =*| 2025-12-01 11:48:43.163030 | controller -> localhost | | oOo=| 2025-12-01 11:48:43.163066 | controller -> localhost | +----[SHA256]-----+ 2025-12-01 11:48:43.163156 | controller -> localhost | ok: Runtime: 0:00:00.311074 2025-12-01 11:48:43.175464 | 2025-12-01 11:48:43.175616 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-01 11:48:43.213100 | controller | ok 2025-12-01 11:48:43.235268 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-01 11:48:43.249978 | 2025-12-01 11:48:43.250118 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-01 11:48:43.275785 | controller | skipping: Conditional result was False 2025-12-01 11:48:43.289820 | 2025-12-01 11:48:43.289984 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-01 11:48:43.790303 | controller | changed 2025-12-01 11:48:43.796816 | 2025-12-01 11:48:43.796885 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-01 11:48:44.037127 | controller | ok 2025-12-01 11:48:44.042022 | 2025-12-01 11:48:44.042082 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-01 11:48:44.969965 | controller | changed 2025-12-01 11:48:44.980623 | 2025-12-01 11:48:44.980785 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-01 11:48:45.989074 | controller | changed 2025-12-01 11:48:46.000833 | 2025-12-01 11:48:46.001008 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-01 11:48:46.031942 | controller | skipping: Conditional result was False 2025-12-01 11:48:46.046193 | 2025-12-01 11:48:46.046439 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-01 11:48:46.503745 | controller -> localhost | changed 2025-12-01 11:48:46.519526 | 2025-12-01 11:48:46.519706 | TASK [add-build-sshkey : Add back temp key] 2025-12-01 11:48:46.840847 | controller -> localhost | Identity added: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/67e68b7e80ab4c71bc60afd86099a155_id_rsa (zuul-build-sshkey) 2025-12-01 11:48:46.841079 | controller -> localhost | ok: Runtime: 0:00:00.016112 2025-12-01 11:48:46.848604 | 2025-12-01 11:48:46.848686 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-01 11:48:47.233255 | controller | ok 2025-12-01 11:48:47.240515 | 2025-12-01 11:48:47.240610 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-01 11:48:47.278047 | controller | skipping: Conditional result was False 2025-12-01 11:48:47.291666 | 2025-12-01 11:48:47.291817 | TASK [include_role : validate-host] 2025-12-01 11:48:47.332843 | controller | ok 2025-12-01 11:48:47.352901 | 2025-12-01 11:48:47.353025 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-01 11:48:47.398053 | controller | ok 2025-12-01 11:48:47.403176 | 2025-12-01 11:48:47.403268 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-01 11:48:47.672925 | controller -> localhost | ok 2025-12-01 11:48:47.679815 | 2025-12-01 11:48:47.679893 | TASK [validate-host : Collect information about the host] 2025-12-01 11:48:48.533627 | controller | ok 2025-12-01 11:48:48.554127 | 2025-12-01 11:48:48.554333 | TASK [validate-host : Sanitize hostname] 2025-12-01 11:48:48.629245 | controller | ok 2025-12-01 11:48:48.636411 | 2025-12-01 11:48:48.636506 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-01 11:48:49.223675 | controller -> localhost | changed 2025-12-01 11:48:49.234417 | 2025-12-01 11:48:49.234545 | TASK [validate-host : Collect information about zuul worker] 2025-12-01 11:48:49.686564 | controller | ok 2025-12-01 11:48:49.697091 | 2025-12-01 11:48:49.697284 | TASK [validate-host : Write out all zuul information for each host] 2025-12-01 11:48:50.195423 | controller -> localhost | changed 2025-12-01 11:48:50.220149 | 2025-12-01 11:48:50.220349 | TASK [include_role : prepare-workspace-openshift] 2025-12-01 11:48:50.248087 | controller | skipping: Conditional result was False 2025-12-01 11:48:50.259187 | 2025-12-01 11:48:50.259330 | TASK [include_role : remove-zuul-sshkey] 2025-12-01 11:48:50.287229 | controller | skipping: Conditional result was False 2025-12-01 11:48:50.298965 | 2025-12-01 11:48:50.299118 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-01 11:48:50.616175 | controller | ok: "logs" 2025-12-01 11:48:50.616596 | controller | ok: All items complete 2025-12-01 11:48:50.616658 | 2025-12-01 11:48:50.866938 | controller | ok: "artifacts" 2025-12-01 11:48:51.129623 | controller | ok: "docs" 2025-12-01 11:48:51.149056 | 2025-12-01 11:48:51.149238 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-01 11:48:51.438386 | controller | changed: "logs" 2025-12-01 11:48:51.710784 | controller | changed: "artifacts" 2025-12-01 11:48:51.971876 | controller | changed: "docs" 2025-12-01 11:48:52.018568 | 2025-12-01 11:48:52.018667 | PLAY RECAP 2025-12-01 11:48:52.018709 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-01 11:48:52.018756 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-01 11:48:52.018776 | 2025-12-01 11:48:52.112835 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-01 11:48:52.113999 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-01 11:48:52.762113 | 2025-12-01 11:48:52.762213 | PLAY [localhost] 2025-12-01 11:48:52.779217 | 2025-12-01 11:48:52.779334 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-01 11:48:53.144559 | localhost | ok 2025-12-01 11:48:53.150457 | 2025-12-01 11:48:53.150542 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-01 11:48:53.779148 | localhost | changed 2025-12-01 11:48:53.817467 | 2025-12-01 11:48:53.817574 | PLAY [all] 2025-12-01 11:48:53.857400 | 2025-12-01 11:48:53.857563 | TASK [include_role : prepare-workspace] 2025-12-01 11:48:53.888654 | controller | ok 2025-12-01 11:48:53.903601 | 2025-12-01 11:48:53.903670 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-01 11:48:54.357527 | controller | ok 2025-12-01 11:48:54.363865 | 2025-12-01 11:48:54.363927 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-01 11:48:55.980073 | controller | Output suppressed because no_log was given 2025-12-01 11:48:55.997228 | 2025-12-01 11:48:55.997366 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-01 11:48:56.295269 | controller | changed: "logs" 2025-12-01 11:48:56.523999 | controller | changed: "artifacts" 2025-12-01 11:48:56.799218 | controller | changed: "docs" 2025-12-01 11:48:56.806433 | 2025-12-01 11:48:56.806511 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-01 11:48:57.079435 | controller | changed: "logs" 2025-12-01 11:48:57.079745 | controller | changed: All items complete 2025-12-01 11:48:57.079793 | 2025-12-01 11:48:57.530195 | controller | changed: "artifacts" 2025-12-01 11:48:57.803476 | controller | changed: "docs" 2025-12-01 11:48:57.836418 | 2025-12-01 11:48:57.836573 | TASK [Check if worker can sudo] 2025-12-01 11:48:58.409887 | controller | ok: Runtime: 0:00:00.052498 2025-12-01 11:48:58.434833 | 2025-12-01 11:48:58.435218 | TASK [configure-mirrors : Gather needed facts] 2025-12-01 11:48:58.528306 | controller | skipping: Conditional result was False 2025-12-01 11:48:58.538612 | 2025-12-01 11:48:58.538758 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-01 11:48:58.591927 | controller | ok 2025-12-01 11:48:58.602658 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-01 11:48:58.611420 | 2025-12-01 11:48:58.611507 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-01 11:48:58.931124 | controller | ok 2025-12-01 11:48:58.938968 | 2025-12-01 11:48:58.939060 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-01 11:48:59.027762 | controller | ok: "/var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-01 11:48:59.045323 | 2025-12-01 11:48:59.045462 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-01 11:48:59.923471 | controller | changed 2025-12-01 11:48:59.937072 | 2025-12-01 11:48:59.937290 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-01 11:49:00.011138 | controller | ok: "/var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-01 11:49:00.011429 | controller | ok: All items complete 2025-12-01 11:49:00.011487 | 2025-12-01 11:49:00.089172 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-01 11:49:00.098039 | 2025-12-01 11:49:00.098107 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-01 11:49:01.174625 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-01 11:49:02.143969 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-01 11:49:02.163998 | 2025-12-01 11:49:02.164243 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-01 11:49:02.659077 | controller | changed: section and option added 2025-12-01 11:49:02.703023 | 2025-12-01 11:49:02.703167 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-01 11:49:03.398958 | controller | 29 files removed 2025-12-01 11:49:03.399576 | controller | ok: Item: dnf clean all Runtime: 0:00:00.328726 2025-12-01 11:49:03.399704 | controller | changed: All items complete 2025-12-01 11:49:03.399815 | 2025-12-01 11:49:14.042004 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-01 11:49:14.042192 | controller | DNF version: 4.14.0 2025-12-01 11:49:14.042252 | controller | cachedir: /var/cache/dnf 2025-12-01 11:49:14.042302 | controller | Making cache files for all metadata files. 2025-12-01 11:49:14.042348 | controller | baseos: has expired and will be refreshed. 2025-12-01 11:49:14.042389 | controller | appstream: has expired and will be refreshed. 2025-12-01 11:49:14.042431 | controller | crb: has expired and will be refreshed. 2025-12-01 11:49:14.042491 | controller | extras-common: has expired and will be refreshed. 2025-12-01 11:49:14.042534 | controller | repo: downloading from remote: baseos 2025-12-01 11:49:14.042577 | controller | CentOS Stream 9 - BaseOS 54 MB/s | 8.8 MB 00:00 2025-12-01 11:49:14.042618 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST. 2025-12-01 11:49:14.042659 | controller | repo: downloading from remote: appstream 2025-12-01 11:49:14.042700 | controller | CentOS Stream 9 - AppStream 63 MB/s | 25 MB 00:00 2025-12-01 11:49:14.042780 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST. 2025-12-01 11:49:14.042827 | controller | repo: downloading from remote: crb 2025-12-01 11:49:14.042868 | controller | CentOS Stream 9 - CRB 71 MB/s | 7.3 MB 00:00 2025-12-01 11:49:14.042909 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST. 2025-12-01 11:49:14.042950 | controller | repo: downloading from remote: extras-common 2025-12-01 11:49:14.042991 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-12-01 11:49:14.043032 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-01 11:49:14.043073 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-01 11:49:14.043114 | controller | Completion plugin: Generating completion cache... 2025-12-01 11:49:14.043155 | controller | Metadata cache created. 2025-12-01 11:49:14.043220 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.346251 2025-12-01 11:49:14.070462 | 2025-12-01 11:49:14.070617 | PLAY RECAP 2025-12-01 11:49:14.070699 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-01 11:49:14.070795 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-01 11:49:14.070838 | 2025-12-01 11:49:14.226829 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-01 11:49:14.228438 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 11:49:14.840242 | 2025-12-01 11:49:14.840355 | PLAY [all] 2025-12-01 11:49:14.862179 | 2025-12-01 11:49:14.862285 | TASK [Install binary dependencies] 2025-12-01 11:49:14.931294 | controller | ok 2025-12-01 11:49:14.949563 | 2025-12-01 11:49:14.949651 | TASK [bindep : Include find tasks] 2025-12-01 11:49:14.980238 | controller | ok 2025-12-01 11:49:14.990466 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-01 11:49:14.998651 | 2025-12-01 11:49:14.998792 | TASK [bindep : Look for bindep.txt] 2025-12-01 11:49:15.442152 | controller | ok 2025-12-01 11:49:15.456440 | 2025-12-01 11:49:15.456633 | TASK [bindep : Define bindep_file fact] 2025-12-01 11:49:15.504057 | controller | ok 2025-12-01 11:49:15.515543 | 2025-12-01 11:49:15.515775 | TASK [bindep : Look for other-requirements.txt] 2025-12-01 11:49:15.542502 | controller | skipping: Conditional result was False 2025-12-01 11:49:15.555578 | 2025-12-01 11:49:15.555803 | TASK [bindep : Define bindep_file fact] 2025-12-01 11:49:15.593144 | controller | skipping: Conditional result was False 2025-12-01 11:49:15.606275 | 2025-12-01 11:49:15.606477 | TASK [bindep : Look for bindep fallback file] 2025-12-01 11:49:15.644279 | controller | skipping: Conditional result was False 2025-12-01 11:49:15.657142 | 2025-12-01 11:49:15.657310 | TASK [bindep : Define bindep_file fact] 2025-12-01 11:49:15.694402 | controller | skipping: Conditional result was False 2025-12-01 11:49:15.706620 | 2025-12-01 11:49:15.706801 | TASK [bindep : Include bindep tasks] 2025-12-01 11:49:15.757421 | controller | ok 2025-12-01 11:49:15.771666 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-01 11:49:15.786779 | 2025-12-01 11:49:15.786895 | TASK [bindep : Look for bindep command] 2025-12-01 11:49:15.822279 | controller | skipping: Conditional result was False 2025-12-01 11:49:15.831040 | 2025-12-01 11:49:15.831166 | TASK [bindep : Check for system bindep] 2025-12-01 11:49:16.371776 | controller | ok: Runtime: 0:00:00.007874 2025-12-01 11:49:16.384715 | 2025-12-01 11:49:16.384906 | TASK [bindep : Define bindep_command fact] 2025-12-01 11:49:16.426525 | controller | skipping: Conditional result was False 2025-12-01 11:49:16.439330 | 2025-12-01 11:49:16.439622 | TASK [bindep : Include install tasks] 2025-12-01 11:49:16.486795 | controller | ok 2025-12-01 11:49:16.503071 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-01 11:49:16.518067 | 2025-12-01 11:49:16.518150 | TASK [bindep : Create temp dir for bindep] 2025-12-01 11:49:16.922899 | controller | changed 2025-12-01 11:49:16.935431 | 2025-12-01 11:49:16.935579 | TASK [Ensure we have pip dependencies] 2025-12-01 11:49:16.964958 | controller | ok 2025-12-01 11:49:17.008193 | 2025-12-01 11:49:17.008333 | TASK [ensure-pip : Check if pip is installed] 2025-12-01 06:49:17.313356 | controller | /usr/bin/pip3 2025-12-01 06:49:17.346957 | controller | /usr/bin/python3: No module named wheel 2025-12-01 11:49:17.540911 | controller | ok: Runtime: 0:00:00.048942 2025-12-01 11:49:17.553434 | 2025-12-01 11:49:17.553633 | LOOP [ensure-pip : Install pip from packages] 2025-12-01 11:49:17.606497 | controller | ok: "/var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-01 11:49:17.629865 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-01 11:49:17.647782 | 2025-12-01 11:49:17.647914 | TASK [ensure-pip : Install Python 3 pip] 2025-12-01 11:49:19.345467 | controller | changed 2025-12-01 11:49:19.357600 | 2025-12-01 11:49:19.357769 | TASK [ensure-pip : Check for EPEL repository] 2025-12-01 11:49:19.425074 | controller | skipping: Conditional result was False 2025-12-01 11:49:19.439209 | 2025-12-01 11:49:19.439372 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-01 11:49:19.487866 | controller | skipping: Conditional result was False 2025-12-01 11:49:19.502101 | 2025-12-01 11:49:19.502252 | TASK [ensure-pip : Install Python 2 pip] 2025-12-01 11:49:19.549829 | controller | skipping: Conditional result was False 2025-12-01 11:49:19.563006 | 2025-12-01 11:49:19.563151 | TASK [ensure-pip : Ensure setuptools] 2025-12-01 11:49:19.589977 | controller | skipping: Conditional result was False 2025-12-01 11:49:19.604347 | 2025-12-01 11:49:19.604495 | TASK [ensure-pip : Check for ensurepip module] 2025-12-01 11:49:20.154120 | controller | skipping: Conditional result was False 2025-12-01 11:49:20.166488 | 2025-12-01 11:49:20.166639 | TASK [ensure-pip : Ensure python3-venv] 2025-12-01 11:49:20.193174 | controller | skipping: Conditional result was False 2025-12-01 11:49:20.213788 | 2025-12-01 11:49:20.214023 | TASK [ensure-pip : Install pip from source] 2025-12-01 11:49:20.241833 | controller | skipping: Conditional result was False 2025-12-01 11:49:20.254621 | 2025-12-01 11:49:20.254833 | TASK [ensure-pip : Probe for venv python full path] 2025-12-01 06:49:20.546746 | controller | /usr/bin/python3 2025-12-01 11:49:20.811131 | controller | ok: Runtime: 0:00:00.006776 2025-12-01 11:49:20.827776 | 2025-12-01 11:49:20.827981 | TASK [ensure-pip : Set host default] 2025-12-01 11:49:20.888710 | controller | ok 2025-12-01 11:49:20.900681 | 2025-12-01 11:49:20.900893 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-01 11:49:20.964275 | controller | ok 2025-12-01 11:49:20.985714 | 2025-12-01 11:49:20.985914 | TASK [bindep : Install bindep into temporary venv] 2025-12-01 11:49:25.302419 | controller | changed 2025-12-01 11:49:25.324245 | 2025-12-01 11:49:25.324429 | TASK [bindep : Define bindep_command] 2025-12-01 11:49:25.371832 | controller | ok 2025-12-01 11:49:25.378711 | 2025-12-01 11:49:25.378824 | LOOP [bindep : Include package tasks] 2025-12-01 11:49:25.449355 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-01 11:49:25.449598 | controller | ok: All items complete 2025-12-01 11:49:25.449626 | 2025-12-01 11:49:25.470881 | controller | included: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-01 11:49:25.495836 | 2025-12-01 11:49:25.495962 | TASK [bindep : Define bindep_run fact] 2025-12-01 11:49:25.538715 | controller | ok 2025-12-01 11:49:25.546070 | 2025-12-01 11:49:25.546160 | TASK [bindep : Get list of packages to install from bindep] 2025-12-01 06:49:27.385118 | controller | podman 2025-12-01 06:49:27.432673 | controller | python3-jmespath 2025-12-01 06:49:27.432886 | controller | python3-libvirt 2025-12-01 06:49:27.432897 | controller | python3-lxml 2025-12-01 06:49:27.432907 | controller | python3-netaddr 2025-12-01 11:49:27.596949 | controller | ok: Runtime: 0:00:01.597282 2025-12-01 11:49:27.609128 | 2025-12-01 11:49:27.609339 | TASK [bindep : Install distro packages from bindep] 2025-12-01 11:50:29.003915 | controller | changed 2025-12-01 11:50:29.016317 | 2025-12-01 11:50:29.016520 | TASK [bindep : Check that packages are installed] 2025-12-01 11:50:30.569074 | controller | ok: Runtime: 0:00:01.185490 2025-12-01 11:50:30.581570 | 2025-12-01 11:50:30.581796 | TASK [bindep : Fail if we cannot install all packages] 2025-12-01 11:50:30.619810 | controller | skipping: Conditional result was False 2025-12-01 11:50:30.642154 | 2025-12-01 11:50:30.642331 | TASK [Run test-setup role] 2025-12-01 11:50:30.673331 | controller | ok 2025-12-01 11:50:30.734098 | 2025-12-01 11:50:30.734221 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-01 11:50:31.011396 | controller | ok 2025-12-01 11:50:31.019279 | 2025-12-01 11:50:31.019400 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-01 11:50:31.556194 | controller | skipping: Conditional result was False 2025-12-01 11:50:31.599978 | 2025-12-01 11:50:31.600200 | TASK [bindep : Remove bindep temp dir] 2025-12-01 11:50:31.968042 | controller | ok 2025-12-01 11:50:31.989759 | 2025-12-01 11:50:31.989991 | PLAY RECAP 2025-12-01 11:50:31.990103 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-01 11:50:31.990154 | 2025-12-01 11:50:32.103116 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 11:50:32.104246 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-01 11:50:32.724920 | 2025-12-01 11:50:32.725037 | PLAY [all] 2025-12-01 11:50:32.744744 | 2025-12-01 11:50:32.744866 | TASK [Abort when test_command variable is undefined] 2025-12-01 11:50:32.769709 | controller | skipping: Conditional result was False 2025-12-01 11:50:32.775637 | 2025-12-01 11:50:32.775716 | TASK [Convert test_command to list] 2025-12-01 11:50:32.819991 | controller | skipping: Conditional result was False 2025-12-01 11:50:32.826382 | 2025-12-01 11:50:32.826458 | TASK [Use test_command list] 2025-12-01 11:50:32.891609 | controller | ok 2025-12-01 11:50:32.903679 | 2025-12-01 11:50:32.903899 | LOOP [Run test_command] 2025-12-01 11:50:33.310396 | controller | no check to run 2025-12-01 11:50:33.310599 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006947 2025-12-01 11:50:33.363194 | 2025-12-01 11:50:33.363345 | PLAY RECAP 2025-12-01 11:50:33.363426 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-01 11:50:33.363470 | 2025-12-01 11:50:33.476167 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-01 11:50:33.477869 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 11:50:34.093256 | 2025-12-01 11:50:34.093412 | PLAY [all] 2025-12-01 11:50:34.116487 | 2025-12-01 11:50:34.116616 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-01 11:50:34.532041 | controller | changed: non-zero return code 2025-12-01 11:50:34.545070 | 2025-12-01 11:50:34.545287 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-01 11:50:34.563082 | controller | skipping: Conditional result was False 2025-12-01 11:50:34.576983 | 2025-12-01 11:50:34.577160 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-01 11:50:34.608400 | 2025-12-01 11:50:34.608701 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-01 11:50:34.639513 | 2025-12-01 11:50:34.639847 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-01 11:50:34.656896 | controller | skipping: Conditional result was False 2025-12-01 11:50:34.671194 | 2025-12-01 11:50:34.671342 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-01 11:50:34.697666 | 2025-12-01 11:50:34.697890 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-01 11:50:34.713030 | controller | skipping: Conditional result was False 2025-12-01 11:50:34.721107 | 2025-12-01 11:50:34.721206 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-01 11:50:34.735879 | controller | skipping: Conditional result was False 2025-12-01 11:50:34.743952 | 2025-12-01 11:50:34.744052 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-01 11:50:34.769178 | controller | skipping: Conditional result was False 2025-12-01 11:50:34.804435 | 2025-12-01 11:50:34.804562 | PLAY RECAP 2025-12-01 11:50:34.804623 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-01 11:50:34.804650 | 2025-12-01 11:50:34.904172 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 11:50:34.905871 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-01 11:50:35.524716 | 2025-12-01 11:50:35.524840 | PLAY [all] 2025-12-01 11:50:35.544186 | 2025-12-01 11:50:35.544282 | TASK [include_role : fetch-output] 2025-12-01 11:50:35.593376 | controller | ok 2025-12-01 11:50:35.610583 | 2025-12-01 11:50:35.610684 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-01 11:50:35.686078 | controller | skipping: Conditional result was False 2025-12-01 11:50:35.698611 | 2025-12-01 11:50:35.698804 | TASK [fetch-output : Set log path for single node] 2025-12-01 11:50:35.738087 | controller | ok 2025-12-01 11:50:35.751057 | 2025-12-01 11:50:35.751246 | LOOP [fetch-output : Ensure local output dirs] 2025-12-01 11:50:36.179957 | controller -> localhost | ok: "/var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/logs" 2025-12-01 11:50:36.399528 | controller -> localhost | changed: "/var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/artifacts" 2025-12-01 11:50:36.633490 | controller -> localhost | changed: "/var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/docs" 2025-12-01 11:50:36.645499 | 2025-12-01 11:50:36.645636 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-01 11:50:37.370476 | controller | changed: .d..t...... ./ 2025-12-01 11:50:37.370928 | controller | changed: All items complete 2025-12-01 11:50:37.370995 | 2025-12-01 11:50:37.871337 | controller | changed: .d..t...... ./ 2025-12-01 11:50:38.358925 | controller | changed: .d..t...... ./ 2025-12-01 11:50:38.387926 | 2025-12-01 11:50:38.388087 | TASK [include_role : fetch-output-openshift] 2025-12-01 11:50:38.415441 | controller | skipping: Conditional result was False 2025-12-01 11:50:38.430567 | 2025-12-01 11:50:38.430776 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-01 11:50:38.879656 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012453 2025-12-01 11:50:39.147112 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013015 2025-12-01 11:50:39.187191 | 2025-12-01 11:50:39.187335 | PLAY [all] 2025-12-01 11:50:39.201443 | 2025-12-01 11:50:39.201528 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-01 11:50:39.659336 | controller | changed 2025-12-01 11:50:39.681242 | 2025-12-01 11:50:39.681320 | PLAY RECAP 2025-12-01 11:50:39.681359 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-01 11:50:39.681379 | 2025-12-01 11:50:39.787931 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-01 11:50:39.789064 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-01 11:50:40.416788 | 2025-12-01 11:50:40.416892 | PLAY [localhost] 2025-12-01 11:50:40.434609 | 2025-12-01 11:50:40.434696 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-01 11:50:40.824068 | localhost | changed 2025-12-01 11:50:40.834163 | 2025-12-01 11:50:40.834323 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-01 11:50:40.870401 | localhost | ok 2025-12-01 11:50:40.888210 | 2025-12-01 11:50:40.888350 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-01 11:50:41.320626 | localhost | changed 2025-12-01 11:50:41.332289 | 2025-12-01 11:50:41.332426 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-01 11:50:42.106495 | localhost | changed 2025-12-01 11:50:42.114001 | 2025-12-01 11:50:42.114100 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-01 11:50:42.601501 | localhost | Identity added: /var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/tmp/ansible.13mogwf0 (/var/lib/zuul/builds/67e68b7e80ab4c71bc60afd86099a155/work/tmp/ansible.13mogwf0) 2025-12-01 11:50:42.601675 | localhost | ok: Runtime: 0:00:00.012514 2025-12-01 11:50:42.605941 | 2025-12-01 11:50:42.606007 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-01 11:50:42.887830 | localhost | ok: Runtime: 0:00:00.008562 2025-12-01 11:50:42.892600 | 2025-12-01 11:50:42.892663 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-01 11:50:42.942049 | localhost | changed 2025-12-01 11:50:42.946801 | 2025-12-01 11:50:42.946871 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-01 11:50:43.437316 | localhost | changed 2025-12-01 11:50:43.480837 | 2025-12-01 11:50:43.480971 | PLAY [localhost] 2025-12-01 11:50:43.500530 | 2025-12-01 11:50:43.500664 | TASK [Generate bulk log download script] 2025-12-01 11:50:43.533107 | localhost | ok 2025-12-01 11:50:43.551626 | 2025-12-01 11:50:43.551786 | TASK [local-log-download : Check API endpoint is defined] 2025-12-01 11:50:43.585429 | localhost | ok: All assertions passed 2025-12-01 11:50:43.591459 | 2025-12-01 11:50:43.591571 | TASK [local-log-download : Create download script] 2025-12-01 11:50:44.056722 | localhost -> localhost | changed 2025-12-01 11:50:44.071548 | 2025-12-01 11:50:44.071683 | TASK [Register quick-download link] 2025-12-01 11:50:44.094522 | localhost | ok 2025-12-01 11:50:44.138702 | 2025-12-01 11:50:44.138858 | PLAY [logserver.rdoproject.org] 2025-12-01 11:50:44.149537 | 2025-12-01 11:50:44.149642 | TASK [Set zuul-log-path fact] 2025-12-01 11:50:44.165964 | logserver.rdoproject.org | ok 2025-12-01 11:50:44.174663 | 2025-12-01 11:50:44.174732 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 11:50:44.211551 | logserver.rdoproject.org | ok 2025-12-01 11:50:44.216850 | 2025-12-01 11:50:44.216913 | TASK [upload-logs : Create log directories] 2025-12-01 11:50:45.138587 | logserver.rdoproject.org | changed 2025-12-01 11:50:45.141682 | 2025-12-01 11:50:45.141747 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-01 11:50:45.478823 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008402 2025-12-01 11:50:45.488508 | 2025-12-01 11:50:45.488638 | TASK [upload-logs : Upload logs to log server] 2025-12-01 11:50:46.253717 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-01 11:50:46.260719 | 2025-12-01 11:50:46.260887 | LOOP [upload-logs : Compress console log and json output] 2025-12-01 11:50:46.334873 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 11:50:46.347072 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 11:50:46.357430 | 2025-12-01 11:50:46.357627 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-01 11:50:46.405703 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 11:50:46.406300 | 2025-12-01 11:50:46.408807 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 11:50:46.425351 | 2025-12-01 11:50:46.425497 | LOOP [upload-logs : Upload console log and json output]