2025-10-08 15:40:03.178809 | Job console starting... 2025-10-08 15:40:03.216265 | Updating repositories 2025-10-08 15:40:03.241863 | Preparing job workspace 2025-10-08 15:40:07.494457 | Running Ansible setup... 2025-10-08 15:40:11.244870 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 15:40:11.840141 | 2025-10-08 15:40:11.840259 | PLAY [localhost] 2025-10-08 15:40:11.848767 | 2025-10-08 15:40:11.848840 | TASK [Gathering Facts] 2025-10-08 15:40:12.785074 | localhost | ok 2025-10-08 15:40:12.815092 | 2025-10-08 15:40:12.815295 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 15:40:13.223270 | localhost -> localhost | changed 2025-10-08 15:40:13.228915 | 2025-10-08 15:40:13.228985 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 15:40:14.119835 | localhost -> localhost | changed 2025-10-08 15:40:14.142135 | 2025-10-08 15:40:14.142279 | TASK [Setup log path fact] 2025-10-08 15:40:14.169878 | localhost | ok 2025-10-08 15:40:14.194387 | 2025-10-08 15:40:14.194483 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 15:40:14.240142 | localhost | ok 2025-10-08 15:40:14.256064 | 2025-10-08 15:40:14.256151 | TASK [emit-job-header : Print job information] 2025-10-08 15:40:14.307485 | # Job Information 2025-10-08 15:40:14.307701 | Ansible Version: 2.15.12 2025-10-08 15:40:14.307742 | Job: cifmw-molecule-krb_request 2025-10-08 15:40:14.307770 | Pipeline: github-check 2025-10-08 15:40:14.307795 | Executor: ze02.softwarefactory-project.io 2025-10-08 15:40:14.307819 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368 2025-10-08 15:40:14.307845 | Log URL (when completed): https://logserver.rdoproject.org/7e1/rdoproject.org/7e1cc41e8aa84da69a1665a6567d771f/ 2025-10-08 15:40:14.307870 | Event ID: b612d780-a45c-11f0-87cb-9ea07ef2b05c 2025-10-08 15:40:14.313790 | 2025-10-08 15:40:14.313876 | LOOP [emit-job-header : Print node information] 2025-10-08 15:40:14.438829 | localhost | ok: 2025-10-08 15:40:14.439025 | localhost | # Node Information 2025-10-08 15:40:14.439052 | localhost | Inventory Hostname: controller 2025-10-08 15:40:14.439074 | localhost | Hostname: np0005477188 2025-10-08 15:40:14.439094 | localhost | Username: zuul 2025-10-08 15:40:14.439114 | localhost | Distro: CentOS 9 2025-10-08 15:40:14.439132 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 15:40:14.439148 | localhost | Region: RegionOne 2025-10-08 15:40:14.439165 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 15:40:14.439182 | localhost | Product Name: OpenStack Nova 2025-10-08 15:40:14.439198 | localhost | Interface IP: 38.129.56.211 2025-10-08 15:40:14.461869 | 2025-10-08 15:40:14.461954 | PLAY [all] 2025-10-08 15:40:14.468377 | 2025-10-08 15:40:14.468441 | TASK [Gather network facts] 2025-10-08 15:40:14.957141 | controller | ok 2025-10-08 15:40:14.987755 | 2025-10-08 15:40:14.988080 | TASK [include_role : start-zuul-console] 2025-10-08 15:40:15.013831 | controller | ok 2025-10-08 15:40:15.029868 | 2025-10-08 15:40:15.029958 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 15:40:15.428606 | controller | ok 2025-10-08 15:40:15.444252 | 2025-10-08 15:40:15.444396 | TASK [include_role : add-build-sshkey] 2025-10-08 15:40:15.491139 | controller | ok 2025-10-08 15:40:15.516161 | 2025-10-08 15:40:15.516401 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 15:40:15.860023 | controller -> localhost | ok 2025-10-08 15:40:15.866094 | 2025-10-08 15:40:15.866157 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 15:40:15.895922 | controller | ok 2025-10-08 15:40:15.908520 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 15:40:15.914125 | 2025-10-08 15:40:15.914185 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 15:40:16.343685 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 15:40:16.343919 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/7e1cc41e8aa84da69a1665a6567d771f_id_rsa. 2025-10-08 15:40:16.343951 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/7e1cc41e8aa84da69a1665a6567d771f_id_rsa.pub. 2025-10-08 15:40:16.343973 | controller -> localhost | The key fingerprint is: 2025-10-08 15:40:16.343992 | controller -> localhost | SHA256:8R2jzNikyv0HwCuRKj7rRm9mk1NPUC9m1jF8lT0EbF4 zuul-build-sshkey 2025-10-08 15:40:16.344011 | controller -> localhost | The key's randomart image is: 2025-10-08 15:40:16.344029 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 15:40:16.344047 | controller -> localhost | | . .o++ | 2025-10-08 15:40:16.344065 | controller -> localhost | | . + .o.E.| 2025-10-08 15:40:16.344083 | controller -> localhost | | +.o.+= . .| 2025-10-08 15:40:16.344100 | controller -> localhost | | + BXoo + | 2025-10-08 15:40:16.344117 | controller -> localhost | | . *S+* . | 2025-10-08 15:40:16.344134 | controller -> localhost | | o ..ooo . | 2025-10-08 15:40:16.344150 | controller -> localhost | | o o oo+. . | 2025-10-08 15:40:16.344167 | controller -> localhost | | + O .. . | 2025-10-08 15:40:16.344184 | controller -> localhost | | oo* o .. | 2025-10-08 15:40:16.344201 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 15:40:16.344249 | controller -> localhost | ok: Runtime: 0:00:00.041946 2025-10-08 15:40:16.350081 | 2025-10-08 15:40:16.350140 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 15:40:16.379031 | controller | ok 2025-10-08 15:40:16.388746 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 15:40:16.396599 | 2025-10-08 15:40:16.396656 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 15:40:16.420563 | controller | skipping: Conditional result was False 2025-10-08 15:40:16.426008 | 2025-10-08 15:40:16.426070 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 15:40:16.893221 | controller | changed 2025-10-08 15:40:16.899060 | 2025-10-08 15:40:16.899123 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 15:40:17.183759 | controller | ok 2025-10-08 15:40:17.198441 | 2025-10-08 15:40:17.198638 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 15:40:18.153988 | controller | changed 2025-10-08 15:40:18.162585 | 2025-10-08 15:40:18.162656 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 15:40:19.141190 | controller | changed 2025-10-08 15:40:19.146264 | 2025-10-08 15:40:19.146353 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 15:40:19.162101 | controller | skipping: Conditional result was False 2025-10-08 15:40:19.168078 | 2025-10-08 15:40:19.168143 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 15:40:19.557652 | controller -> localhost | changed 2025-10-08 15:40:19.573498 | 2025-10-08 15:40:19.573636 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 15:40:19.851328 | controller -> localhost | Identity added: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/7e1cc41e8aa84da69a1665a6567d771f_id_rsa (zuul-build-sshkey) 2025-10-08 15:40:19.851511 | controller -> localhost | ok: Runtime: 0:00:00.008525 2025-10-08 15:40:19.858624 | 2025-10-08 15:40:19.858780 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 15:40:20.203548 | controller | ok 2025-10-08 15:40:20.208226 | 2025-10-08 15:40:20.208287 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 15:40:20.234328 | controller | skipping: Conditional result was False 2025-10-08 15:40:20.246172 | 2025-10-08 15:40:20.246239 | TASK [include_role : validate-host] 2025-10-08 15:40:20.266009 | controller | ok 2025-10-08 15:40:20.286073 | 2025-10-08 15:40:20.286138 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 15:40:20.315595 | controller | ok 2025-10-08 15:40:20.320299 | 2025-10-08 15:40:20.320359 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 15:40:20.557694 | controller -> localhost | ok 2025-10-08 15:40:20.563504 | 2025-10-08 15:40:20.563564 | TASK [validate-host : Collect information about the host] 2025-10-08 15:40:21.374304 | controller | ok 2025-10-08 15:40:21.394912 | 2025-10-08 15:40:21.395201 | TASK [validate-host : Sanitize hostname] 2025-10-08 15:40:21.461708 | controller | ok 2025-10-08 15:40:21.470856 | 2025-10-08 15:40:21.470964 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 15:40:21.920621 | controller -> localhost | changed 2025-10-08 15:40:21.926572 | 2025-10-08 15:40:21.926638 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 15:40:22.410136 | controller | ok 2025-10-08 15:40:22.415964 | 2025-10-08 15:40:22.416029 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 15:40:22.836840 | controller -> localhost | changed 2025-10-08 15:40:22.851206 | 2025-10-08 15:40:22.851332 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 15:40:22.873685 | controller | skipping: Conditional result was False 2025-10-08 15:40:22.879350 | 2025-10-08 15:40:22.879414 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 15:40:22.893293 | controller | skipping: Conditional result was False 2025-10-08 15:40:22.898465 | 2025-10-08 15:40:22.898527 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 15:40:23.173996 | controller | ok: "logs" 2025-10-08 15:40:23.174295 | controller | ok: All items complete 2025-10-08 15:40:23.174324 | 2025-10-08 15:40:24.824375 | controller | ok: "artifacts" 2025-10-08 15:40:25.320959 | controller | ok: "docs" 2025-10-08 15:40:25.336520 | 2025-10-08 15:40:25.336746 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 15:40:25.608307 | controller | changed: "logs" 2025-10-08 15:40:25.866278 | controller | changed: "artifacts" 2025-10-08 15:40:26.120609 | controller | changed: "docs" 2025-10-08 15:40:26.161173 | 2025-10-08 15:40:26.161288 | PLAY RECAP 2025-10-08 15:40:26.161334 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 15:40:26.161360 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 15:40:26.161378 | 2025-10-08 15:40:26.320649 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 15:40:26.321578 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 15:40:26.934157 | 2025-10-08 15:40:26.934308 | PLAY [localhost] 2025-10-08 15:40:26.950495 | 2025-10-08 15:40:26.950575 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 15:40:27.389962 | localhost | ok 2025-10-08 15:40:27.401318 | 2025-10-08 15:40:27.401491 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 15:40:28.129295 | localhost | changed 2025-10-08 15:40:28.149945 | 2025-10-08 15:40:28.150001 | PLAY [all] 2025-10-08 15:40:28.165515 | 2025-10-08 15:40:28.165576 | TASK [include_role : prepare-workspace] 2025-10-08 15:40:28.197429 | controller | ok 2025-10-08 15:40:28.216504 | 2025-10-08 15:40:28.216566 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 15:40:28.699241 | controller | ok 2025-10-08 15:40:28.713582 | 2025-10-08 15:40:28.713753 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 15:40:30.792258 | controller | Output suppressed because no_log was given 2025-10-08 15:40:30.813189 | 2025-10-08 15:40:30.813324 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 15:40:31.207148 | controller | changed: "logs" 2025-10-08 15:40:31.493477 | controller | changed: "artifacts" 2025-10-08 15:40:31.746088 | controller | changed: "docs" 2025-10-08 15:40:31.764481 | 2025-10-08 15:40:31.764719 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 15:40:32.084856 | controller | changed: "logs" 2025-10-08 15:40:32.085236 | controller | changed: All items complete 2025-10-08 15:40:32.085293 | 2025-10-08 15:40:32.318132 | controller | changed: "artifacts" 2025-10-08 15:40:32.612623 | controller | changed: "docs" 2025-10-08 15:40:32.641516 | 2025-10-08 15:40:32.641658 | TASK [Check if worker can sudo] 2025-10-08 15:40:33.215445 | controller | ok: Runtime: 0:00:00.067168 2025-10-08 15:40:33.223059 | 2025-10-08 15:40:33.223145 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 15:40:33.298417 | controller | skipping: Conditional result was False 2025-10-08 15:40:33.306822 | 2025-10-08 15:40:33.306914 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 15:40:33.371410 | controller | ok 2025-10-08 15:40:33.383383 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 15:40:33.422657 | 2025-10-08 15:40:33.422789 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 15:40:33.716329 | controller | ok 2025-10-08 15:40:33.724466 | 2025-10-08 15:40:33.724551 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 15:40:33.780351 | controller | ok: "/var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 15:40:33.789959 | 2025-10-08 15:40:33.790048 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 15:40:34.667431 | controller | changed 2025-10-08 15:40:34.673005 | 2025-10-08 15:40:34.673066 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 15:40:34.726225 | controller | ok: "/var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 15:40:34.726432 | controller | ok: All items complete 2025-10-08 15:40:34.726459 | 2025-10-08 15:40:34.796091 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 15:40:34.818269 | 2025-10-08 15:40:34.818367 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 15:40:36.234287 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 15:40:37.194068 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 15:40:37.212381 | 2025-10-08 15:40:37.212518 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 15:40:37.716261 | controller | changed: section and option added 2025-10-08 15:40:37.744740 | 2025-10-08 15:40:37.744840 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 15:40:38.926098 | controller | 29 files removed 2025-10-08 15:40:38.926852 | controller | ok: Item: dnf clean all Runtime: 0:00:00.747031 2025-10-08 15:40:38.926968 | controller | changed: All items complete 2025-10-08 15:40:38.927021 | 2025-10-08 15:40:52.884330 | 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-08 15:40:52.884519 | controller | DNF version: 4.14.0 2025-10-08 15:40:52.884545 | controller | cachedir: /var/cache/dnf 2025-10-08 15:40:52.884565 | controller | Making cache files for all metadata files. 2025-10-08 15:40:52.884583 | controller | baseos: has expired and will be refreshed. 2025-10-08 15:40:52.884601 | controller | appstream: has expired and will be refreshed. 2025-10-08 15:40:52.884617 | controller | crb: has expired and will be refreshed. 2025-10-08 15:40:52.884645 | controller | extras-common: has expired and will be refreshed. 2025-10-08 15:40:52.884676 | controller | repo: downloading from remote: baseos 2025-10-08 15:40:52.884699 | controller | CentOS Stream 9 - BaseOS 30 MB/s | 8.8 MB 00:00 2025-10-08 15:40:52.884717 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 15:40:52.884734 | controller | repo: downloading from remote: appstream 2025-10-08 15:40:52.884750 | controller | CentOS Stream 9 - AppStream 13 MB/s | 25 MB 00:01 2025-10-08 15:40:52.884766 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 15:40:52.884783 | controller | repo: downloading from remote: crb 2025-10-08 15:40:52.884799 | controller | CentOS Stream 9 - CRB 16 MB/s | 7.1 MB 00:00 2025-10-08 15:40:52.884816 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 15:40:52.884832 | controller | repo: downloading from remote: extras-common 2025-10-08 15:40:52.884849 | controller | CentOS Stream 9 - Extras packages 382 kB/s | 20 kB 00:00 2025-10-08 15:40:52.884866 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 15:40:52.884882 | controller | Last metadata expiration check: 0:00:01 ago on Wed 08 Oct 2025 11:40:50 AM EDT. 2025-10-08 15:40:52.884897 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 15:40:52.884913 | controller | Completion plugin: Generating completion cache... 2025-10-08 15:40:52.884930 | controller | Metadata cache created. 2025-10-08 15:40:52.884956 | controller | ok: Item: dnf makecache -v Runtime: 0:00:13.691285 2025-10-08 15:40:52.923082 | 2025-10-08 15:40:52.923204 | PLAY RECAP 2025-10-08 15:40:52.923278 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 15:40:52.923326 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 15:40:52.923360 | 2025-10-08 15:40:53.023008 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 15:40:53.023860 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 15:40:53.624306 | 2025-10-08 15:40:53.624429 | PLAY [all] 2025-10-08 15:40:53.646068 | 2025-10-08 15:40:53.646170 | TASK [Install binary dependencies] 2025-10-08 15:40:53.719619 | controller | ok 2025-10-08 15:40:53.748019 | 2025-10-08 15:40:53.748176 | TASK [bindep : Include find tasks] 2025-10-08 15:40:53.781893 | controller | ok 2025-10-08 15:40:53.794532 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 15:40:53.804039 | 2025-10-08 15:40:53.804174 | TASK [bindep : Look for bindep.txt] 2025-10-08 15:40:54.525295 | controller | ok 2025-10-08 15:40:54.538432 | 2025-10-08 15:40:54.538577 | TASK [bindep : Define bindep_file fact] 2025-10-08 15:40:54.577217 | controller | ok 2025-10-08 15:40:54.588637 | 2025-10-08 15:40:54.588803 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 15:40:54.606384 | controller | skipping: Conditional result was False 2025-10-08 15:40:54.619032 | 2025-10-08 15:40:54.619172 | TASK [bindep : Define bindep_file fact] 2025-10-08 15:40:54.646814 | controller | skipping: Conditional result was False 2025-10-08 15:40:54.659266 | 2025-10-08 15:40:54.659404 | TASK [bindep : Look for bindep fallback file] 2025-10-08 15:40:54.701233 | controller | skipping: Conditional result was False 2025-10-08 15:40:54.713748 | 2025-10-08 15:40:54.713890 | TASK [bindep : Define bindep_file fact] 2025-10-08 15:40:54.741403 | controller | skipping: Conditional result was False 2025-10-08 15:40:54.755913 | 2025-10-08 15:40:54.756049 | TASK [bindep : Include bindep tasks] 2025-10-08 15:40:54.793777 | controller | ok 2025-10-08 15:40:54.806844 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 15:40:54.817790 | 2025-10-08 15:40:54.817873 | TASK [bindep : Look for bindep command] 2025-10-08 15:40:54.843181 | controller | skipping: Conditional result was False 2025-10-08 15:40:54.851504 | 2025-10-08 15:40:54.851586 | TASK [bindep : Check for system bindep] 2025-10-08 15:40:55.395163 | controller | ok: Runtime: 0:00:00.005782 2025-10-08 15:40:55.402879 | 2025-10-08 15:40:55.402964 | TASK [bindep : Define bindep_command fact] 2025-10-08 15:40:55.428193 | controller | skipping: Conditional result was False 2025-10-08 15:40:55.436074 | 2025-10-08 15:40:55.436164 | TASK [bindep : Include install tasks] 2025-10-08 15:40:55.468157 | controller | ok 2025-10-08 15:40:55.478777 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 15:40:55.491192 | 2025-10-08 15:40:55.491284 | TASK [bindep : Create temp dir for bindep] 2025-10-08 15:40:55.865340 | controller | changed 2025-10-08 15:40:55.890227 | 2025-10-08 15:40:55.890387 | TASK [Ensure we have pip dependencies] 2025-10-08 15:40:55.919804 | controller | ok 2025-10-08 15:40:55.953717 | 2025-10-08 15:40:55.953833 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 11:40:56.379316 | controller | /usr/bin/pip3 2025-10-08 11:40:56.406335 | controller | /usr/bin/python3: No module named wheel 2025-10-08 15:40:56.487638 | controller | ok: Runtime: 0:00:00.064959 2025-10-08 15:40:56.503766 | 2025-10-08 15:40:56.503916 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 15:40:56.552878 | controller | ok: "/var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 15:40:56.567963 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 15:40:56.577647 | 2025-10-08 15:40:56.577726 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 15:41:00.717233 | controller | changed 2025-10-08 15:41:00.730584 | 2025-10-08 15:41:00.730869 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 15:41:00.808917 | controller | skipping: Conditional result was False 2025-10-08 15:41:00.822677 | 2025-10-08 15:41:00.822772 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 15:41:00.865131 | controller | skipping: Conditional result was False 2025-10-08 15:41:00.872096 | 2025-10-08 15:41:00.872173 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 15:41:00.906794 | controller | skipping: Conditional result was False 2025-10-08 15:41:00.913146 | 2025-10-08 15:41:00.913212 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 15:41:00.937872 | controller | skipping: Conditional result was False 2025-10-08 15:41:00.944715 | 2025-10-08 15:41:00.944782 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 15:41:01.477862 | controller | skipping: Conditional result was False 2025-10-08 15:41:01.484997 | 2025-10-08 15:41:01.485065 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 15:41:01.510013 | controller | skipping: Conditional result was False 2025-10-08 15:41:01.522290 | 2025-10-08 15:41:01.522396 | TASK [ensure-pip : Install pip from source] 2025-10-08 15:41:01.543779 | controller | skipping: Conditional result was False 2025-10-08 15:41:01.550539 | 2025-10-08 15:41:01.550604 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 11:41:01.855203 | controller | /usr/bin/python3 2025-10-08 15:41:02.096216 | controller | ok: Runtime: 0:00:00.006431 2025-10-08 15:41:02.108243 | 2025-10-08 15:41:02.108392 | TASK [ensure-pip : Set host default] 2025-10-08 15:41:02.157975 | controller | ok 2025-10-08 15:41:02.163237 | 2025-10-08 15:41:02.163301 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 15:41:02.206029 | controller | ok 2025-10-08 15:41:02.216926 | 2025-10-08 15:41:02.217161 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 15:41:07.443458 | controller | changed 2025-10-08 15:41:07.456811 | 2025-10-08 15:41:07.456946 | TASK [bindep : Define bindep_command] 2025-10-08 15:41:07.491712 | controller | ok 2025-10-08 15:41:07.500983 | 2025-10-08 15:41:07.501070 | LOOP [bindep : Include package tasks] 2025-10-08 15:41:07.543016 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 15:41:07.543229 | controller | ok: All items complete 2025-10-08 15:41:07.543256 | 2025-10-08 15:41:07.553119 | controller | included: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 15:41:07.567914 | 2025-10-08 15:41:07.567988 | TASK [bindep : Define bindep_run fact] 2025-10-08 15:41:07.596818 | controller | ok 2025-10-08 15:41:07.602566 | 2025-10-08 15:41:07.602629 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 11:41:09.149316 | controller | podman 2025-10-08 11:41:09.200263 | controller | python3-jmespath 2025-10-08 11:41:09.200427 | controller | python3-libvirt 2025-10-08 11:41:09.200441 | controller | python3-lxml 2025-10-08 11:41:09.200450 | controller | python3-netaddr 2025-10-08 15:41:09.636149 | controller | ok: Runtime: 0:00:01.310337 2025-10-08 15:41:09.650203 | 2025-10-08 15:41:09.650363 | TASK [bindep : Install distro packages from bindep] 2025-10-08 15:42:20.904453 | controller | changed 2025-10-08 15:42:20.914352 | 2025-10-08 15:42:20.914483 | TASK [bindep : Check that packages are installed] 2025-10-08 15:42:22.470868 | controller | ok: Runtime: 0:00:01.203458 2025-10-08 15:42:22.483405 | 2025-10-08 15:42:22.483536 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 15:42:22.520510 | controller | skipping: Conditional result was False 2025-10-08 15:42:22.542882 | 2025-10-08 15:42:22.543011 | TASK [Run test-setup role] 2025-10-08 15:42:22.570413 | controller | ok 2025-10-08 15:42:22.600783 | 2025-10-08 15:42:22.600871 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 15:42:22.836172 | controller | ok 2025-10-08 15:42:22.842596 | 2025-10-08 15:42:22.842680 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 15:42:23.371361 | controller | skipping: Conditional result was False 2025-10-08 15:42:23.422036 | 2025-10-08 15:42:23.422247 | TASK [bindep : Remove bindep temp dir] 2025-10-08 15:42:23.856201 | controller | ok 2025-10-08 15:42:23.884796 | 2025-10-08 15:42:23.884898 | PLAY RECAP 2025-10-08 15:42:23.884952 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 15:42:23.884980 | 2025-10-08 15:42:24.036840 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 15:42:24.038512 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 15:42:24.598191 | 2025-10-08 15:42:24.598310 | PLAY [all] 2025-10-08 15:42:24.617225 | 2025-10-08 15:42:24.617328 | TASK [Abort when test_command variable is undefined] 2025-10-08 15:42:24.642236 | controller | skipping: Conditional result was False 2025-10-08 15:42:24.649498 | 2025-10-08 15:42:24.649619 | TASK [Convert test_command to list] 2025-10-08 15:42:24.684712 | controller | skipping: Conditional result was False 2025-10-08 15:42:24.694166 | 2025-10-08 15:42:24.694280 | TASK [Use test_command list] 2025-10-08 15:42:24.759986 | controller | ok 2025-10-08 15:42:24.769132 | 2025-10-08 15:42:24.769219 | LOOP [Run test_command] 2025-10-08 15:42:25.218324 | controller | no check to run 2025-10-08 15:42:25.218710 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.012162 2025-10-08 15:42:25.295170 | 2025-10-08 15:42:25.295326 | PLAY RECAP 2025-10-08 15:42:25.295381 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 15:42:25.295421 | 2025-10-08 15:42:25.406447 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 15:42:25.407357 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 15:42:25.987566 | 2025-10-08 15:42:25.987721 | PLAY [all] 2025-10-08 15:42:26.008518 | 2025-10-08 15:42:26.008641 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 15:42:26.394366 | controller | changed: non-zero return code 2025-10-08 15:42:26.399651 | 2025-10-08 15:42:26.399745 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 15:42:26.414921 | controller | skipping: Conditional result was False 2025-10-08 15:42:26.421529 | 2025-10-08 15:42:26.421660 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 15:42:26.475937 | 2025-10-08 15:42:26.476561 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 15:42:26.512276 | 2025-10-08 15:42:26.512479 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 15:42:26.537992 | controller | skipping: Conditional result was False 2025-10-08 15:42:26.546486 | 2025-10-08 15:42:26.546921 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 15:42:26.581279 | 2025-10-08 15:42:26.581452 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 15:42:26.606162 | controller | skipping: Conditional result was False 2025-10-08 15:42:26.614309 | 2025-10-08 15:42:26.614399 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 15:42:26.639614 | controller | skipping: Conditional result was False 2025-10-08 15:42:26.647594 | 2025-10-08 15:42:26.647719 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 15:42:26.673023 | controller | skipping: Conditional result was False 2025-10-08 15:42:26.708089 | 2025-10-08 15:42:26.708181 | PLAY RECAP 2025-10-08 15:42:26.708336 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 15:42:26.708376 | 2025-10-08 15:42:26.824053 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 15:42:26.825179 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 15:42:27.401989 | 2025-10-08 15:42:27.402102 | PLAY [all] 2025-10-08 15:42:27.420893 | 2025-10-08 15:42:27.420987 | TASK [include_role : fetch-output] 2025-10-08 15:42:27.470358 | controller | ok 2025-10-08 15:42:27.488276 | 2025-10-08 15:42:27.488380 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 15:42:27.533840 | controller | skipping: Conditional result was False 2025-10-08 15:42:27.546765 | 2025-10-08 15:42:27.546908 | TASK [fetch-output : Set log path for single node] 2025-10-08 15:42:27.593984 | controller | ok 2025-10-08 15:42:27.605115 | 2025-10-08 15:42:27.605275 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 15:42:28.069207 | controller -> localhost | ok: "/var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/logs" 2025-10-08 15:42:28.305580 | controller -> localhost | changed: "/var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/artifacts" 2025-10-08 15:42:28.556745 | controller -> localhost | changed: "/var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/docs" 2025-10-08 15:42:28.584234 | 2025-10-08 15:42:28.584418 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 15:42:29.245964 | controller | changed: .d..t...... ./ 2025-10-08 15:42:29.246167 | controller | changed: All items complete 2025-10-08 15:42:29.246208 | 2025-10-08 15:42:29.761512 | controller | changed: .d..t...... ./ 2025-10-08 15:42:30.273716 | controller | changed: .d..t...... ./ 2025-10-08 15:42:30.304166 | 2025-10-08 15:42:30.304309 | TASK [include_role : fetch-output-openshift] 2025-10-08 15:42:30.329039 | controller | skipping: Conditional result was False 2025-10-08 15:42:30.337067 | 2025-10-08 15:42:30.337189 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 15:42:30.748883 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010527 2025-10-08 15:42:30.960790 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007240 2025-10-08 15:42:30.993114 | 2025-10-08 15:42:30.993203 | PLAY [all] 2025-10-08 15:42:31.008438 | 2025-10-08 15:42:31.008534 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 15:42:31.448339 | controller | changed 2025-10-08 15:42:31.472841 | 2025-10-08 15:42:31.472925 | PLAY RECAP 2025-10-08 15:42:31.472964 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 15:42:31.472985 | 2025-10-08 15:42:31.593210 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 15:42:31.594047 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 15:42:32.284174 | 2025-10-08 15:42:32.284336 | PLAY [localhost] 2025-10-08 15:42:32.303216 | 2025-10-08 15:42:32.303322 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 15:42:32.732591 | localhost | changed 2025-10-08 15:42:32.737174 | 2025-10-08 15:42:32.737248 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 15:42:32.765648 | localhost | ok 2025-10-08 15:42:32.773532 | 2025-10-08 15:42:32.773597 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 15:42:33.132063 | localhost | changed 2025-10-08 15:42:33.143553 | 2025-10-08 15:42:33.143721 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 15:42:33.888460 | localhost | changed 2025-10-08 15:42:33.894053 | 2025-10-08 15:42:33.894134 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 15:42:34.372601 | localhost | Identity added: /var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/tmp/ansible.tsns6cfc (/var/lib/zuul/builds/7e1cc41e8aa84da69a1665a6567d771f/work/tmp/ansible.tsns6cfc) 2025-10-08 15:42:34.373063 | localhost | ok: Runtime: 0:00:00.015281 2025-10-08 15:42:34.393149 | 2025-10-08 15:42:34.393303 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 15:42:34.742632 | localhost | ok: Runtime: 0:00:00.010263 2025-10-08 15:42:34.748562 | 2025-10-08 15:42:34.748651 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 15:42:34.845309 | localhost | changed 2025-10-08 15:42:34.855213 | 2025-10-08 15:42:34.855291 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 15:42:35.260316 | localhost | changed 2025-10-08 15:42:35.286887 | 2025-10-08 15:42:35.286974 | PLAY [localhost] 2025-10-08 15:42:35.299455 | 2025-10-08 15:42:35.299520 | TASK [Generate bulk log download script] 2025-10-08 15:42:35.318832 | localhost | ok 2025-10-08 15:42:35.331939 | 2025-10-08 15:42:35.332036 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 15:42:35.362903 | localhost | ok: All assertions passed 2025-10-08 15:42:35.367522 | 2025-10-08 15:42:35.367583 | TASK [local-log-download : Create download script] 2025-10-08 15:42:35.810401 | localhost -> localhost | changed 2025-10-08 15:42:35.831408 | 2025-10-08 15:42:35.831628 | TASK [Register quick-download link] 2025-10-08 15:42:35.866755 | localhost | ok 2025-10-08 15:42:35.933002 | 2025-10-08 15:42:35.933165 | PLAY [logserver.rdoproject.org] 2025-10-08 15:42:35.943925 | 2025-10-08 15:42:35.943985 | TASK [Set zuul-log-path fact] 2025-10-08 15:42:35.963448 | logserver.rdoproject.org | ok 2025-10-08 15:42:35.975462 | 2025-10-08 15:42:35.975538 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 15:42:36.004435 | logserver.rdoproject.org | ok 2025-10-08 15:42:36.009722 | 2025-10-08 15:42:36.009797 | TASK [upload-logs : Create log directories] 2025-10-08 15:42:36.679359 | logserver.rdoproject.org | changed 2025-10-08 15:42:36.686781 | 2025-10-08 15:42:36.686928 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 15:42:37.000564 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.011752 2025-10-08 15:42:37.012933 | 2025-10-08 15:42:37.013121 | TASK [upload-logs : Upload logs to log server] 2025-10-08 15:42:37.690317 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 15:42:37.696451 | 2025-10-08 15:42:37.696583 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 15:42:37.754755 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 15:42:37.763052 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 15:42:37.773965 | 2025-10-08 15:42:37.774202 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 15:42:37.816739 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 15:42:37.817235 | 2025-10-08 15:42:37.820094 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 15:42:37.831344 | 2025-10-08 15:42:37.831542 | LOOP [upload-logs : Upload console log and json output]