2025-12-05 15:18:25.724133 | Job console starting... 2025-12-05 15:18:25.732545 | Updating repositories 2025-12-05 15:18:25.763413 | Preparing job workspace 2025-12-05 15:18:29.677152 | Running Ansible setup... 2025-12-05 15:18:33.056943 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:18:33.597894 | 2025-12-05 15:18:33.598006 | PLAY [localhost] 2025-12-05 15:18:33.615981 | 2025-12-05 15:18:33.616052 | TASK [Gathering Facts] 2025-12-05 15:18:34.487246 | localhost | ok 2025-12-05 15:18:34.500971 | 2025-12-05 15:18:34.501046 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 15:18:34.951555 | localhost -> localhost | changed 2025-12-05 15:18:34.957164 | 2025-12-05 15:18:34.957233 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 15:18:35.873368 | localhost -> localhost | changed 2025-12-05 15:18:35.882702 | 2025-12-05 15:18:35.882769 | TASK [Setup log path fact] 2025-12-05 15:18:35.904539 | localhost | ok 2025-12-05 15:18:35.916517 | 2025-12-05 15:18:35.916585 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:18:35.943291 | localhost | ok 2025-12-05 15:18:35.962277 | 2025-12-05 15:18:35.962391 | TASK [emit-job-header : Print job information] 2025-12-05 15:18:35.990072 | # Job Information 2025-12-05 15:18:35.990286 | Ansible Version: 2.15.12 2025-12-05 15:18:35.990314 | Job: cifmw-molecule-ipa 2025-12-05 15:18:35.990333 | Pipeline: github-check 2025-12-05 15:18:35.990351 | Executor: ze04.softwarefactory-project.io 2025-12-05 15:18:35.990368 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539 2025-12-05 15:18:35.990386 | Log URL (when completed): https://logserver.rdoproject.org/90b/rdoproject.org/90bd7a7a785a41eea61c88cecb8f77be/ 2025-12-05 15:18:35.990404 | Event ID: 748a4b40-d1ed-11f0-8510-c0ded0ca5b3b 2025-12-05 15:18:35.995657 | 2025-12-05 15:18:35.995735 | LOOP [emit-job-header : Print node information] 2025-12-05 15:18:36.106218 | localhost | ok: 2025-12-05 15:18:36.106423 | localhost | # Node Information 2025-12-05 15:18:36.106451 | localhost | Inventory Hostname: controller 2025-12-05 15:18:36.106473 | localhost | Hostname: np0005547224 2025-12-05 15:18:36.106492 | localhost | Username: zuul 2025-12-05 15:18:36.106513 | localhost | Distro: CentOS 9 2025-12-05 15:18:36.106531 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 15:18:36.106548 | localhost | Region: RegionOne 2025-12-05 15:18:36.106565 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 15:18:36.106582 | localhost | Product Name: OpenStack Nova 2025-12-05 15:18:36.106604 | localhost | Interface IP: 38.102.83.220 2025-12-05 15:18:36.135124 | 2025-12-05 15:18:36.135198 | PLAY [all] 2025-12-05 15:18:36.143106 | 2025-12-05 15:18:36.143179 | TASK [Gather network facts] 2025-12-05 15:18:36.627555 | controller | ok 2025-12-05 15:18:36.656411 | 2025-12-05 15:18:36.656581 | TASK [include_role : start-zuul-console] 2025-12-05 15:18:36.676593 | controller | ok 2025-12-05 15:18:36.691536 | 2025-12-05 15:18:36.691602 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 15:18:37.131537 | controller | ok 2025-12-05 15:18:37.141725 | 2025-12-05 15:18:37.141786 | TASK [include_role : add-build-sshkey] 2025-12-05 15:18:37.159495 | controller | ok 2025-12-05 15:18:37.176785 | 2025-12-05 15:18:37.176911 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 15:18:37.413453 | controller -> localhost | ok 2025-12-05 15:18:37.419069 | 2025-12-05 15:18:37.419129 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 15:18:37.437800 | controller | ok 2025-12-05 15:18:37.452591 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 15:18:37.458221 | 2025-12-05 15:18:37.458279 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 15:18:38.138731 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 15:18:38.138930 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/90bd7a7a785a41eea61c88cecb8f77be_id_rsa. 2025-12-05 15:18:38.138975 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/90bd7a7a785a41eea61c88cecb8f77be_id_rsa.pub. 2025-12-05 15:18:38.138999 | controller -> localhost | The key fingerprint is: 2025-12-05 15:18:38.139019 | controller -> localhost | SHA256:+f2+bdzksRJop3gIa7RryU7CrDKB79cZKYl4mCb+UUs zuul-build-sshkey 2025-12-05 15:18:38.139037 | controller -> localhost | The key's randomart image is: 2025-12-05 15:18:38.139056 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 15:18:38.139074 | controller -> localhost | | | 2025-12-05 15:18:38.139092 | controller -> localhost | | | 2025-12-05 15:18:38.139110 | controller -> localhost | | | 2025-12-05 15:18:38.139128 | controller -> localhost | | . | 2025-12-05 15:18:38.139146 | controller -> localhost | |.+ . E .S . | 2025-12-05 15:18:38.139164 | controller -> localhost | |*oo B +o . + o ..| 2025-12-05 15:18:38.139181 | controller -> localhost | |+o.. Bo+= = + .++| 2025-12-05 15:18:38.139201 | controller -> localhost | | +. + =B o o o o=| 2025-12-05 15:18:38.139218 | controller -> localhost | | .=+ +o. . .=o.| 2025-12-05 15:18:38.139235 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 15:18:38.139279 | controller -> localhost | ok: Runtime: 0:00:00.238275 2025-12-05 15:18:38.144949 | 2025-12-05 15:18:38.145009 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 15:18:38.163508 | controller | ok 2025-12-05 15:18:38.174010 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 15:18:38.181966 | 2025-12-05 15:18:38.182027 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 15:18:38.196299 | controller | skipping: Conditional result was False 2025-12-05 15:18:38.202318 | 2025-12-05 15:18:38.202380 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 15:18:38.718597 | controller | changed 2025-12-05 15:18:38.723781 | 2025-12-05 15:18:38.723843 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 15:18:38.977326 | controller | ok 2025-12-05 15:18:38.983465 | 2025-12-05 15:18:38.983537 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 15:18:39.832890 | controller | changed 2025-12-05 15:18:39.837727 | 2025-12-05 15:18:39.837787 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 15:18:40.653466 | controller | changed 2025-12-05 15:18:40.658765 | 2025-12-05 15:18:40.658830 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 15:18:40.695863 | controller | skipping: Conditional result was False 2025-12-05 15:18:40.701498 | 2025-12-05 15:18:40.701560 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 15:18:41.466355 | controller -> localhost | changed 2025-12-05 15:18:41.482498 | 2025-12-05 15:18:41.482613 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 15:18:41.810450 | controller -> localhost | Identity added: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/90bd7a7a785a41eea61c88cecb8f77be_id_rsa (zuul-build-sshkey) 2025-12-05 15:18:41.810753 | controller -> localhost | ok: Runtime: 0:00:00.014448 2025-12-05 15:18:41.816825 | 2025-12-05 15:18:41.816885 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 15:18:42.237453 | controller | ok 2025-12-05 15:18:42.243820 | 2025-12-05 15:18:42.243912 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 15:18:42.269017 | controller | skipping: Conditional result was False 2025-12-05 15:18:42.278781 | 2025-12-05 15:18:42.278843 | TASK [include_role : validate-host] 2025-12-05 15:18:42.307778 | controller | ok 2025-12-05 15:18:42.337177 | 2025-12-05 15:18:42.337283 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 15:18:42.405666 | controller | ok 2025-12-05 15:18:42.410191 | 2025-12-05 15:18:42.410263 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 15:18:42.747456 | controller -> localhost | ok 2025-12-05 15:18:42.753341 | 2025-12-05 15:18:42.753404 | TASK [validate-host : Collect information about the host] 2025-12-05 15:18:43.587028 | controller | ok 2025-12-05 15:18:43.601204 | 2025-12-05 15:18:43.601286 | TASK [validate-host : Sanitize hostname] 2025-12-05 15:18:43.662261 | controller | ok 2025-12-05 15:18:43.667105 | 2025-12-05 15:18:43.667178 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 15:18:44.201881 | controller -> localhost | changed 2025-12-05 15:18:44.207475 | 2025-12-05 15:18:44.207578 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 15:18:44.574000 | controller | ok 2025-12-05 15:18:44.579810 | 2025-12-05 15:18:44.579892 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 15:18:45.225970 | controller -> localhost | changed 2025-12-05 15:18:45.235625 | 2025-12-05 15:18:45.235711 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 15:18:45.249543 | controller | skipping: Conditional result was False 2025-12-05 15:18:45.255523 | 2025-12-05 15:18:45.255595 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 15:18:45.271054 | controller | skipping: Conditional result was False 2025-12-05 15:18:45.276357 | 2025-12-05 15:18:45.276422 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:18:45.507573 | controller | ok: "logs" 2025-12-05 15:18:45.507815 | controller | ok: All items complete 2025-12-05 15:18:45.507843 | 2025-12-05 15:18:45.705245 | controller | ok: "artifacts" 2025-12-05 15:18:45.937017 | controller | ok: "docs" 2025-12-05 15:18:45.949312 | 2025-12-05 15:18:45.949412 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:18:46.265698 | controller | changed: "logs" 2025-12-05 15:18:46.471280 | controller | changed: "artifacts" 2025-12-05 15:18:46.730306 | controller | changed: "docs" 2025-12-05 15:18:46.787836 | 2025-12-05 15:18:46.787923 | PLAY RECAP 2025-12-05 15:18:46.787966 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 15:18:46.787997 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:18:46.788031 | 2025-12-05 15:18:47.089303 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:18:47.090100 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:18:48.213210 | 2025-12-05 15:18:48.213306 | PLAY [localhost] 2025-12-05 15:18:48.247215 | 2025-12-05 15:18:48.247304 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 15:18:48.748192 | localhost | ok 2025-12-05 15:18:48.753926 | 2025-12-05 15:18:48.753999 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 15:18:49.637870 | localhost | changed 2025-12-05 15:18:49.680699 | 2025-12-05 15:18:49.680789 | PLAY [all] 2025-12-05 15:18:49.709543 | 2025-12-05 15:18:49.709640 | TASK [include_role : prepare-workspace] 2025-12-05 15:18:49.765332 | controller | ok 2025-12-05 15:18:49.803080 | 2025-12-05 15:18:49.803180 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 15:18:50.435302 | controller | ok 2025-12-05 15:18:50.451705 | 2025-12-05 15:18:50.451782 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 15:18:53.422730 | controller | Output suppressed because no_log was given 2025-12-05 15:18:53.434223 | 2025-12-05 15:18:53.434290 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:18:53.710449 | controller | changed: "logs" 2025-12-05 15:18:53.935992 | controller | changed: "artifacts" 2025-12-05 15:18:54.155424 | controller | changed: "docs" 2025-12-05 15:18:54.168551 | 2025-12-05 15:18:54.168665 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:18:54.460173 | controller | changed: "logs" 2025-12-05 15:18:54.460382 | controller | changed: All items complete 2025-12-05 15:18:54.460483 | 2025-12-05 15:18:54.683926 | controller | changed: "artifacts" 2025-12-05 15:18:54.889308 | controller | changed: "docs" 2025-12-05 15:18:54.905079 | 2025-12-05 15:18:54.905158 | TASK [Check if worker can sudo] 2025-12-05 15:18:55.442736 | controller | ok: Runtime: 0:00:00.033623 2025-12-05 15:18:55.448196 | 2025-12-05 15:18:55.448257 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 15:18:55.581617 | controller | skipping: Conditional result was False 2025-12-05 15:18:55.640335 | 2025-12-05 15:18:55.640456 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 15:18:55.760586 | controller | ok 2025-12-05 15:18:55.777820 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 15:18:55.783158 | 2025-12-05 15:18:55.783215 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 15:18:56.115597 | controller | ok 2025-12-05 15:18:56.121157 | 2025-12-05 15:18:56.121216 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 15:18:56.272424 | controller | ok: "/var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 15:18:56.288820 | 2025-12-05 15:18:56.288927 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 15:18:57.247332 | controller | changed 2025-12-05 15:18:57.260819 | 2025-12-05 15:18:57.262902 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 15:18:57.342799 | controller | ok: "/var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 15:18:57.342965 | controller | ok: All items complete 2025-12-05 15:18:57.342992 | 2025-12-05 15:18:57.399479 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 15:18:57.406312 | 2025-12-05 15:18:57.406373 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 15:18:58.369030 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 15:18:59.259058 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 15:18:59.274864 | 2025-12-05 15:18:59.274988 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 15:18:59.861651 | controller | changed: section and option added 2025-12-05 15:18:59.890205 | 2025-12-05 15:18:59.890280 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 15:19:00.581672 | controller | 29 files removed 2025-12-05 15:19:00.581929 | controller | ok: Item: dnf clean all Runtime: 0:00:00.272019 2025-12-05 15:19:00.581968 | controller | changed: All items complete 2025-12-05 15:19:00.581989 | 2025-12-05 15:19:13.602788 | 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:19:13.603125 | controller | DNF version: 4.14.0 2025-12-05 15:19:13.603193 | controller | cachedir: /var/cache/dnf 2025-12-05 15:19:13.603239 | controller | Making cache files for all metadata files. 2025-12-05 15:19:13.603280 | controller | baseos: has expired and will be refreshed. 2025-12-05 15:19:13.603318 | controller | appstream: has expired and will be refreshed. 2025-12-05 15:19:13.603353 | controller | crb: has expired and will be refreshed. 2025-12-05 15:19:13.603402 | controller | extras-common: has expired and will be refreshed. 2025-12-05 15:19:13.603439 | controller | repo: downloading from remote: baseos 2025-12-05 15:19:13.603475 | controller | CentOS Stream 9 - BaseOS 59 MB/s | 8.8 MB 00:00 2025-12-05 15:19:13.603511 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 15:19:13.603546 | controller | repo: downloading from remote: appstream 2025-12-05 15:19:13.603582 | controller | CentOS Stream 9 - AppStream 51 MB/s | 25 MB 00:00 2025-12-05 15:19:13.603616 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 15:19:13.603651 | controller | repo: downloading from remote: crb 2025-12-05 15:19:13.603731 | controller | CentOS Stream 9 - CRB 11 MB/s | 7.3 MB 00:00 2025-12-05 15:19:13.603775 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 15:19:13.603811 | controller | repo: downloading from remote: extras-common 2025-12-05 15:19:13.603848 | controller | CentOS Stream 9 - Extras packages 16 kB/s | 20 kB 00:01 2025-12-05 15:19:13.603884 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 15:19:13.603919 | controller | Last metadata expiration check: 0:00:01 ago on Fri 05 Dec 2025 10:19:11 AM EST. 2025-12-05 15:19:13.603955 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 15:19:13.603990 | controller | Completion plugin: Generating completion cache... 2025-12-05 15:19:13.604027 | controller | Metadata cache created. 2025-12-05 15:19:13.604079 | controller | ok: Item: dnf makecache -v Runtime: 0:00:12.794406 2025-12-05 15:19:13.643274 | 2025-12-05 15:19:13.643426 | PLAY RECAP 2025-12-05 15:19:13.643506 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 15:19:13.643563 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:19:13.643601 | 2025-12-05 15:19:13.784501 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:19:13.785549 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:19:14.370184 | 2025-12-05 15:19:14.370292 | PLAY [all] 2025-12-05 15:19:14.390779 | 2025-12-05 15:19:14.390860 | TASK [Install binary dependencies] 2025-12-05 15:19:14.462569 | controller | ok 2025-12-05 15:19:14.489896 | 2025-12-05 15:19:14.490007 | TASK [bindep : Include find tasks] 2025-12-05 15:19:14.531660 | controller | ok 2025-12-05 15:19:14.545115 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 15:19:14.559203 | 2025-12-05 15:19:14.559369 | TASK [bindep : Look for bindep.txt] 2025-12-05 15:19:14.942380 | controller | ok 2025-12-05 15:19:14.950916 | 2025-12-05 15:19:14.951006 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:19:14.993880 | controller | ok 2025-12-05 15:19:15.001136 | 2025-12-05 15:19:15.001224 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 15:19:15.025516 | controller | skipping: Conditional result was False 2025-12-05 15:19:15.033038 | 2025-12-05 15:19:15.033132 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:19:15.067922 | controller | skipping: Conditional result was False 2025-12-05 15:19:15.080753 | 2025-12-05 15:19:15.080900 | TASK [bindep : Look for bindep fallback file] 2025-12-05 15:19:15.107747 | controller | skipping: Conditional result was False 2025-12-05 15:19:15.120761 | 2025-12-05 15:19:15.120912 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:19:15.147571 | controller | skipping: Conditional result was False 2025-12-05 15:19:15.160400 | 2025-12-05 15:19:15.160542 | TASK [bindep : Include bindep tasks] 2025-12-05 15:19:15.213020 | controller | ok 2025-12-05 15:19:15.229312 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 15:19:15.247599 | 2025-12-05 15:19:15.247794 | TASK [bindep : Look for bindep command] 2025-12-05 15:19:15.273479 | controller | skipping: Conditional result was False 2025-12-05 15:19:15.281955 | 2025-12-05 15:19:15.282040 | TASK [bindep : Check for system bindep] 2025-12-05 15:19:15.819999 | controller | ok: Runtime: 0:00:00.004660 2025-12-05 15:19:15.834214 | 2025-12-05 15:19:15.834351 | TASK [bindep : Define bindep_command fact] 2025-12-05 15:19:15.872893 | controller | skipping: Conditional result was False 2025-12-05 15:19:15.885522 | 2025-12-05 15:19:15.885738 | TASK [bindep : Include install tasks] 2025-12-05 15:19:15.935703 | controller | ok 2025-12-05 15:19:15.954147 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 15:19:15.978432 | 2025-12-05 15:19:15.978581 | TASK [bindep : Create temp dir for bindep] 2025-12-05 15:19:16.353170 | controller | changed 2025-12-05 15:19:16.365143 | 2025-12-05 15:19:16.365295 | TASK [Ensure we have pip dependencies] 2025-12-05 15:19:16.389332 | controller | ok 2025-12-05 15:19:16.437992 | 2025-12-05 15:19:16.438111 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 10:19:16.747181 | controller | /usr/bin/pip3 2025-12-05 10:19:16.775079 | controller | /usr/bin/python3: No module named wheel 2025-12-05 15:19:16.971967 | controller | ok: Runtime: 0:00:00.040031 2025-12-05 15:19:16.984083 | 2025-12-05 15:19:16.984219 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 15:19:17.010873 | controller | ok: "/var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 15:19:17.038347 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 15:19:17.060090 | 2025-12-05 15:19:17.060177 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 15:19:19.721339 | controller | changed 2025-12-05 15:19:19.727283 | 2025-12-05 15:19:19.727352 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 15:19:19.782515 | controller | skipping: Conditional result was False 2025-12-05 15:19:19.789001 | 2025-12-05 15:19:19.789066 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 15:19:19.823324 | controller | skipping: Conditional result was False 2025-12-05 15:19:19.833803 | 2025-12-05 15:19:19.833892 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 15:19:19.871702 | controller | skipping: Conditional result was False 2025-12-05 15:19:19.879181 | 2025-12-05 15:19:19.879250 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 15:19:19.893058 | controller | skipping: Conditional result was False 2025-12-05 15:19:19.899438 | 2025-12-05 15:19:19.899502 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 15:19:20.428096 | controller | skipping: Conditional result was False 2025-12-05 15:19:20.457160 | 2025-12-05 15:19:20.457352 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 15:19:20.485373 | controller | skipping: Conditional result was False 2025-12-05 15:19:20.494126 | 2025-12-05 15:19:20.494221 | TASK [ensure-pip : Install pip from source] 2025-12-05 15:19:20.509367 | controller | skipping: Conditional result was False 2025-12-05 15:19:20.518987 | 2025-12-05 15:19:20.519078 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 10:19:21.374635 | controller | /usr/bin/python3 2025-12-05 15:19:21.773498 | controller | ok: Runtime: 0:00:00.007424 2025-12-05 15:19:21.781656 | 2025-12-05 15:19:21.781774 | TASK [ensure-pip : Set host default] 2025-12-05 15:19:21.852053 | controller | ok 2025-12-05 15:19:21.857588 | 2025-12-05 15:19:21.857650 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 15:19:21.908527 | controller | ok 2025-12-05 15:19:21.919386 | 2025-12-05 15:19:21.919451 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 15:19:26.046312 | controller | changed 2025-12-05 15:19:26.060013 | 2025-12-05 15:19:26.060143 | TASK [bindep : Define bindep_command] 2025-12-05 15:19:26.099097 | controller | ok 2025-12-05 15:19:26.111133 | 2025-12-05 15:19:26.111255 | LOOP [bindep : Include package tasks] 2025-12-05 15:19:26.194542 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 15:19:26.194769 | controller | ok: All items complete 2025-12-05 15:19:26.194806 | 2025-12-05 15:19:26.215048 | controller | included: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 15:19:26.235275 | 2025-12-05 15:19:26.235363 | TASK [bindep : Define bindep_run fact] 2025-12-05 15:19:26.259241 | controller | ok 2025-12-05 15:19:26.267226 | 2025-12-05 15:19:26.267335 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 10:19:27.683527 | controller | podman 2025-12-05 10:19:27.743686 | controller | python3-jmespath 2025-12-05 10:19:27.743850 | controller | python3-libvirt 2025-12-05 10:19:27.743859 | controller | python3-lxml 2025-12-05 10:19:27.743869 | controller | python3-netaddr 2025-12-05 15:19:27.816360 | controller | ok: Runtime: 0:00:01.175424 2025-12-05 15:19:27.822217 | 2025-12-05 15:19:27.822284 | TASK [bindep : Install distro packages from bindep] 2025-12-05 15:20:37.952730 | controller | changed 2025-12-05 15:20:37.965216 | 2025-12-05 15:20:37.965346 | TASK [bindep : Check that packages are installed] 2025-12-05 15:20:40.014767 | controller | ok: Runtime: 0:00:01.477786 2025-12-05 15:20:40.037885 | 2025-12-05 15:20:40.038023 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 15:20:40.065068 | controller | skipping: Conditional result was False 2025-12-05 15:20:40.079123 | 2025-12-05 15:20:40.079209 | TASK [Run test-setup role] 2025-12-05 15:20:40.110552 | controller | ok 2025-12-05 15:20:40.134160 | 2025-12-05 15:20:40.134247 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 15:20:40.368234 | controller | ok 2025-12-05 15:20:40.375163 | 2025-12-05 15:20:40.375331 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 15:20:40.462644 | controller | skipping: Conditional result was False 2025-12-05 15:20:40.489252 | 2025-12-05 15:20:40.489340 | TASK [bindep : Remove bindep temp dir] 2025-12-05 15:20:40.871863 | controller | ok 2025-12-05 15:20:40.887249 | 2025-12-05 15:20:40.887318 | PLAY RECAP 2025-12-05 15:20:40.887373 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 15:20:40.887401 | 2025-12-05 15:20:40.999444 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:20:41.000333 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:20:41.608629 | 2025-12-05 15:20:41.608757 | PLAY [all] 2025-12-05 15:20:41.628429 | 2025-12-05 15:20:41.628507 | TASK [Abort when test_command variable is undefined] 2025-12-05 15:20:41.663090 | controller | skipping: Conditional result was False 2025-12-05 15:20:41.669031 | 2025-12-05 15:20:41.669106 | TASK [Convert test_command to list] 2025-12-05 15:20:41.723821 | controller | skipping: Conditional result was False 2025-12-05 15:20:41.730537 | 2025-12-05 15:20:41.730608 | TASK [Use test_command list] 2025-12-05 15:20:41.794968 | controller | ok 2025-12-05 15:20:41.800476 | 2025-12-05 15:20:41.800535 | LOOP [Run test_command] 2025-12-05 15:20:42.238418 | controller | no check to run 2025-12-05 15:20:42.238610 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006668 2025-12-05 15:20:42.263526 | 2025-12-05 15:20:42.263631 | PLAY RECAP 2025-12-05 15:20:42.263671 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:20:42.263725 | 2025-12-05 15:20:42.355840 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:20:42.356703 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:20:42.923846 | 2025-12-05 15:20:42.923957 | PLAY [all] 2025-12-05 15:20:42.964378 | 2025-12-05 15:20:42.964481 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 15:20:43.313308 | controller | changed: non-zero return code 2025-12-05 15:20:43.318899 | 2025-12-05 15:20:43.318971 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 15:20:43.342720 | controller | skipping: Conditional result was False 2025-12-05 15:20:43.348467 | 2025-12-05 15:20:43.348536 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 15:20:43.367942 | 2025-12-05 15:20:43.368060 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 15:20:43.386600 | 2025-12-05 15:20:43.386734 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 15:20:43.400060 | controller | skipping: Conditional result was False 2025-12-05 15:20:43.405611 | 2025-12-05 15:20:43.405692 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 15:20:43.424091 | 2025-12-05 15:20:43.424214 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 15:20:43.448209 | controller | skipping: Conditional result was False 2025-12-05 15:20:43.455078 | 2025-12-05 15:20:43.455142 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 15:20:43.468743 | controller | skipping: Conditional result was False 2025-12-05 15:20:43.474203 | 2025-12-05 15:20:43.474265 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 15:20:43.487612 | controller | skipping: Conditional result was False 2025-12-05 15:20:43.509951 | 2025-12-05 15:20:43.510002 | PLAY RECAP 2025-12-05 15:20:43.510042 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 15:20:43.510061 | 2025-12-05 15:20:43.598460 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:20:43.600334 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:20:44.164424 | 2025-12-05 15:20:44.164536 | PLAY [all] 2025-12-05 15:20:44.183178 | 2025-12-05 15:20:44.183271 | TASK [include_role : fetch-output] 2025-12-05 15:20:44.232530 | controller | ok 2025-12-05 15:20:44.250322 | 2025-12-05 15:20:44.250408 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 15:20:44.304669 | controller | skipping: Conditional result was False 2025-12-05 15:20:44.317067 | 2025-12-05 15:20:44.317207 | TASK [fetch-output : Set log path for single node] 2025-12-05 15:20:44.353347 | controller | ok 2025-12-05 15:20:44.364367 | 2025-12-05 15:20:44.364503 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 15:20:44.771902 | controller -> localhost | ok: "/var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/logs" 2025-12-05 15:20:45.000956 | controller -> localhost | changed: "/var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/artifacts" 2025-12-05 15:20:45.225868 | controller -> localhost | changed: "/var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/docs" 2025-12-05 15:20:45.239171 | 2025-12-05 15:20:45.239320 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 15:20:45.890557 | controller | changed: .d..t...... ./ 2025-12-05 15:20:45.890904 | controller | changed: All items complete 2025-12-05 15:20:45.890938 | 2025-12-05 15:20:46.373977 | controller | changed: .d..t...... ./ 2025-12-05 15:20:46.814980 | controller | changed: .d..t...... ./ 2025-12-05 15:20:46.834626 | 2025-12-05 15:20:46.834719 | TASK [include_role : fetch-output-openshift] 2025-12-05 15:20:46.848588 | controller | skipping: Conditional result was False 2025-12-05 15:20:46.855396 | 2025-12-05 15:20:46.855476 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 15:20:47.233270 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007633 2025-12-05 15:20:47.446467 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.022997 2025-12-05 15:20:47.479551 | 2025-12-05 15:20:47.479633 | PLAY [all] 2025-12-05 15:20:47.493766 | 2025-12-05 15:20:47.493833 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 15:20:47.939492 | controller | changed 2025-12-05 15:20:47.961503 | 2025-12-05 15:20:47.961553 | PLAY RECAP 2025-12-05 15:20:47.961590 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:20:47.961610 | 2025-12-05 15:20:48.057631 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:20:48.058453 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 15:20:48.657171 | 2025-12-05 15:20:48.657278 | PLAY [localhost] 2025-12-05 15:20:48.682953 | 2025-12-05 15:20:48.683036 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 15:20:49.010290 | localhost | changed 2025-12-05 15:20:49.015020 | 2025-12-05 15:20:49.015098 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 15:20:49.041325 | localhost | ok 2025-12-05 15:20:49.052948 | 2025-12-05 15:20:49.053019 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 15:20:49.383862 | localhost | changed 2025-12-05 15:20:49.388714 | 2025-12-05 15:20:49.388780 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 15:20:50.014555 | localhost | changed 2025-12-05 15:20:50.025310 | 2025-12-05 15:20:50.025452 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 15:20:50.521293 | localhost | Identity added: /var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/tmp/ansible.uu350t90 (/var/lib/zuul/builds/90bd7a7a785a41eea61c88cecb8f77be/work/tmp/ansible.uu350t90) 2025-12-05 15:20:50.521498 | localhost | ok: Runtime: 0:00:00.020902 2025-12-05 15:20:50.526019 | 2025-12-05 15:20:50.526085 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 15:20:50.779065 | localhost | ok: Runtime: 0:00:00.005293 2025-12-05 15:20:50.785508 | 2025-12-05 15:20:50.785591 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 15:20:50.837444 | localhost | changed 2025-12-05 15:20:50.842327 | 2025-12-05 15:20:50.842390 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 15:20:51.298375 | localhost | changed 2025-12-05 15:20:51.323727 | 2025-12-05 15:20:51.323788 | PLAY [localhost] 2025-12-05 15:20:51.340094 | 2025-12-05 15:20:51.340151 | TASK [Generate bulk log download script] 2025-12-05 15:20:51.368215 | localhost | ok 2025-12-05 15:20:51.380003 | 2025-12-05 15:20:51.380066 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 15:20:51.406924 | localhost | ok: All assertions passed 2025-12-05 15:20:51.411538 | 2025-12-05 15:20:51.411597 | TASK [local-log-download : Create download script] 2025-12-05 15:20:51.813757 | localhost -> localhost | changed 2025-12-05 15:20:51.838363 | 2025-12-05 15:20:51.838493 | TASK [Register quick-download link] 2025-12-05 15:20:51.871946 | localhost | ok 2025-12-05 15:20:51.922318 | 2025-12-05 15:20:51.922419 | PLAY [logserver.rdoproject.org] 2025-12-05 15:20:51.931800 | 2025-12-05 15:20:51.931856 | TASK [Set zuul-log-path fact] 2025-12-05 15:20:51.968117 | logserver.rdoproject.org | ok 2025-12-05 15:20:51.977579 | 2025-12-05 15:20:51.977639 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:20:52.013847 | logserver.rdoproject.org | ok 2025-12-05 15:20:52.019903 | 2025-12-05 15:20:52.019967 | TASK [upload-logs : Create log directories] 2025-12-05 15:20:52.785340 | logserver.rdoproject.org | changed 2025-12-05 15:20:52.788560 | 2025-12-05 15:20:52.788621 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 15:20:53.061510 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.018588 2025-12-05 15:20:53.066322 | 2025-12-05 15:20:53.066383 | TASK [upload-logs : Upload logs to log server] 2025-12-05 15:20:53.682567 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 15:20:53.685462 | 2025-12-05 15:20:53.685522 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 15:20:53.756896 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:20:53.769268 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:20:53.778300 | 2025-12-05 15:20:53.778461 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 15:20:53.828082 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:20:53.828484 | 2025-12-05 15:20:53.831216 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:20:53.842632 | 2025-12-05 15:20:53.842829 | LOOP [upload-logs : Upload console log and json output]