2025-12-01 12:28:16.443204 | Job console starting... 2025-12-01 12:28:16.456858 | Updating repositories 2025-12-01 12:28:16.494927 | Preparing job workspace 2025-12-01 12:28:20.807230 | Running Ansible setup... 2025-12-01 12:28:24.833768 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-01 12:28:25.428056 | 2025-12-01 12:28:25.428176 | PLAY [localhost] 2025-12-01 12:28:25.437109 | 2025-12-01 12:28:25.437183 | TASK [Gathering Facts] 2025-12-01 12:28:26.411498 | localhost | ok 2025-12-01 12:28:26.424869 | 2025-12-01 12:28:26.424946 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-01 12:28:26.763003 | localhost -> localhost | changed 2025-12-01 12:28:26.768550 | 2025-12-01 12:28:26.768627 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-01 12:28:27.625053 | localhost -> localhost | changed 2025-12-01 12:28:27.635397 | 2025-12-01 12:28:27.635472 | TASK [Setup log path fact] 2025-12-01 12:28:27.654855 | localhost | ok 2025-12-01 12:28:27.670578 | 2025-12-01 12:28:27.670666 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 12:28:27.699830 | localhost | ok 2025-12-01 12:28:27.710173 | 2025-12-01 12:28:27.710260 | TASK [emit-job-header : Print job information] 2025-12-01 12:28:27.749150 | # Job Information 2025-12-01 12:28:27.749340 | Ansible Version: 2.15.12 2025-12-01 12:28:27.749375 | Job: cifmw-molecule-cifmw_setup 2025-12-01 12:28:27.749402 | Pipeline: github-check 2025-12-01 12:28:27.749427 | Executor: ze03.softwarefactory-project.io 2025-12-01 12:28:27.749452 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3505 2025-12-01 12:28:27.749478 | Log URL (when completed): https://logserver.rdoproject.org/db5/rdoproject.org/db5f88da2fbc4362aa6a8bf1cacaad04/ 2025-12-01 12:28:27.749503 | Event ID: 0f5f1c30-ceb1-11f0-8d61-2bc68a7aefff 2025-12-01 12:28:27.755476 | 2025-12-01 12:28:27.755617 | LOOP [emit-job-header : Print node information] 2025-12-01 12:28:27.859196 | localhost | ok: 2025-12-01 12:28:27.859564 | localhost | # Node Information 2025-12-01 12:28:27.859624 | localhost | Inventory Hostname: controller 2025-12-01 12:28:27.859673 | localhost | Hostname: np0005541149 2025-12-01 12:28:27.859714 | localhost | Username: zuul 2025-12-01 12:28:27.859811 | localhost | Distro: CentOS 9 2025-12-01 12:28:27.859853 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-01 12:28:27.859893 | localhost | Region: RegionOne 2025-12-01 12:28:27.859930 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-01 12:28:27.859967 | localhost | Product Name: OpenStack Nova 2025-12-01 12:28:27.860003 | localhost | Interface IP: 38.102.83.38 2025-12-01 12:28:27.888353 | 2025-12-01 12:28:27.888480 | PLAY [all] 2025-12-01 12:28:27.897259 | 2025-12-01 12:28:27.897342 | TASK [Gather network facts] 2025-12-01 12:28:28.422415 | controller | ok 2025-12-01 12:28:28.441020 | 2025-12-01 12:28:28.441178 | TASK [include_role : start-zuul-console] 2025-12-01 12:28:28.463392 | controller | ok 2025-12-01 12:28:28.479671 | 2025-12-01 12:28:28.479826 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-01 12:28:28.939331 | controller | ok 2025-12-01 12:28:28.948479 | 2025-12-01 12:28:28.948605 | TASK [include_role : add-build-sshkey] 2025-12-01 12:28:28.980486 | controller | ok 2025-12-01 12:28:29.000494 | 2025-12-01 12:28:29.000663 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-01 12:28:29.253957 | controller -> localhost | ok 2025-12-01 12:28:29.262023 | 2025-12-01 12:28:29.262176 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-01 12:28:29.286860 | controller | ok 2025-12-01 12:28:29.306001 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-01 12:28:29.315011 | 2025-12-01 12:28:29.315174 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-01 12:28:29.803320 | controller -> localhost | Generating public/private rsa key pair. 2025-12-01 12:28:29.803669 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/db5f88da2fbc4362aa6a8bf1cacaad04_id_rsa. 2025-12-01 12:28:29.803764 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/db5f88da2fbc4362aa6a8bf1cacaad04_id_rsa.pub. 2025-12-01 12:28:29.803820 | controller -> localhost | The key fingerprint is: 2025-12-01 12:28:29.803864 | controller -> localhost | SHA256:FV/WKGNYL6bXsNntxQELTbnN5DQj+OxMOEA82S2P9Eg zuul-build-sshkey 2025-12-01 12:28:29.803906 | controller -> localhost | The key's randomart image is: 2025-12-01 12:28:29.803947 | controller -> localhost | +---[RSA 3072]----+ 2025-12-01 12:28:29.803987 | controller -> localhost | | o.++*o+o | 2025-12-01 12:28:29.804028 | controller -> localhost | | =.E=O+=.| 2025-12-01 12:28:29.804068 | controller -> localhost | | *.#+X.o| 2025-12-01 12:28:29.804108 | controller -> localhost | | . B # *.| 2025-12-01 12:28:29.804147 | controller -> localhost | | S . O o +| 2025-12-01 12:28:29.804185 | controller -> localhost | | . o ..| 2025-12-01 12:28:29.804223 | controller -> localhost | | .| 2025-12-01 12:28:29.804263 | controller -> localhost | | | 2025-12-01 12:28:29.804300 | controller -> localhost | | | 2025-12-01 12:28:29.804339 | controller -> localhost | +----[SHA256]-----+ 2025-12-01 12:28:29.804426 | controller -> localhost | ok: Runtime: 0:00:00.047496 2025-12-01 12:28:29.816295 | 2025-12-01 12:28:29.816436 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-01 12:28:29.841894 | controller | ok 2025-12-01 12:28:29.862927 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-01 12:28:29.876205 | 2025-12-01 12:28:29.876292 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-01 12:28:29.890814 | controller | skipping: Conditional result was False 2025-12-01 12:28:29.898474 | 2025-12-01 12:28:29.898565 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-01 12:28:30.374345 | controller | changed 2025-12-01 12:28:30.386561 | 2025-12-01 12:28:30.386695 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-01 12:28:30.689183 | controller | ok 2025-12-01 12:28:30.699915 | 2025-12-01 12:28:30.700086 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-01 12:28:31.732241 | controller | changed 2025-12-01 12:28:31.743262 | 2025-12-01 12:28:31.743411 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-01 12:28:32.738443 | controller | changed 2025-12-01 12:28:32.753991 | 2025-12-01 12:28:32.754228 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-01 12:28:32.770976 | controller | skipping: Conditional result was False 2025-12-01 12:28:32.784329 | 2025-12-01 12:28:32.784517 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-01 12:28:33.208385 | controller -> localhost | changed 2025-12-01 12:28:33.219800 | 2025-12-01 12:28:33.219974 | TASK [add-build-sshkey : Add back temp key] 2025-12-01 12:28:33.544566 | controller -> localhost | Identity added: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/db5f88da2fbc4362aa6a8bf1cacaad04_id_rsa (zuul-build-sshkey) 2025-12-01 12:28:33.545103 | controller -> localhost | ok: Runtime: 0:00:00.016141 2025-12-01 12:28:33.561404 | 2025-12-01 12:28:33.561566 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-01 12:28:33.972156 | controller | ok 2025-12-01 12:28:33.984816 | 2025-12-01 12:28:33.985023 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-01 12:28:34.023160 | controller | skipping: Conditional result was False 2025-12-01 12:28:34.044542 | 2025-12-01 12:28:34.044688 | TASK [include_role : validate-host] 2025-12-01 12:28:34.081869 | controller | ok 2025-12-01 12:28:34.116569 | 2025-12-01 12:28:34.116752 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-01 12:28:34.168503 | controller | ok 2025-12-01 12:28:34.174884 | 2025-12-01 12:28:34.174979 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-01 12:28:34.464486 | controller -> localhost | ok 2025-12-01 12:28:34.473240 | 2025-12-01 12:28:34.473339 | TASK [validate-host : Collect information about the host] 2025-12-01 12:28:35.357532 | controller | ok 2025-12-01 12:28:35.365801 | 2025-12-01 12:28:35.365864 | TASK [validate-host : Sanitize hostname] 2025-12-01 12:28:35.438054 | controller | ok 2025-12-01 12:28:35.445971 | 2025-12-01 12:28:35.446059 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-01 12:28:35.950037 | controller -> localhost | changed 2025-12-01 12:28:35.955620 | 2025-12-01 12:28:35.955685 | TASK [validate-host : Collect information about zuul worker] 2025-12-01 12:28:36.426614 | controller | ok 2025-12-01 12:28:36.439636 | 2025-12-01 12:28:36.439854 | TASK [validate-host : Write out all zuul information for each host] 2025-12-01 12:28:36.959493 | controller -> localhost | changed 2025-12-01 12:28:36.984932 | 2025-12-01 12:28:36.985222 | TASK [include_role : prepare-workspace-openshift] 2025-12-01 12:28:37.001985 | controller | skipping: Conditional result was False 2025-12-01 12:28:37.013687 | 2025-12-01 12:28:37.013856 | TASK [include_role : remove-zuul-sshkey] 2025-12-01 12:28:37.030225 | controller | skipping: Conditional result was False 2025-12-01 12:28:37.041940 | 2025-12-01 12:28:37.042083 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-01 12:28:37.339955 | controller | ok: "logs" 2025-12-01 12:28:37.340464 | controller | ok: All items complete 2025-12-01 12:28:37.340534 | 2025-12-01 12:28:37.604568 | controller | ok: "artifacts" 2025-12-01 12:28:37.868953 | controller | ok: "docs" 2025-12-01 12:28:37.887713 | 2025-12-01 12:28:37.887881 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-01 12:28:38.227898 | controller | changed: "logs" 2025-12-01 12:28:38.492042 | controller | changed: "artifacts" 2025-12-01 12:28:38.737937 | controller | changed: "docs" 2025-12-01 12:28:38.764486 | 2025-12-01 12:28:38.764605 | PLAY RECAP 2025-12-01 12:28:38.764660 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-01 12:28:38.764696 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-01 12:28:38.764718 | 2025-12-01 12:28:38.895428 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-01 12:28:38.896337 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-01 12:28:39.485028 | 2025-12-01 12:28:39.485177 | PLAY [localhost] 2025-12-01 12:28:39.506175 | 2025-12-01 12:28:39.506331 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-01 12:28:39.979550 | localhost | ok 2025-12-01 12:28:39.987719 | 2025-12-01 12:28:39.987856 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-01 12:28:40.702118 | localhost | changed 2025-12-01 12:28:40.743787 | 2025-12-01 12:28:40.744004 | PLAY [all] 2025-12-01 12:28:40.766818 | 2025-12-01 12:28:40.766917 | TASK [include_role : prepare-workspace] 2025-12-01 12:28:40.801783 | controller | ok 2025-12-01 12:28:40.821967 | 2025-12-01 12:28:40.822110 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-01 12:28:41.251237 | controller | ok 2025-12-01 12:28:41.265008 | 2025-12-01 12:28:41.265188 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-01 12:28:43.145985 | controller | Output suppressed because no_log was given 2025-12-01 12:28:43.166075 | 2025-12-01 12:28:43.166162 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-01 12:28:43.482925 | controller | changed: "logs" 2025-12-01 12:28:43.737019 | controller | changed: "artifacts" 2025-12-01 12:28:44.003561 | controller | changed: "docs" 2025-12-01 12:28:44.023624 | 2025-12-01 12:28:44.023845 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-01 12:28:44.301301 | controller | changed: "logs" 2025-12-01 12:28:44.301528 | controller | changed: All items complete 2025-12-01 12:28:44.301555 | 2025-12-01 12:28:44.577599 | controller | changed: "artifacts" 2025-12-01 12:28:44.850783 | controller | changed: "docs" 2025-12-01 12:28:44.892821 | 2025-12-01 12:28:44.893078 | TASK [Check if worker can sudo] 2025-12-01 12:28:45.443904 | controller | ok: Runtime: 0:00:00.049517 2025-12-01 12:28:45.455395 | 2025-12-01 12:28:45.455556 | TASK [configure-mirrors : Gather needed facts] 2025-12-01 12:28:45.533549 | controller | skipping: Conditional result was False 2025-12-01 12:28:45.545786 | 2025-12-01 12:28:45.545920 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-01 12:28:45.625234 | controller | ok 2025-12-01 12:28:45.642331 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-01 12:28:45.686251 | 2025-12-01 12:28:45.686397 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-01 12:28:46.020973 | controller | ok 2025-12-01 12:28:46.033583 | 2025-12-01 12:28:46.033717 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-01 12:28:46.123753 | controller | ok: "/var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-01 12:28:46.148415 | 2025-12-01 12:28:46.148624 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-01 12:28:47.158113 | controller | changed 2025-12-01 12:28:47.169484 | 2025-12-01 12:28:47.169613 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-01 12:28:47.252681 | controller | ok: "/var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-01 12:28:47.252894 | controller | ok: All items complete 2025-12-01 12:28:47.252934 | 2025-12-01 12:28:47.328060 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-01 12:28:47.336929 | 2025-12-01 12:28:47.337019 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-01 12:28:48.474397 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-01 12:28:49.493414 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-01 12:28:49.508556 | 2025-12-01 12:28:49.508854 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-01 12:28:50.032951 | controller | changed: section and option added 2025-12-01 12:28:50.061938 | 2025-12-01 12:28:50.062071 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-01 12:28:50.713644 | controller | 29 files removed 2025-12-01 12:28:50.713913 | controller | ok: Item: dnf clean all Runtime: 0:00:00.302881 2025-12-01 12:28:50.713968 | controller | changed: All items complete 2025-12-01 12:28:50.713997 | 2025-12-01 12:29:01.141102 | 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 12:29:01.141288 | controller | DNF version: 4.14.0 2025-12-01 12:29:01.141342 | controller | cachedir: /var/cache/dnf 2025-12-01 12:29:01.141388 | controller | Making cache files for all metadata files. 2025-12-01 12:29:01.141429 | controller | baseos: has expired and will be refreshed. 2025-12-01 12:29:01.141469 | controller | appstream: has expired and will be refreshed. 2025-12-01 12:29:01.141507 | controller | crb: has expired and will be refreshed. 2025-12-01 12:29:01.141560 | controller | extras-common: has expired and will be refreshed. 2025-12-01 12:29:01.141599 | controller | repo: downloading from remote: baseos 2025-12-01 12:29:01.141637 | controller | CentOS Stream 9 - BaseOS 54 MB/s | 8.8 MB 00:00 2025-12-01 12:29:01.141676 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST. 2025-12-01 12:29:01.141713 | controller | repo: downloading from remote: appstream 2025-12-01 12:29:01.141792 | controller | CentOS Stream 9 - AppStream 96 MB/s | 25 MB 00:00 2025-12-01 12:29:01.141832 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST. 2025-12-01 12:29:01.141869 | controller | repo: downloading from remote: crb 2025-12-01 12:29:01.141906 | controller | CentOS Stream 9 - CRB 65 MB/s | 7.3 MB 00:00 2025-12-01 12:29:01.141944 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST. 2025-12-01 12:29:01.141980 | controller | repo: downloading from remote: extras-common 2025-12-01 12:29:01.142018 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-12-01 12:29:01.142055 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-01 12:29:01.142114 | controller | Last metadata expiration check: 0:00:01 ago on Mon 01 Dec 2025 07:28:59 AM EST. 2025-12-01 12:29:01.142153 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-01 12:29:01.142191 | controller | Completion plugin: Generating completion cache... 2025-12-01 12:29:01.142229 | controller | Metadata cache created. 2025-12-01 12:29:01.142284 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.111119 2025-12-01 12:29:01.171128 | 2025-12-01 12:29:01.171335 | PLAY RECAP 2025-12-01 12:29:01.171410 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-01 12:29:01.171458 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-01 12:29:01.171494 | 2025-12-01 12:29:01.297186 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-01 12:29:01.298077 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 12:29:01.903488 | 2025-12-01 12:29:01.903608 | PLAY [all] 2025-12-01 12:29:01.925124 | 2025-12-01 12:29:01.925236 | TASK [Install binary dependencies] 2025-12-01 12:29:01.997540 | controller | ok 2025-12-01 12:29:02.025803 | 2025-12-01 12:29:02.025995 | TASK [bindep : Include find tasks] 2025-12-01 12:29:02.068088 | controller | ok 2025-12-01 12:29:02.076165 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-01 12:29:02.082320 | 2025-12-01 12:29:02.082389 | TASK [bindep : Look for bindep.txt] 2025-12-01 12:29:02.512659 | controller | ok 2025-12-01 12:29:02.519071 | 2025-12-01 12:29:02.519137 | TASK [bindep : Define bindep_file fact] 2025-12-01 12:29:02.548008 | controller | ok 2025-12-01 12:29:02.553090 | 2025-12-01 12:29:02.553176 | TASK [bindep : Look for other-requirements.txt] 2025-12-01 12:29:02.576936 | controller | skipping: Conditional result was False 2025-12-01 12:29:02.582843 | 2025-12-01 12:29:02.582911 | TASK [bindep : Define bindep_file fact] 2025-12-01 12:29:02.616873 | controller | skipping: Conditional result was False 2025-12-01 12:29:02.624672 | 2025-12-01 12:29:02.624823 | TASK [bindep : Look for bindep fallback file] 2025-12-01 12:29:02.660235 | controller | skipping: Conditional result was False 2025-12-01 12:29:02.673303 | 2025-12-01 12:29:02.673461 | TASK [bindep : Define bindep_file fact] 2025-12-01 12:29:02.700898 | controller | skipping: Conditional result was False 2025-12-01 12:29:02.711243 | 2025-12-01 12:29:02.711346 | TASK [bindep : Include bindep tasks] 2025-12-01 12:29:02.744808 | controller | ok 2025-12-01 12:29:02.753836 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-01 12:29:02.764927 | 2025-12-01 12:29:02.765057 | TASK [bindep : Look for bindep command] 2025-12-01 12:29:02.790423 | controller | skipping: Conditional result was False 2025-12-01 12:29:02.802868 | 2025-12-01 12:29:02.803011 | TASK [bindep : Check for system bindep] 2025-12-01 12:29:03.352860 | controller | ok: Runtime: 0:00:00.008285 2025-12-01 12:29:03.366258 | 2025-12-01 12:29:03.366475 | TASK [bindep : Define bindep_command fact] 2025-12-01 12:29:03.405999 | controller | skipping: Conditional result was False 2025-12-01 12:29:03.420762 | 2025-12-01 12:29:03.421000 | TASK [bindep : Include install tasks] 2025-12-01 12:29:03.453626 | controller | ok 2025-12-01 12:29:03.461853 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-01 12:29:03.471320 | 2025-12-01 12:29:03.471395 | TASK [bindep : Create temp dir for bindep] 2025-12-01 12:29:03.896065 | controller | changed 2025-12-01 12:29:03.904409 | 2025-12-01 12:29:03.904528 | TASK [Ensure we have pip dependencies] 2025-12-01 12:29:03.930315 | controller | ok 2025-12-01 12:29:03.966488 | 2025-12-01 12:29:03.966612 | TASK [ensure-pip : Check if pip is installed] 2025-12-01 07:29:04.264937 | controller | /usr/bin/pip3 2025-12-01 07:29:04.307770 | controller | /usr/bin/python3: No module named wheel 2025-12-01 12:29:04.497681 | controller | ok: Runtime: 0:00:00.057800 2025-12-01 12:29:04.507040 | 2025-12-01 12:29:04.507180 | LOOP [ensure-pip : Install pip from packages] 2025-12-01 12:29:04.555072 | controller | ok: "/var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-01 12:29:04.568294 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-01 12:29:04.586378 | 2025-12-01 12:29:04.586543 | TASK [ensure-pip : Install Python 3 pip] 2025-12-01 12:29:06.412512 | controller | changed 2025-12-01 12:29:06.429555 | 2025-12-01 12:29:06.429810 | TASK [ensure-pip : Check for EPEL repository] 2025-12-01 12:29:06.491164 | controller | skipping: Conditional result was False 2025-12-01 12:29:06.504302 | 2025-12-01 12:29:06.504470 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-01 12:29:06.563244 | controller | skipping: Conditional result was False 2025-12-01 12:29:06.575685 | 2025-12-01 12:29:06.575892 | TASK [ensure-pip : Install Python 2 pip] 2025-12-01 12:29:06.623667 | controller | skipping: Conditional result was False 2025-12-01 12:29:06.636004 | 2025-12-01 12:29:06.636176 | TASK [ensure-pip : Ensure setuptools] 2025-12-01 12:29:06.662852 | controller | skipping: Conditional result was False 2025-12-01 12:29:06.676577 | 2025-12-01 12:29:06.676795 | TASK [ensure-pip : Check for ensurepip module] 2025-12-01 12:29:07.224258 | controller | skipping: Conditional result was False 2025-12-01 12:29:07.237252 | 2025-12-01 12:29:07.237448 | TASK [ensure-pip : Ensure python3-venv] 2025-12-01 12:29:07.264566 | controller | skipping: Conditional result was False 2025-12-01 12:29:07.276600 | 2025-12-01 12:29:07.276823 | TASK [ensure-pip : Install pip from source] 2025-12-01 12:29:07.303691 | controller | skipping: Conditional result was False 2025-12-01 12:29:07.316815 | 2025-12-01 12:29:07.316987 | TASK [ensure-pip : Probe for venv python full path] 2025-12-01 07:29:07.598427 | controller | /usr/bin/python3 2025-12-01 12:29:07.864328 | controller | ok: Runtime: 0:00:00.008389 2025-12-01 12:29:07.870495 | 2025-12-01 12:29:07.870595 | TASK [ensure-pip : Set host default] 2025-12-01 12:29:07.914561 | controller | ok 2025-12-01 12:29:07.922802 | 2025-12-01 12:29:07.922928 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-01 12:29:07.968956 | controller | ok 2025-12-01 12:29:07.984403 | 2025-12-01 12:29:07.984514 | TASK [bindep : Install bindep into temporary venv] 2025-12-01 12:29:11.901616 | controller | changed 2025-12-01 12:29:11.916427 | 2025-12-01 12:29:11.916634 | TASK [bindep : Define bindep_command] 2025-12-01 12:29:11.941391 | controller | ok 2025-12-01 12:29:11.948706 | 2025-12-01 12:29:11.948817 | LOOP [bindep : Include package tasks] 2025-12-01 12:29:11.996470 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-01 12:29:11.996996 | controller | ok: All items complete 2025-12-01 12:29:11.997074 | 2025-12-01 12:29:12.018110 | controller | included: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-01 12:29:12.033769 | 2025-12-01 12:29:12.033861 | TASK [bindep : Define bindep_run fact] 2025-12-01 12:29:12.076234 | controller | ok 2025-12-01 12:29:12.082757 | 2025-12-01 12:29:12.082828 | TASK [bindep : Get list of packages to install from bindep] 2025-12-01 07:29:13.733294 | controller | podman 2025-12-01 07:29:13.770498 | controller | python3-jmespath 2025-12-01 07:29:13.770519 | controller | python3-libvirt 2025-12-01 07:29:13.770526 | controller | python3-lxml 2025-12-01 07:29:13.770534 | controller | python3-netaddr 2025-12-01 12:29:14.123410 | controller | ok: Runtime: 0:00:01.361634 2025-12-01 12:29:14.137035 | 2025-12-01 12:29:14.137218 | TASK [bindep : Install distro packages from bindep] 2025-12-01 12:30:13.334647 | controller | changed 2025-12-01 12:30:13.349041 | 2025-12-01 12:30:13.349309 | TASK [bindep : Check that packages are installed] 2025-12-01 12:30:15.403844 | controller | ok: Runtime: 0:00:01.237530 2025-12-01 12:30:15.417849 | 2025-12-01 12:30:15.418570 | TASK [bindep : Fail if we cannot install all packages] 2025-12-01 12:30:15.456653 | controller | skipping: Conditional result was False 2025-12-01 12:30:15.523527 | 2025-12-01 12:30:15.523679 | TASK [Run test-setup role] 2025-12-01 12:30:15.547281 | controller | ok 2025-12-01 12:30:15.574055 | 2025-12-01 12:30:15.574212 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-01 12:30:15.818598 | controller | ok 2025-12-01 12:30:15.823611 | 2025-12-01 12:30:15.823704 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-01 12:30:16.353397 | controller | skipping: Conditional result was False 2025-12-01 12:30:16.381957 | 2025-12-01 12:30:16.382096 | TASK [bindep : Remove bindep temp dir] 2025-12-01 12:30:16.776575 | controller | ok 2025-12-01 12:30:16.799027 | 2025-12-01 12:30:16.799178 | PLAY RECAP 2025-12-01 12:30:16.799263 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-01 12:30:16.799345 | 2025-12-01 12:30:16.925021 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 12:30:16.925945 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-01 12:30:17.484753 | 2025-12-01 12:30:17.484914 | PLAY [all] 2025-12-01 12:30:17.505578 | 2025-12-01 12:30:17.505752 | TASK [Abort when test_command variable is undefined] 2025-12-01 12:30:17.540324 | controller | skipping: Conditional result was False 2025-12-01 12:30:17.546320 | 2025-12-01 12:30:17.546404 | TASK [Convert test_command to list] 2025-12-01 12:30:17.611708 | controller | skipping: Conditional result was False 2025-12-01 12:30:17.624638 | 2025-12-01 12:30:17.624839 | TASK [Use test_command list] 2025-12-01 12:30:17.693506 | controller | ok 2025-12-01 12:30:17.705550 | 2025-12-01 12:30:17.705765 | LOOP [Run test_command] 2025-12-01 12:30:18.145204 | controller | no check to run 2025-12-01 12:30:18.145485 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004798 2025-12-01 12:30:18.196804 | 2025-12-01 12:30:18.196960 | PLAY RECAP 2025-12-01 12:30:18.197055 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-01 12:30:18.197106 | 2025-12-01 12:30:18.312563 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-01 12:30:18.314503 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 12:30:18.871222 | 2025-12-01 12:30:18.871350 | PLAY [all] 2025-12-01 12:30:18.891595 | 2025-12-01 12:30:18.891720 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-01 12:30:19.345509 | controller | changed: non-zero return code 2025-12-01 12:30:19.351412 | 2025-12-01 12:30:19.351546 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-01 12:30:19.377703 | controller | skipping: Conditional result was False 2025-12-01 12:30:19.386551 | 2025-12-01 12:30:19.386758 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-01 12:30:19.421857 | 2025-12-01 12:30:19.422072 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-01 12:30:19.456594 | 2025-12-01 12:30:19.456838 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-01 12:30:19.483051 | controller | skipping: Conditional result was False 2025-12-01 12:30:19.491987 | 2025-12-01 12:30:19.492123 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-01 12:30:19.528360 | 2025-12-01 12:30:19.528591 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-01 12:30:19.555162 | controller | skipping: Conditional result was False 2025-12-01 12:30:19.564023 | 2025-12-01 12:30:19.564196 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-01 12:30:19.590608 | controller | skipping: Conditional result was False 2025-12-01 12:30:19.599143 | 2025-12-01 12:30:19.599263 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-01 12:30:19.625109 | controller | skipping: Conditional result was False 2025-12-01 12:30:19.660928 | 2025-12-01 12:30:19.661059 | PLAY RECAP 2025-12-01 12:30:19.661120 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-01 12:30:19.661151 | 2025-12-01 12:30:19.782771 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 12:30:19.784477 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-01 12:30:20.391679 | 2025-12-01 12:30:20.391818 | PLAY [all] 2025-12-01 12:30:20.412269 | 2025-12-01 12:30:20.412381 | TASK [include_role : fetch-output] 2025-12-01 12:30:20.451453 | controller | ok 2025-12-01 12:30:20.468122 | 2025-12-01 12:30:20.468250 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-01 12:30:20.543250 | controller | skipping: Conditional result was False 2025-12-01 12:30:20.555070 | 2025-12-01 12:30:20.555216 | TASK [fetch-output : Set log path for single node] 2025-12-01 12:30:20.602257 | controller | ok 2025-12-01 12:30:20.615427 | 2025-12-01 12:30:20.615559 | LOOP [fetch-output : Ensure local output dirs] 2025-12-01 12:30:21.006542 | controller -> localhost | ok: "/var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/logs" 2025-12-01 12:30:21.271965 | controller -> localhost | changed: "/var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/artifacts" 2025-12-01 12:30:21.564501 | controller -> localhost | changed: "/var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/docs" 2025-12-01 12:30:21.587452 | 2025-12-01 12:30:21.587630 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-01 12:30:22.305518 | controller | changed: .d..t...... ./ 2025-12-01 12:30:22.305720 | controller | changed: All items complete 2025-12-01 12:30:22.305770 | 2025-12-01 12:30:22.841206 | controller | changed: .d..t...... ./ 2025-12-01 12:30:23.343231 | controller | changed: .d..t...... ./ 2025-12-01 12:30:23.376792 | 2025-12-01 12:30:23.377010 | TASK [include_role : fetch-output-openshift] 2025-12-01 12:30:23.394335 | controller | skipping: Conditional result was False 2025-12-01 12:30:23.403775 | 2025-12-01 12:30:23.403904 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-01 12:30:23.827756 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008963 2025-12-01 12:30:24.080046 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013005 2025-12-01 12:30:24.141450 | 2025-12-01 12:30:24.141596 | PLAY [all] 2025-12-01 12:30:24.155804 | 2025-12-01 12:30:24.155875 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-01 12:30:24.630193 | controller | changed 2025-12-01 12:30:24.676063 | 2025-12-01 12:30:24.676187 | PLAY RECAP 2025-12-01 12:30:24.676243 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-01 12:30:24.676272 | 2025-12-01 12:30:24.789858 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-01 12:30:24.791030 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-01 12:30:25.480671 | 2025-12-01 12:30:25.480824 | PLAY [localhost] 2025-12-01 12:30:25.500499 | 2025-12-01 12:30:25.500749 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-01 12:30:25.952270 | localhost | changed 2025-12-01 12:30:25.958936 | 2025-12-01 12:30:25.959111 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-01 12:30:25.991453 | localhost | ok 2025-12-01 12:30:26.000329 | 2025-12-01 12:30:26.000436 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-01 12:30:26.431799 | localhost | changed 2025-12-01 12:30:26.443787 | 2025-12-01 12:30:26.443932 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-01 12:30:27.254235 | localhost | changed 2025-12-01 12:30:27.265194 | 2025-12-01 12:30:27.265375 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-01 12:30:27.739157 | localhost | Identity added: /var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/tmp/ansible.iuugernf (/var/lib/zuul/builds/db5f88da2fbc4362aa6a8bf1cacaad04/work/tmp/ansible.iuugernf) 2025-12-01 12:30:27.739398 | localhost | ok: Runtime: 0:00:00.013667 2025-12-01 12:30:27.745511 | 2025-12-01 12:30:27.745592 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-01 12:30:28.057750 | localhost | ok: Runtime: 0:00:00.008676 2025-12-01 12:30:28.069097 | 2025-12-01 12:30:28.069266 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-01 12:30:28.155829 | localhost | changed 2025-12-01 12:30:28.165167 | 2025-12-01 12:30:28.165308 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-01 12:30:28.628647 | localhost | changed 2025-12-01 12:30:28.671026 | 2025-12-01 12:30:28.671107 | PLAY [localhost] 2025-12-01 12:30:28.688172 | 2025-12-01 12:30:28.688250 | TASK [Generate bulk log download script] 2025-12-01 12:30:28.708623 | localhost | ok 2025-12-01 12:30:28.724577 | 2025-12-01 12:30:28.724676 | TASK [local-log-download : Check API endpoint is defined] 2025-12-01 12:30:28.774402 | localhost | ok: All assertions passed 2025-12-01 12:30:28.780619 | 2025-12-01 12:30:28.780708 | TASK [local-log-download : Create download script] 2025-12-01 12:30:29.262618 | localhost -> localhost | changed 2025-12-01 12:30:29.272915 | 2025-12-01 12:30:29.272991 | TASK [Register quick-download link] 2025-12-01 12:30:29.302078 | localhost | ok 2025-12-01 12:30:29.345326 | 2025-12-01 12:30:29.345513 | PLAY [logserver.rdoproject.org] 2025-12-01 12:30:29.356384 | 2025-12-01 12:30:29.356451 | TASK [Set zuul-log-path fact] 2025-12-01 12:30:29.384203 | logserver.rdoproject.org | ok 2025-12-01 12:30:29.393508 | 2025-12-01 12:30:29.393583 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 12:30:29.435687 | logserver.rdoproject.org | ok 2025-12-01 12:30:29.443549 | 2025-12-01 12:30:29.443646 | TASK [upload-logs : Create log directories] 2025-12-01 12:30:30.299026 | logserver.rdoproject.org | changed 2025-12-01 12:30:30.308011 | 2025-12-01 12:30:30.308212 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-01 12:30:30.667273 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.011155 2025-12-01 12:30:30.680553 | 2025-12-01 12:30:30.680807 | TASK [upload-logs : Upload logs to log server] 2025-12-01 12:30:31.401699 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-01 12:30:31.404891 | 2025-12-01 12:30:31.404959 | LOOP [upload-logs : Compress console log and json output] 2025-12-01 12:30:31.456141 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 12:30:31.468874 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 12:30:31.475153 | 2025-12-01 12:30:31.475334 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-01 12:30:31.528018 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 12:30:31.528443 | 2025-12-01 12:30:31.531354 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 12:30:31.545343 | 2025-12-01 12:30:31.545514 | LOOP [upload-logs : Upload console log and json output]