2025-12-05 15:33:23.110408 | Job console starting... 2025-12-05 15:33:23.121562 | Updating repositories 2025-12-05 15:33:23.146956 | Preparing job workspace 2025-12-05 15:33:26.584604 | Running Ansible setup... 2025-12-05 15:33:30.317565 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:33:30.939150 | 2025-12-05 15:33:30.939267 | PLAY [localhost] 2025-12-05 15:33:30.948684 | 2025-12-05 15:33:30.948763 | TASK [Gathering Facts] 2025-12-05 15:33:31.912642 | localhost | ok 2025-12-05 15:33:31.934123 | 2025-12-05 15:33:31.934270 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 15:33:32.415900 | localhost -> localhost | changed 2025-12-05 15:33:32.423270 | 2025-12-05 15:33:32.423372 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 15:33:33.636402 | localhost -> localhost | changed 2025-12-05 15:33:33.645769 | 2025-12-05 15:33:33.646658 | TASK [Setup log path fact] 2025-12-05 15:33:33.669162 | localhost | ok 2025-12-05 15:33:33.686278 | 2025-12-05 15:33:33.686353 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:33:33.713868 | localhost | ok 2025-12-05 15:33:33.722039 | 2025-12-05 15:33:33.722114 | TASK [emit-job-header : Print job information] 2025-12-05 15:33:33.761074 | # Job Information 2025-12-05 15:33:33.761244 | Ansible Version: 2.15.12 2025-12-05 15:33:33.761270 | Job: cifmw-molecule-krb_request 2025-12-05 15:33:33.761289 | Pipeline: github-check 2025-12-05 15:33:33.761307 | Executor: ze01.softwarefactory-project.io 2025-12-05 15:33:33.761325 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539 2025-12-05 15:33:33.761343 | Log URL (when completed): https://logserver.rdoproject.org/963/rdoproject.org/963d163510234aa1aed22ebe3de5cfe3/ 2025-12-05 15:33:33.761361 | Event ID: 757b9e30-d1ef-11f0-97eb-f505e6ea5a00 2025-12-05 15:33:33.765273 | 2025-12-05 15:33:33.765368 | LOOP [emit-job-header : Print node information] 2025-12-05 15:33:33.869581 | localhost | ok: 2025-12-05 15:33:33.869802 | localhost | # Node Information 2025-12-05 15:33:33.869831 | localhost | Inventory Hostname: controller 2025-12-05 15:33:33.869858 | localhost | Hostname: np0005547429 2025-12-05 15:33:33.869878 | localhost | Username: zuul 2025-12-05 15:33:33.869898 | localhost | Distro: CentOS 9 2025-12-05 15:33:33.869916 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 15:33:33.869935 | localhost | Region: RegionOne 2025-12-05 15:33:33.869953 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 15:33:33.869970 | localhost | Product Name: OpenStack Nova 2025-12-05 15:33:33.869986 | localhost | Interface IP: 38.102.83.156 2025-12-05 15:33:33.900491 | 2025-12-05 15:33:33.900597 | PLAY [all] 2025-12-05 15:33:33.908245 | 2025-12-05 15:33:33.908361 | TASK [Gather network facts] 2025-12-05 15:33:34.362149 | controller | ok 2025-12-05 15:33:34.405997 | 2025-12-05 15:33:34.406140 | TASK [include_role : start-zuul-console] 2025-12-05 15:33:34.426320 | controller | ok 2025-12-05 15:33:34.442490 | 2025-12-05 15:33:34.442589 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 15:33:34.856316 | controller | ok 2025-12-05 15:33:34.876727 | 2025-12-05 15:33:34.878108 | TASK [include_role : add-build-sshkey] 2025-12-05 15:33:34.931114 | controller | ok 2025-12-05 15:33:34.957718 | 2025-12-05 15:33:34.957848 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 15:33:35.441626 | controller -> localhost | ok 2025-12-05 15:33:35.448356 | 2025-12-05 15:33:35.448425 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 15:33:35.487252 | controller | ok 2025-12-05 15:33:35.516196 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 15:33:35.525940 | 2025-12-05 15:33:35.526043 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 15:33:36.499556 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 15:33:36.499821 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/963d163510234aa1aed22ebe3de5cfe3_id_rsa. 2025-12-05 15:33:36.499852 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/963d163510234aa1aed22ebe3de5cfe3_id_rsa.pub. 2025-12-05 15:33:36.499874 | controller -> localhost | The key fingerprint is: 2025-12-05 15:33:36.499895 | controller -> localhost | SHA256:G5Ca5O8C57uGPHmaax7y2/YH1zrFgUydxaozZ7/52fU zuul-build-sshkey 2025-12-05 15:33:36.499914 | controller -> localhost | The key's randomart image is: 2025-12-05 15:33:36.499932 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 15:33:36.499950 | controller -> localhost | | . +. | 2025-12-05 15:33:36.499969 | controller -> localhost | | .. o . | 2025-12-05 15:33:36.499988 | controller -> localhost | | . oo . . | 2025-12-05 15:33:36.500006 | controller -> localhost | | o o .o o | 2025-12-05 15:33:36.500045 | controller -> localhost | | + S+ . | 2025-12-05 15:33:36.500064 | controller -> localhost | | . ... =o* | 2025-12-05 15:33:36.500083 | controller -> localhost | |...* .o.B . .| 2025-12-05 15:33:36.500102 | controller -> localhost | | o*+*. + .. oo| 2025-12-05 15:33:36.500119 | controller -> localhost | | oBO+=o. . ooo E| 2025-12-05 15:33:36.500137 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 15:33:36.500181 | controller -> localhost | ok: Runtime: 0:00:00.339153 2025-12-05 15:33:36.505698 | 2025-12-05 15:33:36.505762 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 15:33:36.537965 | controller | ok 2025-12-05 15:33:36.555501 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 15:33:36.571976 | 2025-12-05 15:33:36.572126 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 15:33:36.597207 | controller | skipping: Conditional result was False 2025-12-05 15:33:36.602957 | 2025-12-05 15:33:36.603053 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 15:33:37.077900 | controller | changed 2025-12-05 15:33:37.082755 | 2025-12-05 15:33:37.082814 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 15:33:37.339107 | controller | ok 2025-12-05 15:33:37.344528 | 2025-12-05 15:33:37.344591 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 15:33:38.214587 | controller | changed 2025-12-05 15:33:38.220340 | 2025-12-05 15:33:38.220414 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 15:33:39.146288 | controller | changed 2025-12-05 15:33:39.153147 | 2025-12-05 15:33:39.153283 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 15:33:39.177104 | controller | skipping: Conditional result was False 2025-12-05 15:33:39.182765 | 2025-12-05 15:33:39.182842 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 15:33:39.614691 | controller -> localhost | changed 2025-12-05 15:33:39.628113 | 2025-12-05 15:33:39.628225 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 15:33:40.011968 | controller -> localhost | Identity added: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/963d163510234aa1aed22ebe3de5cfe3_id_rsa (zuul-build-sshkey) 2025-12-05 15:33:40.012301 | controller -> localhost | ok: Runtime: 0:00:00.014631 2025-12-05 15:33:40.019572 | 2025-12-05 15:33:40.019639 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 15:33:40.394958 | controller | ok 2025-12-05 15:33:40.399966 | 2025-12-05 15:33:40.400081 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 15:33:40.435602 | controller | skipping: Conditional result was False 2025-12-05 15:33:40.445418 | 2025-12-05 15:33:40.445493 | TASK [include_role : validate-host] 2025-12-05 15:33:40.464876 | controller | ok 2025-12-05 15:33:40.484270 | 2025-12-05 15:33:40.484349 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 15:33:40.513112 | controller | ok 2025-12-05 15:33:40.517975 | 2025-12-05 15:33:40.518062 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 15:33:40.820650 | controller -> localhost | ok 2025-12-05 15:33:40.893442 | 2025-12-05 15:33:40.893604 | TASK [validate-host : Collect information about the host] 2025-12-05 15:33:41.620831 | controller | ok 2025-12-05 15:33:41.631898 | 2025-12-05 15:33:41.632010 | TASK [validate-host : Sanitize hostname] 2025-12-05 15:33:41.693317 | controller | ok 2025-12-05 15:33:41.700004 | 2025-12-05 15:33:41.700095 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 15:33:42.146222 | controller -> localhost | changed 2025-12-05 15:33:42.152105 | 2025-12-05 15:33:42.152181 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 15:33:42.577179 | controller | ok 2025-12-05 15:33:42.582615 | 2025-12-05 15:33:42.582683 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 15:33:43.068098 | controller -> localhost | changed 2025-12-05 15:33:43.078711 | 2025-12-05 15:33:43.078793 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 15:33:43.093712 | controller | skipping: Conditional result was False 2025-12-05 15:33:43.099205 | 2025-12-05 15:33:43.099270 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 15:33:43.125648 | controller | skipping: Conditional result was False 2025-12-05 15:33:43.132151 | 2025-12-05 15:33:43.132225 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:33:43.370607 | controller | ok: "logs" 2025-12-05 15:33:43.370972 | controller | ok: All items complete 2025-12-05 15:33:43.371010 | 2025-12-05 15:33:43.574188 | controller | ok: "artifacts" 2025-12-05 15:33:43.774663 | controller | ok: "docs" 2025-12-05 15:33:43.790144 | 2025-12-05 15:33:43.790225 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:33:44.038282 | controller | changed: "logs" 2025-12-05 15:33:44.251045 | controller | changed: "artifacts" 2025-12-05 15:33:44.485270 | controller | changed: "docs" 2025-12-05 15:33:44.540504 | 2025-12-05 15:33:44.540616 | PLAY RECAP 2025-12-05 15:33:44.540659 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 15:33:44.540685 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:33:44.540702 | 2025-12-05 15:33:44.701685 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:33:44.702579 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:33:45.663604 | 2025-12-05 15:33:45.663762 | PLAY [localhost] 2025-12-05 15:33:45.691722 | 2025-12-05 15:33:45.691844 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 15:33:46.150765 | localhost | ok 2025-12-05 15:33:46.162783 | 2025-12-05 15:33:46.162906 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 15:33:47.422505 | localhost | changed 2025-12-05 15:33:47.453582 | 2025-12-05 15:33:47.453662 | PLAY [all] 2025-12-05 15:33:47.469456 | 2025-12-05 15:33:47.475240 | TASK [include_role : prepare-workspace] 2025-12-05 15:33:47.505282 | controller | ok 2025-12-05 15:33:47.526626 | 2025-12-05 15:33:47.526758 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 15:33:47.907122 | controller | ok 2025-12-05 15:33:47.916274 | 2025-12-05 15:33:47.916363 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 15:33:49.661769 | controller | Output suppressed because no_log was given 2025-12-05 15:33:49.672662 | 2025-12-05 15:33:49.672750 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:33:49.940718 | controller | changed: "logs" 2025-12-05 15:33:50.182640 | controller | changed: "artifacts" 2025-12-05 15:33:50.410401 | controller | changed: "docs" 2025-12-05 15:33:50.418241 | 2025-12-05 15:33:50.418358 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:33:50.682739 | controller | changed: "logs" 2025-12-05 15:33:50.683030 | controller | changed: All items complete 2025-12-05 15:33:50.683062 | 2025-12-05 15:33:50.895920 | controller | changed: "artifacts" 2025-12-05 15:33:51.115998 | controller | changed: "docs" 2025-12-05 15:33:51.145096 | 2025-12-05 15:33:51.145254 | TASK [Check if worker can sudo] 2025-12-05 15:33:52.184456 | controller | ok: Runtime: 0:00:00.038013 2025-12-05 15:33:52.190911 | 2025-12-05 15:33:52.191064 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 15:33:52.268423 | controller | skipping: Conditional result was False 2025-12-05 15:33:52.277335 | 2025-12-05 15:33:52.277489 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 15:33:52.378478 | controller | ok 2025-12-05 15:33:52.389272 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 15:33:52.438005 | 2025-12-05 15:33:52.438145 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 15:33:52.696383 | controller | ok 2025-12-05 15:33:52.702601 | 2025-12-05 15:33:52.702669 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 15:33:52.762491 | controller | ok: "/var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 15:33:52.777676 | 2025-12-05 15:33:52.777779 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 15:33:53.707434 | controller | changed 2025-12-05 15:33:53.714132 | 2025-12-05 15:33:53.714197 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 15:33:53.777557 | controller | ok: "/var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 15:33:53.777797 | controller | ok: All items complete 2025-12-05 15:33:53.777826 | 2025-12-05 15:33:53.822174 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 15:33:53.828898 | 2025-12-05 15:33:53.828978 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 15:33:54.683125 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 15:33:55.452098 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 15:33:55.472199 | 2025-12-05 15:33:55.472357 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 15:33:55.972181 | controller | changed: section and option added 2025-12-05 15:33:56.008010 | 2025-12-05 15:33:56.008200 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 15:33:56.605724 | controller | 29 files removed 2025-12-05 15:33:56.606070 | controller | ok: Item: dnf clean all Runtime: 0:00:00.298657 2025-12-05 15:33:56.606120 | controller | changed: All items complete 2025-12-05 15:33:56.606169 | 2025-12-05 15:34:07.886741 | 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-05 15:34:07.886865 | controller | DNF version: 4.14.0 2025-12-05 15:34:07.886891 | controller | cachedir: /var/cache/dnf 2025-12-05 15:34:07.886912 | controller | Making cache files for all metadata files. 2025-12-05 15:34:07.886931 | controller | baseos: has expired and will be refreshed. 2025-12-05 15:34:07.886949 | controller | appstream: has expired and will be refreshed. 2025-12-05 15:34:07.886986 | controller | crb: has expired and will be refreshed. 2025-12-05 15:34:07.887036 | controller | extras-common: has expired and will be refreshed. 2025-12-05 15:34:07.887060 | controller | repo: downloading from remote: baseos 2025-12-05 15:34:07.887078 | controller | CentOS Stream 9 - BaseOS 69 MB/s | 8.8 MB 00:00 2025-12-05 15:34:07.887123 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 15:34:07.887141 | controller | repo: downloading from remote: appstream 2025-12-05 15:34:07.887157 | controller | CentOS Stream 9 - AppStream 89 MB/s | 25 MB 00:00 2025-12-05 15:34:07.887173 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 15:34:07.887189 | controller | repo: downloading from remote: crb 2025-12-05 15:34:07.887209 | controller | CentOS Stream 9 - CRB 65 MB/s | 7.3 MB 00:00 2025-12-05 15:34:07.887232 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 15:34:07.887251 | controller | repo: downloading from remote: extras-common 2025-12-05 15:34:07.887269 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-12-05 15:34:07.887290 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 15:34:07.887314 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 15:34:07.887337 | controller | Completion plugin: Generating completion cache... 2025-12-05 15:34:07.887354 | controller | Metadata cache created. 2025-12-05 15:34:07.887381 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.032821 2025-12-05 15:34:07.902519 | 2025-12-05 15:34:07.902629 | PLAY RECAP 2025-12-05 15:34:07.902670 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 15:34:07.902695 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:34:07.902713 | 2025-12-05 15:34:08.019039 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:34:08.021202 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:34:08.595635 | 2025-12-05 15:34:08.595760 | PLAY [all] 2025-12-05 15:34:08.616970 | 2025-12-05 15:34:08.617087 | TASK [Install binary dependencies] 2025-12-05 15:34:08.663658 | controller | ok 2025-12-05 15:34:08.684318 | 2025-12-05 15:34:08.684449 | TASK [bindep : Include find tasks] 2025-12-05 15:34:08.727067 | controller | ok 2025-12-05 15:34:08.739164 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 15:34:08.747865 | 2025-12-05 15:34:08.747951 | TASK [bindep : Look for bindep.txt] 2025-12-05 15:34:09.186453 | controller | ok 2025-12-05 15:34:09.193375 | 2025-12-05 15:34:09.193450 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:09.222610 | controller | ok 2025-12-05 15:34:09.227915 | 2025-12-05 15:34:09.227978 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 15:34:09.241612 | controller | skipping: Conditional result was False 2025-12-05 15:34:09.247542 | 2025-12-05 15:34:09.247616 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:09.281257 | controller | skipping: Conditional result was False 2025-12-05 15:34:09.287181 | 2025-12-05 15:34:09.287274 | TASK [bindep : Look for bindep fallback file] 2025-12-05 15:34:09.311063 | controller | skipping: Conditional result was False 2025-12-05 15:34:09.316856 | 2025-12-05 15:34:09.316930 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:09.350676 | controller | skipping: Conditional result was False 2025-12-05 15:34:09.356604 | 2025-12-05 15:34:09.356689 | TASK [bindep : Include bindep tasks] 2025-12-05 15:34:09.386637 | controller | ok 2025-12-05 15:34:09.393755 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 15:34:09.401682 | 2025-12-05 15:34:09.401748 | TASK [bindep : Look for bindep command] 2025-12-05 15:34:09.426060 | controller | skipping: Conditional result was False 2025-12-05 15:34:09.432768 | 2025-12-05 15:34:09.432882 | TASK [bindep : Check for system bindep] 2025-12-05 15:34:09.969153 | controller | ok: Runtime: 0:00:00.004962 2025-12-05 15:34:09.982376 | 2025-12-05 15:34:09.982568 | TASK [bindep : Define bindep_command fact] 2025-12-05 15:34:10.009998 | controller | skipping: Conditional result was False 2025-12-05 15:34:10.024263 | 2025-12-05 15:34:10.024417 | TASK [bindep : Include install tasks] 2025-12-05 15:34:10.063256 | controller | ok 2025-12-05 15:34:10.081752 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 15:34:10.099642 | 2025-12-05 15:34:10.099767 | TASK [bindep : Create temp dir for bindep] 2025-12-05 15:34:10.491192 | controller | changed 2025-12-05 15:34:10.503829 | 2025-12-05 15:34:10.503969 | TASK [Ensure we have pip dependencies] 2025-12-05 15:34:10.532875 | controller | ok 2025-12-05 15:34:10.574881 | 2025-12-05 15:34:10.575039 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 10:34:10.871892 | controller | /usr/bin/pip3 2025-12-05 10:34:10.895048 | controller | /usr/bin/python3: No module named wheel 2025-12-05 15:34:11.111384 | controller | ok: Runtime: 0:00:00.034546 2025-12-05 15:34:11.125195 | 2025-12-05 15:34:11.125382 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 15:34:11.165359 | controller | ok: "/var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 15:34:11.189223 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 15:34:11.204580 | 2025-12-05 15:34:11.204690 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 15:34:12.941357 | controller | changed 2025-12-05 15:34:12.949312 | 2025-12-05 15:34:12.949410 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 15:34:12.995685 | controller | skipping: Conditional result was False 2025-12-05 15:34:13.009384 | 2025-12-05 15:34:13.009530 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 15:34:13.079810 | controller | skipping: Conditional result was False 2025-12-05 15:34:13.094599 | 2025-12-05 15:34:13.094774 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 15:34:13.165280 | controller | skipping: Conditional result was False 2025-12-05 15:34:13.186916 | 2025-12-05 15:34:13.187247 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 15:34:13.224505 | controller | skipping: Conditional result was False 2025-12-05 15:34:13.243426 | 2025-12-05 15:34:13.243538 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 15:34:13.786384 | controller | skipping: Conditional result was False 2025-12-05 15:34:13.800226 | 2025-12-05 15:34:13.800413 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 15:34:13.828582 | controller | skipping: Conditional result was False 2025-12-05 15:34:13.842460 | 2025-12-05 15:34:13.842604 | TASK [ensure-pip : Install pip from source] 2025-12-05 15:34:13.869496 | controller | skipping: Conditional result was False 2025-12-05 15:34:13.885404 | 2025-12-05 15:34:13.885557 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 10:34:14.215547 | controller | /usr/bin/python3 2025-12-05 15:34:14.432848 | controller | ok: Runtime: 0:00:00.005325 2025-12-05 15:34:14.447965 | 2025-12-05 15:34:14.448171 | TASK [ensure-pip : Set host default] 2025-12-05 15:34:14.515585 | controller | ok 2025-12-05 15:34:14.535765 | 2025-12-05 15:34:14.535943 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 15:34:14.597852 | controller | ok 2025-12-05 15:34:14.612065 | 2025-12-05 15:34:14.612207 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 15:34:19.313343 | controller | changed 2025-12-05 15:34:19.318875 | 2025-12-05 15:34:19.318940 | TASK [bindep : Define bindep_command] 2025-12-05 15:34:19.368571 | controller | ok 2025-12-05 15:34:19.374220 | 2025-12-05 15:34:19.374281 | LOOP [bindep : Include package tasks] 2025-12-05 15:34:19.424746 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 15:34:19.424923 | controller | ok: All items complete 2025-12-05 15:34:19.424949 | 2025-12-05 15:34:19.439119 | controller | included: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 15:34:19.450111 | 2025-12-05 15:34:19.450191 | TASK [bindep : Define bindep_run fact] 2025-12-05 15:34:19.479184 | controller | ok 2025-12-05 15:34:19.484267 | 2025-12-05 15:34:19.484329 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 10:34:21.242616 | controller | podman 2025-12-05 10:34:21.282803 | controller | python3-jmespath 2025-12-05 10:34:21.282902 | controller | python3-libvirt 2025-12-05 10:34:21.282910 | controller | python3-lxml 2025-12-05 10:34:21.282920 | controller | python3-netaddr 2025-12-05 15:34:21.517195 | controller | ok: Runtime: 0:00:01.563992 2025-12-05 15:34:21.524849 | 2025-12-05 15:34:21.524937 | TASK [bindep : Install distro packages from bindep] 2025-12-05 15:35:30.403148 | controller | changed 2025-12-05 15:35:30.412230 | 2025-12-05 15:35:30.412337 | TASK [bindep : Check that packages are installed] 2025-12-05 15:35:32.453235 | controller | ok: Runtime: 0:00:01.534513 2025-12-05 15:35:32.459104 | 2025-12-05 15:35:32.459194 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 15:35:32.493345 | controller | skipping: Conditional result was False 2025-12-05 15:35:32.508180 | 2025-12-05 15:35:32.508690 | TASK [Run test-setup role] 2025-12-05 15:35:32.545088 | controller | ok 2025-12-05 15:35:32.574966 | 2025-12-05 15:35:32.575179 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 15:35:32.832446 | controller | ok 2025-12-05 15:35:32.840663 | 2025-12-05 15:35:32.840749 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 15:35:33.415667 | controller | skipping: Conditional result was False 2025-12-05 15:35:33.445426 | 2025-12-05 15:35:33.445575 | TASK [bindep : Remove bindep temp dir] 2025-12-05 15:35:33.783912 | controller | ok 2025-12-05 15:35:33.828452 | 2025-12-05 15:35:33.828574 | PLAY RECAP 2025-12-05 15:35:33.828622 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 15:35:33.828644 | 2025-12-05 15:35:33.941044 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:35:33.941900 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:35:34.722524 | 2025-12-05 15:35:34.722664 | PLAY [all] 2025-12-05 15:35:34.754178 | 2025-12-05 15:35:34.754285 | TASK [Abort when test_command variable is undefined] 2025-12-05 15:35:34.779227 | controller | skipping: Conditional result was False 2025-12-05 15:35:34.785498 | 2025-12-05 15:35:34.785579 | TASK [Convert test_command to list] 2025-12-05 15:35:34.832372 | controller | skipping: Conditional result was False 2025-12-05 15:35:34.843940 | 2025-12-05 15:35:34.844044 | TASK [Use test_command list] 2025-12-05 15:35:34.933963 | controller | ok 2025-12-05 15:35:34.939569 | 2025-12-05 15:35:34.939634 | LOOP [Run test_command] 2025-12-05 15:35:35.360154 | controller | no check to run 2025-12-05 15:35:35.360331 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006081 2025-12-05 15:35:35.405415 | 2025-12-05 15:35:35.405519 | PLAY RECAP 2025-12-05 15:35:35.405561 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:35:35.405586 | 2025-12-05 15:35:35.537362 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:35:35.538255 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:35:36.503139 | 2025-12-05 15:35:36.503273 | PLAY [all] 2025-12-05 15:35:36.526240 | 2025-12-05 15:35:36.526395 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 15:35:36.883540 | controller | changed: non-zero return code 2025-12-05 15:35:36.889905 | 2025-12-05 15:35:36.889992 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 15:35:36.932419 | controller | skipping: Conditional result was False 2025-12-05 15:35:36.938459 | 2025-12-05 15:35:36.938562 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 15:35:37.011301 | 2025-12-05 15:35:37.011439 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 15:35:37.062107 | 2025-12-05 15:35:37.062302 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 15:35:37.111399 | controller | skipping: Conditional result was False 2025-12-05 15:35:37.118811 | 2025-12-05 15:35:37.118898 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 15:35:37.199696 | 2025-12-05 15:35:37.199843 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 15:35:37.238565 | controller | skipping: Conditional result was False 2025-12-05 15:35:37.244662 | 2025-12-05 15:35:37.244730 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 15:35:37.283115 | controller | skipping: Conditional result was False 2025-12-05 15:35:37.288783 | 2025-12-05 15:35:37.288846 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 15:35:37.322830 | controller | skipping: Conditional result was False 2025-12-05 15:35:37.368102 | 2025-12-05 15:35:37.368234 | PLAY RECAP 2025-12-05 15:35:37.368283 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 15:35:37.368303 | 2025-12-05 15:35:37.502432 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:35:37.503289 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:35:38.270962 | 2025-12-05 15:35:38.271116 | PLAY [all] 2025-12-05 15:35:38.295099 | 2025-12-05 15:35:38.295234 | TASK [include_role : fetch-output] 2025-12-05 15:35:38.345770 | controller | ok 2025-12-05 15:35:38.370211 | 2025-12-05 15:35:38.370360 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 15:35:38.455573 | controller | skipping: Conditional result was False 2025-12-05 15:35:38.468690 | 2025-12-05 15:35:38.468806 | TASK [fetch-output : Set log path for single node] 2025-12-05 15:35:38.562943 | controller | ok 2025-12-05 15:35:38.577675 | 2025-12-05 15:35:38.577806 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 15:35:39.263281 | controller -> localhost | ok: "/var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/logs" 2025-12-05 15:35:39.583859 | controller -> localhost | changed: "/var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/artifacts" 2025-12-05 15:35:39.980917 | controller -> localhost | changed: "/var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/docs" 2025-12-05 15:35:39.994169 | 2025-12-05 15:35:39.994297 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 15:35:40.892356 | controller | changed: .d..t...... ./ 2025-12-05 15:35:40.892572 | controller | changed: All items complete 2025-12-05 15:35:40.892600 | 2025-12-05 15:35:42.064340 | controller | changed: .d..t...... ./ 2025-12-05 15:35:43.083882 | controller | changed: .d..t...... ./ 2025-12-05 15:35:43.102768 | 2025-12-05 15:35:43.102888 | TASK [include_role : fetch-output-openshift] 2025-12-05 15:35:43.139777 | controller | skipping: Conditional result was False 2025-12-05 15:35:43.152379 | 2025-12-05 15:35:43.152500 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 15:35:44.280319 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.015215 2025-12-05 15:35:44.745988 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014192 2025-12-05 15:35:44.872307 | 2025-12-05 15:35:44.872449 | PLAY [all] 2025-12-05 15:35:44.924986 | 2025-12-05 15:35:44.925150 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 15:35:46.037666 | controller | changed 2025-12-05 15:35:46.084147 | 2025-12-05 15:35:46.084247 | PLAY RECAP 2025-12-05 15:35:46.084296 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:35:46.084318 | 2025-12-05 15:35:46.248110 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:35:46.251129 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 15:35:47.469721 | 2025-12-05 15:35:47.469858 | PLAY [localhost] 2025-12-05 15:35:47.488245 | 2025-12-05 15:35:47.488359 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 15:35:48.139735 | localhost | changed 2025-12-05 15:35:48.148624 | 2025-12-05 15:35:48.148776 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 15:35:48.199865 | localhost | ok 2025-12-05 15:35:48.217058 | 2025-12-05 15:35:48.217192 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 15:35:48.985901 | localhost | changed 2025-12-05 15:35:48.990851 | 2025-12-05 15:35:48.990928 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 15:35:49.892915 | localhost | changed 2025-12-05 15:35:49.898495 | 2025-12-05 15:35:49.898560 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 15:35:50.535152 | localhost | Identity added: /var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/tmp/ansible.gdw15e7s (/var/lib/zuul/builds/963d163510234aa1aed22ebe3de5cfe3/work/tmp/ansible.gdw15e7s) 2025-12-05 15:35:50.535348 | localhost | ok: Runtime: 0:00:00.008482 2025-12-05 15:35:50.539894 | 2025-12-05 15:35:50.539960 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 15:35:50.874740 | localhost | ok: Runtime: 0:00:00.005704 2025-12-05 15:35:50.880977 | 2025-12-05 15:35:50.895078 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 15:35:50.968810 | localhost | changed 2025-12-05 15:35:50.973565 | 2025-12-05 15:35:50.973630 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 15:35:51.483084 | localhost | changed 2025-12-05 15:35:51.560993 | 2025-12-05 15:35:51.561217 | PLAY [localhost] 2025-12-05 15:35:51.588903 | 2025-12-05 15:35:51.589052 | TASK [Generate bulk log download script] 2025-12-05 15:35:51.609084 | localhost | ok 2025-12-05 15:35:51.626332 | 2025-12-05 15:35:51.626436 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 15:35:51.668322 | localhost | ok: All assertions passed 2025-12-05 15:35:51.673611 | 2025-12-05 15:35:51.673675 | TASK [local-log-download : Create download script] 2025-12-05 15:35:52.140552 | localhost -> localhost | changed 2025-12-05 15:35:52.196955 | 2025-12-05 15:35:52.197102 | TASK [Register quick-download link] 2025-12-05 15:35:52.216265 | localhost | ok 2025-12-05 15:35:52.235917 | 2025-12-05 15:35:52.236059 | PLAY [logserver.rdoproject.org] 2025-12-05 15:35:52.246630 | 2025-12-05 15:35:52.246695 | TASK [Set zuul-log-path fact] 2025-12-05 15:35:52.274224 | logserver.rdoproject.org | ok 2025-12-05 15:35:52.284597 | 2025-12-05 15:35:52.284666 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:35:52.321260 | logserver.rdoproject.org | ok 2025-12-05 15:35:52.327058 | 2025-12-05 15:35:52.327123 | TASK [upload-logs : Create log directories] 2025-12-05 15:35:53.020316 | logserver.rdoproject.org | changed 2025-12-05 15:35:53.024419 | 2025-12-05 15:35:53.024724 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 15:35:53.530140 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.018824 2025-12-05 15:35:53.535299 | 2025-12-05 15:35:53.535367 | TASK [upload-logs : Upload logs to log server] 2025-12-05 15:35:54.493618 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 15:35:54.496667 | 2025-12-05 15:35:54.496730 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 15:35:54.591489 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.592352 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.596837 | 2025-12-05 15:35:54.596974 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 15:35:54.695651 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.695864 | 2025-12-05 15:35:54.696505 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.707552 | 2025-12-05 15:35:54.707677 | LOOP [upload-logs : Upload console log and json output]