2025-12-17 16:19:45.147370 | Job console starting... 2025-12-17 16:19:45.157215 | Updating repositories 2025-12-17 16:19:45.182394 | Preparing job workspace 2025-12-17 16:20:00.269221 | Running Ansible setup... 2025-12-17 16:20:04.109375 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-17 16:20:04.657772 | 2025-12-17 16:20:04.657892 | PLAY [localhost] 2025-12-17 16:20:04.666895 | 2025-12-17 16:20:04.666986 | TASK [Gathering Facts] 2025-12-17 16:20:05.595503 | localhost | ok 2025-12-17 16:20:05.609844 | 2025-12-17 16:20:05.609961 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-17 16:20:06.009091 | localhost -> localhost | changed 2025-12-17 16:20:06.015315 | 2025-12-17 16:20:06.015389 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-17 16:20:06.905906 | localhost -> localhost | changed 2025-12-17 16:20:06.916542 | 2025-12-17 16:20:06.916798 | TASK [Setup log path fact] 2025-12-17 16:20:06.938472 | localhost | ok 2025-12-17 16:20:06.951251 | 2025-12-17 16:20:06.951349 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-17 16:20:06.988193 | localhost | ok 2025-12-17 16:20:06.999119 | 2025-12-17 16:20:06.999223 | TASK [emit-job-header : Print job information] 2025-12-17 16:20:07.040443 | # Job Information 2025-12-17 16:20:07.040649 | Ansible Version: 2.15.12 2025-12-17 16:20:07.040687 | Job: cifmw-molecule-ovirt 2025-12-17 16:20:07.040715 | Pipeline: github-check 2025-12-17 16:20:07.040822 | Executor: ze03.softwarefactory-project.io 2025-12-17 16:20:07.040852 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451 2025-12-17 16:20:07.040879 | Log URL (when completed): https://logserver.rdoproject.org/3a8/rdoproject.org/3a8654955e844a1fa5b526e2f817a383/ 2025-12-17 16:20:07.040903 | Event ID: 9a909fe0-db63-11f0-8247-ccb7108525bc 2025-12-17 16:20:07.046327 | 2025-12-17 16:20:07.046416 | LOOP [emit-job-header : Print node information] 2025-12-17 16:20:07.154808 | localhost | ok: 2025-12-17 16:20:07.155199 | localhost | # Node Information 2025-12-17 16:20:07.155418 | localhost | Inventory Hostname: controller 2025-12-17 16:20:07.155448 | localhost | Hostname: np0005564336 2025-12-17 16:20:07.155474 | localhost | Username: zuul 2025-12-17 16:20:07.155501 | localhost | Distro: CentOS 9 2025-12-17 16:20:07.155526 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-17 16:20:07.155550 | localhost | Region: RegionOne 2025-12-17 16:20:07.155575 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-17 16:20:07.155598 | localhost | Product Name: OpenStack Nova 2025-12-17 16:20:07.155622 | localhost | Interface IP: 38.102.83.236 2025-12-17 16:20:07.191611 | 2025-12-17 16:20:07.191757 | PLAY [all] 2025-12-17 16:20:07.201593 | 2025-12-17 16:20:07.201764 | TASK [Gather network facts] 2025-12-17 16:20:07.634676 | controller | ok 2025-12-17 16:20:07.656211 | 2025-12-17 16:20:07.656303 | TASK [include_role : start-zuul-console] 2025-12-17 16:20:07.678065 | controller | ok 2025-12-17 16:20:07.693784 | 2025-12-17 16:20:07.693921 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-17 16:20:08.136448 | controller | ok 2025-12-17 16:20:08.150681 | 2025-12-17 16:20:08.150832 | TASK [include_role : add-build-sshkey] 2025-12-17 16:20:08.183391 | controller | ok 2025-12-17 16:20:08.208265 | 2025-12-17 16:20:08.208376 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-17 16:20:08.472331 | controller -> localhost | ok 2025-12-17 16:20:08.479166 | 2025-12-17 16:20:08.479272 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-17 16:20:08.508287 | controller | ok 2025-12-17 16:20:08.522995 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-17 16:20:08.529963 | 2025-12-17 16:20:08.530071 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-17 16:20:09.197792 | controller -> localhost | Generating public/private rsa key pair. 2025-12-17 16:20:09.198061 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/3a8654955e844a1fa5b526e2f817a383_id_rsa. 2025-12-17 16:20:09.198107 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/3a8654955e844a1fa5b526e2f817a383_id_rsa.pub. 2025-12-17 16:20:09.198138 | controller -> localhost | The key fingerprint is: 2025-12-17 16:20:09.198167 | controller -> localhost | SHA256:5wcRnRj1l9Avid5Fk+guOyJMnb8dnWnALY1DPgJybno zuul-build-sshkey 2025-12-17 16:20:09.198195 | controller -> localhost | The key's randomart image is: 2025-12-17 16:20:09.198224 | controller -> localhost | +---[RSA 3072]----+ 2025-12-17 16:20:09.198250 | controller -> localhost | | o=.oo .| 2025-12-17 16:20:09.198296 | controller -> localhost | | ..oo.+o| 2025-12-17 16:20:09.198323 | controller -> localhost | | . o. .o.++| 2025-12-17 16:20:09.198348 | controller -> localhost | | + ..=.*.o| 2025-12-17 16:20:09.198373 | controller -> localhost | | So+o.X = | 2025-12-17 16:20:09.198399 | controller -> localhost | | .o= oo.B o| 2025-12-17 16:20:09.198426 | controller -> localhost | | o. Eo +. = | 2025-12-17 16:20:09.198450 | controller -> localhost | | o.. =. o | 2025-12-17 16:20:09.198472 | controller -> localhost | | . ..o. | 2025-12-17 16:20:09.198493 | controller -> localhost | +----[SHA256]-----+ 2025-12-17 16:20:09.198547 | controller -> localhost | ok: Runtime: 0:00:00.219121 2025-12-17 16:20:09.205531 | 2025-12-17 16:20:09.205640 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-17 16:20:09.243123 | controller | ok 2025-12-17 16:20:09.256576 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-17 16:20:09.265378 | 2025-12-17 16:20:09.265469 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-17 16:20:09.289769 | controller | skipping: Conditional result was False 2025-12-17 16:20:09.295368 | 2025-12-17 16:20:09.295452 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-17 16:20:09.730423 | controller | changed 2025-12-17 16:20:09.736320 | 2025-12-17 16:20:09.736395 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-17 16:20:09.970606 | controller | ok 2025-12-17 16:20:09.976274 | 2025-12-17 16:20:09.976366 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-17 16:20:10.739593 | controller | changed 2025-12-17 16:20:10.751119 | 2025-12-17 16:20:10.751221 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-17 16:20:11.525108 | controller | changed 2025-12-17 16:20:11.537931 | 2025-12-17 16:20:11.538098 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-17 16:20:11.580029 | controller | skipping: Conditional result was False 2025-12-17 16:20:11.592228 | 2025-12-17 16:20:11.594805 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-17 16:20:11.981200 | controller -> localhost | changed 2025-12-17 16:20:11.991903 | 2025-12-17 16:20:11.992006 | TASK [add-build-sshkey : Add back temp key] 2025-12-17 16:20:12.248054 | controller -> localhost | Identity added: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/3a8654955e844a1fa5b526e2f817a383_id_rsa (zuul-build-sshkey) 2025-12-17 16:20:12.248230 | controller -> localhost | ok: Runtime: 0:00:00.008097 2025-12-17 16:20:12.253784 | 2025-12-17 16:20:12.253857 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-17 16:20:12.690722 | controller | ok 2025-12-17 16:20:12.696334 | 2025-12-17 16:20:12.696406 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-17 16:20:12.720652 | controller | skipping: Conditional result was False 2025-12-17 16:20:12.732133 | 2025-12-17 16:20:12.732247 | TASK [include_role : validate-host] 2025-12-17 16:20:12.763336 | controller | ok 2025-12-17 16:20:12.791412 | 2025-12-17 16:20:12.791545 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-17 16:20:12.831636 | controller | ok 2025-12-17 16:20:12.836434 | 2025-12-17 16:20:12.836512 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-17 16:20:13.106500 | controller -> localhost | ok 2025-12-17 16:20:13.112573 | 2025-12-17 16:20:13.112636 | TASK [validate-host : Collect information about the host] 2025-12-17 16:20:13.842830 | controller | ok 2025-12-17 16:20:13.851439 | 2025-12-17 16:20:13.851505 | TASK [validate-host : Sanitize hostname] 2025-12-17 16:20:13.902256 | controller | ok 2025-12-17 16:20:13.908280 | 2025-12-17 16:20:13.908347 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-17 16:20:14.424819 | controller -> localhost | changed 2025-12-17 16:20:14.430705 | 2025-12-17 16:20:14.430948 | TASK [validate-host : Collect information about zuul worker] 2025-12-17 16:20:14.887367 | controller | ok 2025-12-17 16:20:14.896625 | 2025-12-17 16:20:14.901185 | TASK [validate-host : Write out all zuul information for each host] 2025-12-17 16:20:15.303950 | controller -> localhost | changed 2025-12-17 16:20:15.315177 | 2025-12-17 16:20:15.315327 | TASK [include_role : prepare-workspace-openshift] 2025-12-17 16:20:15.340537 | controller | skipping: Conditional result was False 2025-12-17 16:20:15.347255 | 2025-12-17 16:20:15.347340 | TASK [include_role : remove-zuul-sshkey] 2025-12-17 16:20:15.373416 | controller | skipping: Conditional result was False 2025-12-17 16:20:15.379766 | 2025-12-17 16:20:15.380064 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-17 16:20:15.612130 | controller | ok: "logs" 2025-12-17 16:20:15.612363 | controller | ok: All items complete 2025-12-17 16:20:15.612390 | 2025-12-17 16:20:15.814207 | controller | ok: "artifacts" 2025-12-17 16:20:16.050263 | controller | ok: "docs" 2025-12-17 16:20:16.062403 | 2025-12-17 16:20:16.062522 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-17 16:20:16.295982 | controller | changed: "logs" 2025-12-17 16:20:16.541201 | controller | changed: "artifacts" 2025-12-17 16:20:16.765410 | controller | changed: "docs" 2025-12-17 16:20:16.810368 | 2025-12-17 16:20:16.810479 | PLAY RECAP 2025-12-17 16:20:16.810525 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-17 16:20:16.810551 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-17 16:20:16.810570 | 2025-12-17 16:20:17.004781 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-17 16:20:17.005589 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-17 16:20:17.635304 | 2025-12-17 16:20:17.635413 | PLAY [localhost] 2025-12-17 16:20:17.652144 | 2025-12-17 16:20:17.653085 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-17 16:20:18.095230 | localhost | ok 2025-12-17 16:20:18.101477 | 2025-12-17 16:20:18.101572 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-17 16:20:18.857778 | localhost | changed 2025-12-17 16:20:18.894831 | 2025-12-17 16:20:18.895318 | PLAY [all] 2025-12-17 16:20:18.937500 | 2025-12-17 16:20:18.937639 | TASK [include_role : prepare-workspace] 2025-12-17 16:20:18.972161 | controller | ok 2025-12-17 16:20:18.994494 | 2025-12-17 16:20:18.994613 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-17 16:20:19.471450 | controller | ok 2025-12-17 16:20:19.484686 | 2025-12-17 16:20:19.484909 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-17 16:20:23.027850 | controller | Output suppressed because no_log was given 2025-12-17 16:20:23.042506 | 2025-12-17 16:20:23.042604 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-17 16:20:23.399973 | controller | changed: "logs" 2025-12-17 16:20:23.615301 | controller | changed: "artifacts" 2025-12-17 16:20:23.802128 | controller | changed: "docs" 2025-12-17 16:20:23.817369 | 2025-12-17 16:20:23.817479 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-17 16:20:24.062488 | controller | changed: "logs" 2025-12-17 16:20:24.062926 | controller | changed: All items complete 2025-12-17 16:20:24.062987 | 2025-12-17 16:20:24.296488 | controller | changed: "artifacts" 2025-12-17 16:20:24.505924 | controller | changed: "docs" 2025-12-17 16:20:24.538428 | 2025-12-17 16:20:24.538562 | TASK [Check if worker can sudo] 2025-12-17 16:20:25.083160 | controller | ok: Runtime: 0:00:00.034534 2025-12-17 16:20:25.089717 | 2025-12-17 16:20:25.089814 | TASK [configure-mirrors : Gather needed facts] 2025-12-17 16:20:25.200193 | controller | skipping: Conditional result was False 2025-12-17 16:20:25.258778 | 2025-12-17 16:20:25.258903 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-17 16:20:25.321592 | controller | ok 2025-12-17 16:20:25.330197 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-17 16:20:25.335764 | 2025-12-17 16:20:25.335827 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-17 16:20:25.598215 | controller | ok 2025-12-17 16:20:25.604591 | 2025-12-17 16:20:25.604655 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-17 16:20:25.701924 | controller | ok: "/var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-17 16:20:25.720649 | 2025-12-17 16:20:25.720878 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-17 16:20:26.731512 | controller | changed 2025-12-17 16:20:26.741673 | 2025-12-17 16:20:26.741837 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-17 16:20:26.807094 | controller | ok: "/var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-17 16:20:26.807309 | controller | ok: All items complete 2025-12-17 16:20:26.807336 | 2025-12-17 16:20:26.864123 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-17 16:20:26.870839 | 2025-12-17 16:20:26.870927 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-17 16:20:27.706285 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-17 16:20:28.480014 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-17 16:20:28.499634 | 2025-12-17 16:20:28.499815 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-17 16:20:28.944668 | controller | changed: section and option added 2025-12-17 16:20:28.977980 | 2025-12-17 16:20:28.978090 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-17 16:20:29.554252 | controller | 29 files removed 2025-12-17 16:20:29.554453 | controller | ok: Item: dnf clean all Runtime: 0:00:00.271789 2025-12-17 16:20:29.554494 | controller | changed: All items complete 2025-12-17 16:20:29.554516 | 2025-12-17 16:20:40.735473 | 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-17 16:20:40.735577 | controller | DNF version: 4.14.0 2025-12-17 16:20:40.735608 | controller | cachedir: /var/cache/dnf 2025-12-17 16:20:40.735630 | controller | Making cache files for all metadata files. 2025-12-17 16:20:40.735650 | controller | baseos: has expired and will be refreshed. 2025-12-17 16:20:40.735668 | controller | appstream: has expired and will be refreshed. 2025-12-17 16:20:40.735686 | controller | crb: has expired and will be refreshed. 2025-12-17 16:20:40.735713 | controller | extras-common: has expired and will be refreshed. 2025-12-17 16:20:40.735918 | controller | repo: downloading from remote: baseos 2025-12-17 16:20:40.735947 | controller | CentOS Stream 9 - BaseOS 74 MB/s | 8.8 MB 00:00 2025-12-17 16:20:40.736089 | controller | baseos: using metadata from Mon 15 Dec 2025 11:30:30 AM EST. 2025-12-17 16:20:40.736116 | controller | repo: downloading from remote: appstream 2025-12-17 16:20:40.736136 | controller | CentOS Stream 9 - AppStream 98 MB/s | 26 MB 00:00 2025-12-17 16:20:40.736154 | controller | appstream: using metadata from Mon 15 Dec 2025 11:33:53 AM EST. 2025-12-17 16:20:40.736172 | controller | repo: downloading from remote: crb 2025-12-17 16:20:40.736190 | controller | CentOS Stream 9 - CRB 73 MB/s | 7.4 MB 00:00 2025-12-17 16:20:40.736208 | controller | crb: using metadata from Mon 15 Dec 2025 11:38:02 AM EST. 2025-12-17 16:20:40.736225 | controller | repo: downloading from remote: extras-common 2025-12-17 16:20:40.736243 | controller | CentOS Stream 9 - Extras packages 1.6 MB/s | 20 kB 00:00 2025-12-17 16:20:40.736261 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-17 16:20:40.736301 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-17 16:20:40.736321 | controller | Completion plugin: Generating completion cache... 2025-12-17 16:20:40.736339 | controller | Metadata cache created. 2025-12-17 16:20:40.736367 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.929120 2025-12-17 16:20:40.782036 | 2025-12-17 16:20:40.782132 | PLAY RECAP 2025-12-17 16:20:40.782188 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-17 16:20:40.782229 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-17 16:20:40.782260 | 2025-12-17 16:20:40.924798 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-17 16:20:40.927428 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-17 16:20:41.501638 | 2025-12-17 16:20:41.501765 | PLAY [all] 2025-12-17 16:20:41.523473 | 2025-12-17 16:20:41.523564 | TASK [Install binary dependencies] 2025-12-17 16:20:41.595934 | controller | ok 2025-12-17 16:20:41.625583 | 2025-12-17 16:20:41.625718 | TASK [bindep : Include find tasks] 2025-12-17 16:20:41.658043 | controller | ok 2025-12-17 16:20:41.668411 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-17 16:20:41.677279 | 2025-12-17 16:20:41.677371 | TASK [bindep : Look for bindep.txt] 2025-12-17 16:20:42.119526 | controller | ok 2025-12-17 16:20:42.127920 | 2025-12-17 16:20:42.128017 | TASK [bindep : Define bindep_file fact] 2025-12-17 16:20:42.160807 | controller | ok 2025-12-17 16:20:42.166585 | 2025-12-17 16:20:42.166651 | TASK [bindep : Look for other-requirements.txt] 2025-12-17 16:20:42.191230 | controller | skipping: Conditional result was False 2025-12-17 16:20:42.197230 | 2025-12-17 16:20:42.197337 | TASK [bindep : Define bindep_file fact] 2025-12-17 16:20:42.222330 | controller | skipping: Conditional result was False 2025-12-17 16:20:42.228918 | 2025-12-17 16:20:42.228992 | TASK [bindep : Look for bindep fallback file] 2025-12-17 16:20:42.253045 | controller | skipping: Conditional result was False 2025-12-17 16:20:42.258960 | 2025-12-17 16:20:42.259032 | TASK [bindep : Define bindep_file fact] 2025-12-17 16:20:42.283009 | controller | skipping: Conditional result was False 2025-12-17 16:20:42.293002 | 2025-12-17 16:20:42.293090 | TASK [bindep : Include bindep tasks] 2025-12-17 16:20:42.324880 | controller | ok 2025-12-17 16:20:42.334542 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-17 16:20:42.346226 | 2025-12-17 16:20:42.346312 | TASK [bindep : Look for bindep command] 2025-12-17 16:20:42.370496 | controller | skipping: Conditional result was False 2025-12-17 16:20:42.376953 | 2025-12-17 16:20:42.377022 | TASK [bindep : Check for system bindep] 2025-12-17 16:20:42.909417 | controller | ok: Runtime: 0:00:00.005388 2025-12-17 16:20:42.915367 | 2025-12-17 16:20:42.915465 | TASK [bindep : Define bindep_command fact] 2025-12-17 16:20:42.941965 | controller | skipping: Conditional result was False 2025-12-17 16:20:42.947970 | 2025-12-17 16:20:42.948035 | TASK [bindep : Include install tasks] 2025-12-17 16:20:42.980313 | controller | ok 2025-12-17 16:20:42.989095 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-17 16:20:42.997884 | 2025-12-17 16:20:42.997947 | TASK [bindep : Create temp dir for bindep] 2025-12-17 16:20:43.358177 | controller | changed 2025-12-17 16:20:43.364929 | 2025-12-17 16:20:43.365042 | TASK [Ensure we have pip dependencies] 2025-12-17 16:20:43.410153 | controller | ok 2025-12-17 16:20:43.452265 | 2025-12-17 16:20:43.452395 | TASK [ensure-pip : Check if pip is installed] 2025-12-17 11:20:43.711744 | controller | /usr/bin/pip3 2025-12-17 11:20:43.732424 | controller | /usr/bin/python3: No module named wheel 2025-12-17 16:20:43.997499 | controller | ok: Runtime: 0:00:00.029734 2025-12-17 16:20:44.003525 | 2025-12-17 16:20:44.003614 | LOOP [ensure-pip : Install pip from packages] 2025-12-17 16:20:44.036863 | controller | ok: "/var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-17 16:20:44.049196 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-17 16:20:44.060314 | 2025-12-17 16:20:44.060416 | TASK [ensure-pip : Install Python 3 pip] 2025-12-17 16:20:45.928678 | controller | changed 2025-12-17 16:20:45.938132 | 2025-12-17 16:20:45.938243 | TASK [ensure-pip : Check for EPEL repository] 2025-12-17 16:20:45.982963 | controller | skipping: Conditional result was False 2025-12-17 16:20:45.993591 | 2025-12-17 16:20:45.993689 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-17 16:20:46.038589 | controller | skipping: Conditional result was False 2025-12-17 16:20:46.045795 | 2025-12-17 16:20:46.045885 | TASK [ensure-pip : Install Python 2 pip] 2025-12-17 16:20:46.090463 | controller | skipping: Conditional result was False 2025-12-17 16:20:46.097839 | 2025-12-17 16:20:46.097961 | TASK [ensure-pip : Ensure setuptools] 2025-12-17 16:20:46.122093 | controller | skipping: Conditional result was False 2025-12-17 16:20:46.130020 | 2025-12-17 16:20:46.130143 | TASK [ensure-pip : Check for ensurepip module] 2025-12-17 16:20:46.662214 | controller | skipping: Conditional result was False 2025-12-17 16:20:46.668915 | 2025-12-17 16:20:46.669121 | TASK [ensure-pip : Ensure python3-venv] 2025-12-17 16:20:46.683832 | controller | skipping: Conditional result was False 2025-12-17 16:20:46.692920 | 2025-12-17 16:20:46.693056 | TASK [ensure-pip : Install pip from source] 2025-12-17 16:20:46.722652 | controller | skipping: Conditional result was False 2025-12-17 16:20:46.729080 | 2025-12-17 16:20:46.729156 | TASK [ensure-pip : Probe for venv python full path] 2025-12-17 11:20:46.992534 | controller | /usr/bin/python3 2025-12-17 16:20:47.270864 | controller | ok: Runtime: 0:00:00.004817 2025-12-17 16:20:47.277155 | 2025-12-17 16:20:47.277237 | TASK [ensure-pip : Set host default] 2025-12-17 16:20:47.357112 | controller | ok 2025-12-17 16:20:47.362331 | 2025-12-17 16:20:47.362400 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-17 16:20:47.444690 | controller | ok 2025-12-17 16:20:47.458993 | 2025-12-17 16:20:47.459115 | TASK [bindep : Install bindep into temporary venv] 2025-12-17 16:20:53.121161 | controller | changed 2025-12-17 16:20:53.133107 | 2025-12-17 16:20:53.133241 | TASK [bindep : Define bindep_command] 2025-12-17 16:20:53.168438 | controller | ok 2025-12-17 16:20:53.178316 | 2025-12-17 16:20:53.178405 | LOOP [bindep : Include package tasks] 2025-12-17 16:20:53.252057 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-17 16:20:53.252230 | controller | ok: All items complete 2025-12-17 16:20:53.252256 | 2025-12-17 16:20:53.282441 | controller | included: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-17 16:20:53.297087 | 2025-12-17 16:20:53.297172 | TASK [bindep : Define bindep_run fact] 2025-12-17 16:20:53.329186 | controller | ok 2025-12-17 16:20:53.335924 | 2025-12-17 16:20:53.336013 | TASK [bindep : Get list of packages to install from bindep] 2025-12-17 11:20:54.630153 | controller | podman 2025-12-17 11:20:54.664204 | controller | python3-jmespath 2025-12-17 11:20:54.664276 | controller | python3-libvirt 2025-12-17 11:20:54.664374 | controller | python3-lxml 2025-12-17 11:20:54.664387 | controller | python3-netaddr 2025-12-17 16:20:54.870629 | controller | ok: Runtime: 0:00:01.078365 2025-12-17 16:20:54.876567 | 2025-12-17 16:20:54.876648 | TASK [bindep : Install distro packages from bindep] 2025-12-17 16:21:55.549973 | controller | changed 2025-12-17 16:21:55.555997 | 2025-12-17 16:21:55.556067 | TASK [bindep : Check that packages are installed] 2025-12-17 16:21:57.086871 | controller | ok: Runtime: 0:00:01.128748 2025-12-17 16:21:57.093163 | 2025-12-17 16:21:57.093299 | TASK [bindep : Fail if we cannot install all packages] 2025-12-17 16:21:57.117347 | controller | skipping: Conditional result was False 2025-12-17 16:21:57.131123 | 2025-12-17 16:21:57.131234 | TASK [Run test-setup role] 2025-12-17 16:21:57.163609 | controller | ok 2025-12-17 16:21:57.188244 | 2025-12-17 16:21:57.188364 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-17 16:21:57.453170 | controller | ok 2025-12-17 16:21:57.458362 | 2025-12-17 16:21:57.458428 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-17 16:21:57.988487 | controller | skipping: Conditional result was False 2025-12-17 16:21:58.007860 | 2025-12-17 16:21:58.007973 | TASK [bindep : Remove bindep temp dir] 2025-12-17 16:21:58.385508 | controller | ok 2025-12-17 16:21:58.398357 | 2025-12-17 16:21:58.398474 | PLAY RECAP 2025-12-17 16:21:58.398550 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-17 16:21:58.398575 | 2025-12-17 16:21:58.613851 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-17 16:21:58.614770 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-17 16:21:59.179595 | 2025-12-17 16:21:59.179739 | PLAY [all] 2025-12-17 16:21:59.199072 | 2025-12-17 16:21:59.199191 | TASK [Abort when test_command variable is undefined] 2025-12-17 16:21:59.243486 | controller | skipping: Conditional result was False 2025-12-17 16:21:59.249381 | 2025-12-17 16:21:59.249499 | TASK [Convert test_command to list] 2025-12-17 16:21:59.284801 | controller | skipping: Conditional result was False 2025-12-17 16:21:59.290321 | 2025-12-17 16:21:59.290419 | TASK [Use test_command list] 2025-12-17 16:21:59.352140 | controller | ok 2025-12-17 16:21:59.357456 | 2025-12-17 16:21:59.357536 | LOOP [Run test_command] 2025-12-17 16:21:59.759642 | controller | no check to run 2025-12-17 16:21:59.759851 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004893 2025-12-17 16:21:59.791994 | 2025-12-17 16:21:59.792096 | PLAY RECAP 2025-12-17 16:21:59.792136 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-17 16:21:59.792156 | 2025-12-17 16:21:59.910583 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-17 16:21:59.911505 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-17 16:22:00.488595 | 2025-12-17 16:22:00.488739 | PLAY [all] 2025-12-17 16:22:00.510916 | 2025-12-17 16:22:00.511047 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-17 16:22:00.897383 | controller | changed: non-zero return code 2025-12-17 16:22:00.902788 | 2025-12-17 16:22:00.902867 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-17 16:22:00.927846 | controller | skipping: Conditional result was False 2025-12-17 16:22:00.933313 | 2025-12-17 16:22:00.933780 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-17 16:22:00.975288 | 2025-12-17 16:22:00.975439 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-17 16:22:01.042082 | 2025-12-17 16:22:01.042280 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-17 16:22:01.072394 | controller | skipping: Conditional result was False 2025-12-17 16:22:01.078709 | 2025-12-17 16:22:01.078920 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-17 16:22:01.112450 | 2025-12-17 16:22:01.112616 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-17 16:22:01.136598 | controller | skipping: Conditional result was False 2025-12-17 16:22:01.142557 | 2025-12-17 16:22:01.142634 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-17 16:22:01.156381 | controller | skipping: Conditional result was False 2025-12-17 16:22:01.165293 | 2025-12-17 16:22:01.165427 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-17 16:22:01.182872 | controller | skipping: Conditional result was False 2025-12-17 16:22:01.210195 | 2025-12-17 16:22:01.210305 | PLAY RECAP 2025-12-17 16:22:01.210349 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-17 16:22:01.210370 | 2025-12-17 16:22:01.310891 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-17 16:22:01.311773 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-17 16:22:01.984063 | 2025-12-17 16:22:01.984218 | PLAY [all] 2025-12-17 16:22:02.017295 | 2025-12-17 16:22:02.017450 | TASK [include_role : fetch-output] 2025-12-17 16:22:02.047832 | controller | ok 2025-12-17 16:22:02.066187 | 2025-12-17 16:22:02.066332 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-17 16:22:02.111166 | controller | skipping: Conditional result was False 2025-12-17 16:22:02.120106 | 2025-12-17 16:22:02.120289 | TASK [fetch-output : Set log path for single node] 2025-12-17 16:22:02.152774 | controller | ok 2025-12-17 16:22:02.158033 | 2025-12-17 16:22:02.158103 | LOOP [fetch-output : Ensure local output dirs] 2025-12-17 16:22:02.572694 | controller -> localhost | ok: "/var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/logs" 2025-12-17 16:22:02.800391 | controller -> localhost | changed: "/var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/artifacts" 2025-12-17 16:22:03.001033 | controller -> localhost | changed: "/var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/docs" 2025-12-17 16:22:03.011109 | 2025-12-17 16:22:03.011190 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-17 16:22:03.650683 | controller | changed: .d..t...... ./ 2025-12-17 16:22:03.651059 | controller | changed: All items complete 2025-12-17 16:22:03.651122 | 2025-12-17 16:22:04.209035 | controller | changed: .d..t...... ./ 2025-12-17 16:22:04.735771 | controller | changed: .d..t...... ./ 2025-12-17 16:22:04.761422 | 2025-12-17 16:22:04.761564 | TASK [include_role : fetch-output-openshift] 2025-12-17 16:22:04.786319 | controller | skipping: Conditional result was False 2025-12-17 16:22:04.793245 | 2025-12-17 16:22:04.793356 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-17 16:22:05.244057 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.021999 2025-12-17 16:22:05.494982 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012070 2025-12-17 16:22:05.535952 | 2025-12-17 16:22:05.536064 | PLAY [all] 2025-12-17 16:22:05.551313 | 2025-12-17 16:22:05.551428 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-17 16:22:06.025234 | controller | changed 2025-12-17 16:22:06.072610 | 2025-12-17 16:22:06.072758 | PLAY RECAP 2025-12-17 16:22:06.072822 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-17 16:22:06.072854 | 2025-12-17 16:22:06.225938 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-17 16:22:06.227656 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-17 16:22:06.916328 | 2025-12-17 16:22:06.916449 | PLAY [localhost] 2025-12-17 16:22:06.935393 | 2025-12-17 16:22:06.935537 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-17 16:22:07.350711 | localhost | changed 2025-12-17 16:22:07.361526 | 2025-12-17 16:22:07.361800 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-17 16:22:07.395410 | localhost | ok 2025-12-17 16:22:07.408644 | 2025-12-17 16:22:07.408865 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-17 16:22:07.798202 | localhost | changed 2025-12-17 16:22:07.803257 | 2025-12-17 16:22:07.803349 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-17 16:22:08.574632 | localhost | changed 2025-12-17 16:22:08.581521 | 2025-12-17 16:22:08.581649 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-17 16:22:09.059751 | localhost | Identity added: /var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/tmp/ansible.qx1zafqk (/var/lib/zuul/builds/3a8654955e844a1fa5b526e2f817a383/work/tmp/ansible.qx1zafqk) 2025-12-17 16:22:09.060079 | localhost | ok: Runtime: 0:00:00.014068 2025-12-17 16:22:09.070317 | 2025-12-17 16:22:09.070426 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-17 16:22:09.377293 | localhost | ok: Runtime: 0:00:00.007996 2025-12-17 16:22:09.385231 | 2025-12-17 16:22:09.385339 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-17 16:22:09.480841 | localhost | changed 2025-12-17 16:22:09.490282 | 2025-12-17 16:22:09.490432 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-17 16:22:09.978100 | localhost | changed 2025-12-17 16:22:09.999781 | 2025-12-17 16:22:09.999892 | PLAY [localhost] 2025-12-17 16:22:10.012675 | 2025-12-17 16:22:10.012809 | TASK [Generate bulk log download script] 2025-12-17 16:22:10.030703 | localhost | ok 2025-12-17 16:22:10.042736 | 2025-12-17 16:22:10.042872 | TASK [local-log-download : Check API endpoint is defined] 2025-12-17 16:22:10.071114 | localhost | ok: All assertions passed 2025-12-17 16:22:10.075802 | 2025-12-17 16:22:10.075876 | TASK [local-log-download : Create download script] 2025-12-17 16:22:10.554911 | localhost -> localhost | changed 2025-12-17 16:22:10.564876 | 2025-12-17 16:22:10.564977 | TASK [Register quick-download link] 2025-12-17 16:22:10.593583 | localhost | ok 2025-12-17 16:22:10.632833 | 2025-12-17 16:22:10.632930 | PLAY [logserver.rdoproject.org] 2025-12-17 16:22:10.642438 | 2025-12-17 16:22:10.642524 | TASK [Set zuul-log-path fact] 2025-12-17 16:22:10.659521 | logserver.rdoproject.org | ok 2025-12-17 16:22:10.668565 | 2025-12-17 16:22:10.668682 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-17 16:22:10.707203 | logserver.rdoproject.org | ok 2025-12-17 16:22:10.712869 | 2025-12-17 16:22:10.712961 | TASK [upload-logs : Create log directories] 2025-12-17 16:22:11.397930 | logserver.rdoproject.org | changed 2025-12-17 16:22:11.426231 | 2025-12-17 16:22:11.426428 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-17 16:22:11.745515 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008334 2025-12-17 16:22:11.750527 | 2025-12-17 16:22:11.750619 | TASK [upload-logs : Upload logs to log server] 2025-12-17 16:22:12.465280 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-17 16:22:12.471442 | 2025-12-17 16:22:12.471600 | LOOP [upload-logs : Compress console log and json output] 2025-12-17 16:22:12.554984 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 16:22:12.574155 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 16:22:12.584478 | 2025-12-17 16:22:12.584669 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-17 16:22:12.653923 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 16:22:12.654191 | 2025-12-17 16:22:12.659264 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 16:22:12.669002 | 2025-12-17 16:22:12.669183 | LOOP [upload-logs : Upload console log and json output]