2025-10-13 16:09:28.169000 | Job console starting... 2025-10-13 16:09:28.177593 | Updating repositories 2025-10-13 16:09:28.198769 | Preparing job workspace 2025-10-13 16:09:33.512031 | Running Ansible setup... 2025-10-13 16:09:37.342511 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 16:09:37.909462 | 2025-10-13 16:09:37.909569 | PLAY [localhost] 2025-10-13 16:09:37.917885 | 2025-10-13 16:09:37.917952 | TASK [Gathering Facts] 2025-10-13 16:09:38.825043 | localhost | ok 2025-10-13 16:09:38.838247 | 2025-10-13 16:09:38.838325 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 16:09:39.229044 | localhost -> localhost | changed 2025-10-13 16:09:39.241370 | 2025-10-13 16:09:39.241513 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 16:09:40.057577 | localhost -> localhost | changed 2025-10-13 16:09:40.078065 | 2025-10-13 16:09:40.078214 | TASK [Setup log path fact] 2025-10-13 16:09:40.103384 | localhost | ok 2025-10-13 16:09:40.127936 | 2025-10-13 16:09:40.128027 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 16:09:40.157977 | localhost | ok 2025-10-13 16:09:40.168901 | 2025-10-13 16:09:40.169008 | TASK [emit-job-header : Print job information] 2025-10-13 16:09:40.219262 | # Job Information 2025-10-13 16:09:40.219421 | Ansible Version: 2.15.12 2025-10-13 16:09:40.219456 | Job: cifmw-molecule-cifmw_nfs 2025-10-13 16:09:40.219482 | Pipeline: github-check 2025-10-13 16:09:40.219507 | Executor: ze04.softwarefactory-project.io 2025-10-13 16:09:40.219532 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402 2025-10-13 16:09:40.219558 | Log URL (when completed): https://logserver.rdoproject.org/3aa/rdoproject.org/3aa724cc13be4567afa92007fa605fb2/ 2025-10-13 16:09:40.219583 | Event ID: b0cb8a10-a84e-11f0-9fc4-7f703dfb38e8 2025-10-13 16:09:40.226811 | 2025-10-13 16:09:40.226899 | LOOP [emit-job-header : Print node information] 2025-10-13 16:09:40.333352 | localhost | ok: 2025-10-13 16:09:40.333532 | localhost | # Node Information 2025-10-13 16:09:40.333567 | localhost | Inventory Hostname: controller 2025-10-13 16:09:40.333598 | localhost | Hostname: np0005485758 2025-10-13 16:09:40.333624 | localhost | Username: zuul 2025-10-13 16:09:40.333652 | localhost | Distro: CentOS 9 2025-10-13 16:09:40.333681 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 16:09:40.333730 | localhost | Region: RegionOne 2025-10-13 16:09:40.333755 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 16:09:40.333778 | localhost | Product Name: OpenStack Nova 2025-10-13 16:09:40.333800 | localhost | Interface IP: 38.102.83.142 2025-10-13 16:09:40.365784 | 2025-10-13 16:09:40.365844 | PLAY [all] 2025-10-13 16:09:40.372160 | 2025-10-13 16:09:40.372221 | TASK [Gather network facts] 2025-10-13 16:09:40.850843 | controller | ok 2025-10-13 16:09:40.869214 | 2025-10-13 16:09:40.869309 | TASK [include_role : start-zuul-console] 2025-10-13 16:09:40.887953 | controller | ok 2025-10-13 16:09:40.899531 | 2025-10-13 16:09:40.899603 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 16:09:41.282372 | controller | ok 2025-10-13 16:09:41.291019 | 2025-10-13 16:09:41.291080 | TASK [include_role : add-build-sshkey] 2025-10-13 16:09:41.319623 | controller | ok 2025-10-13 16:09:41.332701 | 2025-10-13 16:09:41.332769 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 16:09:41.571774 | controller -> localhost | ok 2025-10-13 16:09:41.588902 | 2025-10-13 16:09:41.589124 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 16:09:41.617664 | controller | ok 2025-10-13 16:09:41.644490 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 16:09:41.663993 | 2025-10-13 16:09:41.664131 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 16:09:42.280200 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 16:09:42.280509 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/3aa724cc13be4567afa92007fa605fb2_id_rsa. 2025-10-13 16:09:42.280576 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/3aa724cc13be4567afa92007fa605fb2_id_rsa.pub. 2025-10-13 16:09:42.280623 | controller -> localhost | The key fingerprint is: 2025-10-13 16:09:42.280664 | controller -> localhost | SHA256:u+wIpGhTa2DjkuF5xgneRgLK9iA1hegPNND8nCJ9f6I zuul-build-sshkey 2025-10-13 16:09:42.280759 | controller -> localhost | The key's randomart image is: 2025-10-13 16:09:42.280803 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 16:09:42.280842 | controller -> localhost | |o+ .. | 2025-10-13 16:09:42.280882 | controller -> localhost | |.o+. | 2025-10-13 16:09:42.280921 | controller -> localhost | |+.+o . | 2025-10-13 16:09:42.280961 | controller -> localhost | |=+o.= | 2025-10-13 16:09:42.280998 | controller -> localhost | |+@o=.. S | 2025-10-13 16:09:42.281036 | controller -> localhost | |B+&+o o .. | 2025-10-13 16:09:42.281074 | controller -> localhost | |+B.@.. o. | 2025-10-13 16:09:42.281116 | controller -> localhost | |o * E. o . | 2025-10-13 16:09:42.281154 | controller -> localhost | | ..+ | 2025-10-13 16:09:42.281192 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 16:09:42.281273 | controller -> localhost | ok: Runtime: 0:00:00.180460 2025-10-13 16:09:42.293665 | 2025-10-13 16:09:42.294276 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 16:09:42.337269 | controller | ok 2025-10-13 16:09:42.349065 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 16:09:42.356772 | 2025-10-13 16:09:42.356834 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 16:09:42.390976 | controller | skipping: Conditional result was False 2025-10-13 16:09:42.397281 | 2025-10-13 16:09:42.397346 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 16:09:42.870249 | controller | changed 2025-10-13 16:09:42.881336 | 2025-10-13 16:09:42.881477 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 16:09:43.124030 | controller | ok 2025-10-13 16:09:43.135478 | 2025-10-13 16:09:43.135618 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 16:09:44.028898 | controller | changed 2025-10-13 16:09:44.041652 | 2025-10-13 16:09:44.041815 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 16:09:44.846969 | controller | changed 2025-10-13 16:09:44.858122 | 2025-10-13 16:09:44.858263 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 16:09:44.885186 | controller | skipping: Conditional result was False 2025-10-13 16:09:44.898919 | 2025-10-13 16:09:44.899110 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 16:09:45.332801 | controller -> localhost | changed 2025-10-13 16:09:45.342848 | 2025-10-13 16:09:45.342915 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 16:09:45.652725 | controller -> localhost | Identity added: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/3aa724cc13be4567afa92007fa605fb2_id_rsa (zuul-build-sshkey) 2025-10-13 16:09:45.653136 | controller -> localhost | ok: Runtime: 0:00:00.012115 2025-10-13 16:09:45.665403 | 2025-10-13 16:09:45.665536 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 16:09:46.022837 | controller | ok 2025-10-13 16:09:46.027549 | 2025-10-13 16:09:46.027612 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 16:09:46.062203 | controller | skipping: Conditional result was False 2025-10-13 16:09:46.071713 | 2025-10-13 16:09:46.071777 | TASK [include_role : validate-host] 2025-10-13 16:09:46.091103 | controller | ok 2025-10-13 16:09:46.113500 | 2025-10-13 16:09:46.113581 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 16:09:46.152392 | controller | ok 2025-10-13 16:09:46.156856 | 2025-10-13 16:09:46.156916 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 16:09:46.383890 | controller -> localhost | ok 2025-10-13 16:09:46.389558 | 2025-10-13 16:09:46.389627 | TASK [validate-host : Collect information about the host] 2025-10-13 16:09:47.205293 | controller | ok 2025-10-13 16:09:47.223916 | 2025-10-13 16:09:47.224045 | TASK [validate-host : Sanitize hostname] 2025-10-13 16:09:47.301052 | controller | ok 2025-10-13 16:09:47.311585 | 2025-10-13 16:09:47.311748 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 16:09:47.910022 | controller -> localhost | changed 2025-10-13 16:09:47.917600 | 2025-10-13 16:09:47.917698 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 16:09:48.379242 | controller | ok 2025-10-13 16:09:48.391161 | 2025-10-13 16:09:48.391330 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 16:09:48.937590 | controller -> localhost | changed 2025-10-13 16:09:48.947417 | 2025-10-13 16:09:48.947483 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 16:09:48.983188 | controller | skipping: Conditional result was False 2025-10-13 16:09:48.989483 | 2025-10-13 16:09:48.989547 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 16:09:49.014018 | controller | skipping: Conditional result was False 2025-10-13 16:09:49.020256 | 2025-10-13 16:09:49.020323 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 16:09:49.285286 | controller | ok: "logs" 2025-10-13 16:09:49.285499 | controller | ok: All items complete 2025-10-13 16:09:49.285527 | 2025-10-13 16:09:49.536004 | controller | ok: "artifacts" 2025-10-13 16:09:49.744489 | controller | ok: "docs" 2025-10-13 16:09:49.753799 | 2025-10-13 16:09:49.753915 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 16:09:50.033978 | controller | changed: "logs" 2025-10-13 16:09:50.272221 | controller | changed: "artifacts" 2025-10-13 16:09:50.510339 | controller | changed: "docs" 2025-10-13 16:09:50.555488 | 2025-10-13 16:09:50.555627 | PLAY RECAP 2025-10-13 16:09:50.555713 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 16:09:50.555756 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 16:09:50.555783 | 2025-10-13 16:09:50.673842 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 16:09:50.674896 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 16:09:51.272811 | 2025-10-13 16:09:51.272913 | PLAY [localhost] 2025-10-13 16:09:51.288666 | 2025-10-13 16:09:51.288771 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 16:09:51.713144 | localhost | ok 2025-10-13 16:09:51.719282 | 2025-10-13 16:09:51.719372 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 16:09:52.372871 | localhost | changed 2025-10-13 16:09:52.402836 | 2025-10-13 16:09:52.402996 | PLAY [all] 2025-10-13 16:09:52.418623 | 2025-10-13 16:09:52.418701 | TASK [include_role : prepare-workspace] 2025-10-13 16:09:52.436886 | controller | ok 2025-10-13 16:09:52.451204 | 2025-10-13 16:09:52.451267 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 16:09:52.829643 | controller | ok 2025-10-13 16:09:52.835992 | 2025-10-13 16:09:52.836056 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 16:09:54.629486 | controller | Output suppressed because no_log was given 2025-10-13 16:09:54.644279 | 2025-10-13 16:09:54.644406 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 16:09:54.954165 | controller | changed: "logs" 2025-10-13 16:09:55.153053 | controller | changed: "artifacts" 2025-10-13 16:09:55.392611 | controller | changed: "docs" 2025-10-13 16:09:55.409921 | 2025-10-13 16:09:55.410193 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 16:09:55.725787 | controller | changed: "logs" 2025-10-13 16:09:55.726013 | controller | changed: All items complete 2025-10-13 16:09:55.726041 | 2025-10-13 16:09:55.957127 | controller | changed: "artifacts" 2025-10-13 16:09:56.169816 | controller | changed: "docs" 2025-10-13 16:09:56.184370 | 2025-10-13 16:09:56.184475 | TASK [Check if worker can sudo] 2025-10-13 16:09:56.715355 | controller | ok: Runtime: 0:00:00.048773 2025-10-13 16:09:56.722805 | 2025-10-13 16:09:56.722897 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 16:09:56.798902 | controller | skipping: Conditional result was False 2025-10-13 16:09:56.808783 | 2025-10-13 16:09:56.808934 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 16:09:56.903954 | controller | ok 2025-10-13 16:09:56.945650 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 16:09:56.953770 | 2025-10-13 16:09:56.953858 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 16:09:57.258461 | controller | ok 2025-10-13 16:09:57.264393 | 2025-10-13 16:09:57.264456 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 16:09:57.337695 | controller | ok: "/var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 16:09:57.353588 | 2025-10-13 16:09:57.353808 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 16:09:58.209585 | controller | changed 2025-10-13 16:09:58.217075 | 2025-10-13 16:09:58.217160 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 16:09:58.283325 | controller | ok: "/var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 16:09:58.284039 | controller | ok: All items complete 2025-10-13 16:09:58.284144 | 2025-10-13 16:09:58.347822 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 16:09:58.354798 | 2025-10-13 16:09:58.354863 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 16:09:59.293059 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 16:10:00.132303 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 16:10:00.148145 | 2025-10-13 16:10:00.148260 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 16:10:00.580462 | controller | changed: section and option added 2025-10-13 16:10:00.614311 | 2025-10-13 16:10:00.614414 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 16:10:01.402494 | controller | 29 files removed 2025-10-13 16:10:01.402807 | controller | ok: Item: dnf clean all Runtime: 0:00:00.508452 2025-10-13 16:10:01.402871 | controller | changed: All items complete 2025-10-13 16:10:01.402901 | 2025-10-13 16:10:12.394223 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-10-13 16:10:12.394331 | controller | DNF version: 4.14.0 2025-10-13 16:10:12.394355 | controller | cachedir: /var/cache/dnf 2025-10-13 16:10:12.394375 | controller | Making cache files for all metadata files. 2025-10-13 16:10:12.394393 | controller | baseos: has expired and will be refreshed. 2025-10-13 16:10:12.394411 | controller | appstream: has expired and will be refreshed. 2025-10-13 16:10:12.394427 | controller | crb: has expired and will be refreshed. 2025-10-13 16:10:12.394453 | controller | extras-common: has expired and will be refreshed. 2025-10-13 16:10:12.394471 | controller | repo: downloading from remote: baseos 2025-10-13 16:10:12.394487 | controller | CentOS Stream 9 - BaseOS 79 MB/s | 8.8 MB 00:00 2025-10-13 16:10:12.394503 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 16:10:12.394519 | controller | repo: downloading from remote: appstream 2025-10-13 16:10:12.394535 | controller | CentOS Stream 9 - AppStream 98 MB/s | 25 MB 00:00 2025-10-13 16:10:12.394551 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 16:10:12.394567 | controller | repo: downloading from remote: crb 2025-10-13 16:10:12.394583 | controller | CentOS Stream 9 - CRB 57 MB/s | 7.2 MB 00:00 2025-10-13 16:10:12.394599 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 16:10:12.394615 | controller | repo: downloading from remote: extras-common 2025-10-13 16:10:12.394631 | controller | CentOS Stream 9 - Extras packages 1.8 MB/s | 20 kB 00:00 2025-10-13 16:10:12.394647 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 16:10:12.394663 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 16:10:12.394697 | controller | Completion plugin: Generating completion cache... 2025-10-13 16:10:12.394719 | controller | Metadata cache created. 2025-10-13 16:10:12.394745 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.689644 2025-10-13 16:10:12.412303 | 2025-10-13 16:10:12.412423 | PLAY RECAP 2025-10-13 16:10:12.412482 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 16:10:12.412518 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 16:10:12.412543 | 2025-10-13 16:10:12.528295 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 16:10:12.529292 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 16:10:13.110755 | 2025-10-13 16:10:13.110865 | PLAY [all] 2025-10-13 16:10:13.131476 | 2025-10-13 16:10:13.131555 | TASK [Install binary dependencies] 2025-10-13 16:10:13.180914 | controller | ok 2025-10-13 16:10:13.199778 | 2025-10-13 16:10:13.199858 | TASK [bindep : Include find tasks] 2025-10-13 16:10:13.228250 | controller | ok 2025-10-13 16:10:13.235539 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 16:10:13.241581 | 2025-10-13 16:10:13.241647 | TASK [bindep : Look for bindep.txt] 2025-10-13 16:10:13.644181 | controller | ok 2025-10-13 16:10:13.653969 | 2025-10-13 16:10:13.654075 | TASK [bindep : Define bindep_file fact] 2025-10-13 16:10:13.702088 | controller | ok 2025-10-13 16:10:13.713629 | 2025-10-13 16:10:13.713795 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 16:10:13.740070 | controller | skipping: Conditional result was False 2025-10-13 16:10:13.747326 | 2025-10-13 16:10:13.747418 | TASK [bindep : Define bindep_file fact] 2025-10-13 16:10:13.772034 | controller | skipping: Conditional result was False 2025-10-13 16:10:13.779564 | 2025-10-13 16:10:13.779655 | TASK [bindep : Look for bindep fallback file] 2025-10-13 16:10:13.805731 | controller | skipping: Conditional result was False 2025-10-13 16:10:13.813746 | 2025-10-13 16:10:13.813839 | TASK [bindep : Define bindep_file fact] 2025-10-13 16:10:13.838445 | controller | skipping: Conditional result was False 2025-10-13 16:10:13.847589 | 2025-10-13 16:10:13.847737 | TASK [bindep : Include bindep tasks] 2025-10-13 16:10:13.878754 | controller | ok 2025-10-13 16:10:13.889653 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 16:10:13.906531 | 2025-10-13 16:10:13.906616 | TASK [bindep : Look for bindep command] 2025-10-13 16:10:13.931237 | controller | skipping: Conditional result was False 2025-10-13 16:10:13.937248 | 2025-10-13 16:10:13.937379 | TASK [bindep : Check for system bindep] 2025-10-13 16:10:14.466026 | controller | ok: Runtime: 0:00:00.004589 2025-10-13 16:10:14.473647 | 2025-10-13 16:10:14.473783 | TASK [bindep : Define bindep_command fact] 2025-10-13 16:10:14.498210 | controller | skipping: Conditional result was False 2025-10-13 16:10:14.503857 | 2025-10-13 16:10:14.503920 | TASK [bindep : Include install tasks] 2025-10-13 16:10:14.531946 | controller | ok 2025-10-13 16:10:14.539320 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 16:10:14.547873 | 2025-10-13 16:10:14.547932 | TASK [bindep : Create temp dir for bindep] 2025-10-13 16:10:14.905555 | controller | changed 2025-10-13 16:10:14.917776 | 2025-10-13 16:10:14.917851 | TASK [Ensure we have pip dependencies] 2025-10-13 16:10:14.938570 | controller | ok 2025-10-13 16:10:14.973538 | 2025-10-13 16:10:14.973704 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 12:10:15.230152 | controller | /usr/bin/pip3 2025-10-13 12:10:15.257250 | controller | /usr/bin/python3: No module named wheel 2025-10-13 16:10:15.503757 | controller | ok: Runtime: 0:00:00.040702 2025-10-13 16:10:15.515669 | 2025-10-13 16:10:15.515867 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 16:10:15.579523 | controller | ok: "/var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 16:10:15.594223 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 16:10:15.604084 | 2025-10-13 16:10:15.604145 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 16:10:18.007766 | controller | changed 2025-10-13 16:10:18.022015 | 2025-10-13 16:10:18.022174 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 16:10:18.099645 | controller | skipping: Conditional result was False 2025-10-13 16:10:18.108267 | 2025-10-13 16:10:18.108357 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 16:10:18.164310 | controller | skipping: Conditional result was False 2025-10-13 16:10:18.176767 | 2025-10-13 16:10:18.176902 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 16:10:18.234136 | controller | skipping: Conditional result was False 2025-10-13 16:10:18.241659 | 2025-10-13 16:10:18.241770 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 16:10:18.265923 | controller | skipping: Conditional result was False 2025-10-13 16:10:18.275202 | 2025-10-13 16:10:18.275364 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 16:10:18.817272 | controller | skipping: Conditional result was False 2025-10-13 16:10:18.832756 | 2025-10-13 16:10:18.832986 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 16:10:18.860069 | controller | skipping: Conditional result was False 2025-10-13 16:10:18.873424 | 2025-10-13 16:10:18.873561 | TASK [ensure-pip : Install pip from source] 2025-10-13 16:10:18.900672 | controller | skipping: Conditional result was False 2025-10-13 16:10:18.914928 | 2025-10-13 16:10:18.915066 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 12:10:19.198866 | controller | /usr/bin/python3 2025-10-13 16:10:19.457471 | controller | ok: Runtime: 0:00:00.004223 2025-10-13 16:10:19.465495 | 2025-10-13 16:10:19.465615 | TASK [ensure-pip : Set host default] 2025-10-13 16:10:19.518774 | controller | ok 2025-10-13 16:10:19.524533 | 2025-10-13 16:10:19.524600 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 16:10:19.576838 | controller | ok 2025-10-13 16:10:19.587335 | 2025-10-13 16:10:19.587408 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 16:10:23.778207 | controller | changed 2025-10-13 16:10:23.791400 | 2025-10-13 16:10:23.791588 | TASK [bindep : Define bindep_command] 2025-10-13 16:10:23.817661 | controller | ok 2025-10-13 16:10:23.825471 | 2025-10-13 16:10:23.825560 | LOOP [bindep : Include package tasks] 2025-10-13 16:10:23.883575 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 16:10:23.884407 | controller | ok: All items complete 2025-10-13 16:10:23.884478 | 2025-10-13 16:10:23.905838 | controller | included: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 16:10:23.931297 | 2025-10-13 16:10:23.931455 | TASK [bindep : Define bindep_run fact] 2025-10-13 16:10:24.001768 | controller | ok 2025-10-13 16:10:24.011253 | 2025-10-13 16:10:24.011373 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 12:10:25.306067 | controller | podman 2025-10-13 12:10:25.338149 | controller | python3-jmespath 2025-10-13 12:10:25.338229 | controller | python3-libvirt 2025-10-13 12:10:25.338241 | controller | python3-lxml 2025-10-13 12:10:25.338255 | controller | python3-netaddr 2025-10-13 16:10:25.551370 | controller | ok: Runtime: 0:00:01.079343 2025-10-13 16:10:25.563893 | 2025-10-13 16:10:25.564025 | TASK [bindep : Install distro packages from bindep] 2025-10-13 16:11:28.418884 | controller | changed 2025-10-13 16:11:28.429380 | 2025-10-13 16:11:28.429485 | TASK [bindep : Check that packages are installed] 2025-10-13 16:11:29.972411 | controller | ok: Runtime: 0:00:01.134800 2025-10-13 16:11:29.985199 | 2025-10-13 16:11:29.985341 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 16:11:30.022127 | controller | skipping: Conditional result was False 2025-10-13 16:11:30.047736 | 2025-10-13 16:11:30.047918 | TASK [Run test-setup role] 2025-10-13 16:11:30.077603 | controller | ok 2025-10-13 16:11:30.106318 | 2025-10-13 16:11:30.106416 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 16:11:30.352718 | controller | ok 2025-10-13 16:11:30.361151 | 2025-10-13 16:11:30.361236 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 16:11:30.898602 | controller | skipping: Conditional result was False 2025-10-13 16:11:30.941772 | 2025-10-13 16:11:30.941923 | TASK [bindep : Remove bindep temp dir] 2025-10-13 16:11:31.343204 | controller | ok 2025-10-13 16:11:31.357452 | 2025-10-13 16:11:31.357521 | PLAY RECAP 2025-10-13 16:11:31.357571 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 16:11:31.357599 | 2025-10-13 16:11:31.465819 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 16:11:31.468052 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 16:11:32.029924 | 2025-10-13 16:11:32.030026 | PLAY [all] 2025-10-13 16:11:32.048662 | 2025-10-13 16:11:32.048765 | TASK [Abort when test_command variable is undefined] 2025-10-13 16:11:32.082822 | controller | skipping: Conditional result was False 2025-10-13 16:11:32.088209 | 2025-10-13 16:11:32.088281 | TASK [Convert test_command to list] 2025-10-13 16:11:32.134416 | controller | skipping: Conditional result was False 2025-10-13 16:11:32.146639 | 2025-10-13 16:11:32.146816 | TASK [Use test_command list] 2025-10-13 16:11:32.225023 | controller | ok 2025-10-13 16:11:32.236426 | 2025-10-13 16:11:32.236556 | LOOP [Run test_command] 2025-10-13 16:11:32.632927 | controller | no check to run 2025-10-13 16:11:32.633223 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006624 2025-10-13 16:11:32.683358 | 2025-10-13 16:11:32.683511 | PLAY RECAP 2025-10-13 16:11:32.683595 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 16:11:32.683640 | 2025-10-13 16:11:32.788797 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 16:11:32.790513 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 16:11:33.380521 | 2025-10-13 16:11:33.380755 | PLAY [all] 2025-10-13 16:11:33.401244 | 2025-10-13 16:11:33.401339 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 16:11:33.805768 | controller | changed: non-zero return code 2025-10-13 16:11:33.811120 | 2025-10-13 16:11:33.811193 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 16:11:33.834804 | controller | skipping: Conditional result was False 2025-10-13 16:11:33.840248 | 2025-10-13 16:11:33.840313 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 16:11:33.879070 | 2025-10-13 16:11:33.879425 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 16:11:33.910344 | 2025-10-13 16:11:33.910624 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 16:11:33.927721 | controller | skipping: Conditional result was False 2025-10-13 16:11:33.940740 | 2025-10-13 16:11:33.940878 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 16:11:33.971019 | 2025-10-13 16:11:33.971260 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 16:11:33.987631 | controller | skipping: Conditional result was False 2025-10-13 16:11:33.999191 | 2025-10-13 16:11:33.999326 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 16:11:34.015987 | controller | skipping: Conditional result was False 2025-10-13 16:11:34.027935 | 2025-10-13 16:11:34.028079 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 16:11:34.044623 | controller | skipping: Conditional result was False 2025-10-13 16:11:34.077290 | 2025-10-13 16:11:34.077359 | PLAY RECAP 2025-10-13 16:11:34.077413 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 16:11:34.077440 | 2025-10-13 16:11:34.167972 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 16:11:34.168823 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 16:11:34.748773 | 2025-10-13 16:11:34.748890 | PLAY [all] 2025-10-13 16:11:34.768185 | 2025-10-13 16:11:34.768270 | TASK [include_role : fetch-output] 2025-10-13 16:11:34.797587 | controller | ok 2025-10-13 16:11:34.814723 | 2025-10-13 16:11:34.814806 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 16:11:34.869239 | controller | skipping: Conditional result was False 2025-10-13 16:11:34.875576 | 2025-10-13 16:11:34.875647 | TASK [fetch-output : Set log path for single node] 2025-10-13 16:11:34.911058 | controller | ok 2025-10-13 16:11:34.921461 | 2025-10-13 16:11:34.921569 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 16:11:35.345714 | controller -> localhost | ok: "/var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/logs" 2025-10-13 16:11:35.553065 | controller -> localhost | changed: "/var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/artifacts" 2025-10-13 16:11:35.843001 | controller -> localhost | changed: "/var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/docs" 2025-10-13 16:11:35.858105 | 2025-10-13 16:11:35.858230 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 16:11:36.540762 | controller | changed: .d..t...... ./ 2025-10-13 16:11:36.541097 | controller | changed: All items complete 2025-10-13 16:11:36.541160 | 2025-10-13 16:11:37.004092 | controller | changed: .d..t...... ./ 2025-10-13 16:11:37.533324 | controller | changed: .d..t...... ./ 2025-10-13 16:11:37.559195 | 2025-10-13 16:11:37.559358 | TASK [include_role : fetch-output-openshift] 2025-10-13 16:11:37.586175 | controller | skipping: Conditional result was False 2025-10-13 16:11:37.599803 | 2025-10-13 16:11:37.600005 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 16:11:38.063812 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007498 2025-10-13 16:11:38.348142 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012086 2025-10-13 16:11:38.376842 | 2025-10-13 16:11:38.376958 | PLAY [all] 2025-10-13 16:11:38.392011 | 2025-10-13 16:11:38.392083 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 16:11:38.809552 | controller | changed 2025-10-13 16:11:38.832642 | 2025-10-13 16:11:38.832739 | PLAY RECAP 2025-10-13 16:11:38.832780 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 16:11:38.832801 | 2025-10-13 16:11:38.927427 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 16:11:38.928295 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 16:11:39.526731 | 2025-10-13 16:11:39.526843 | PLAY [localhost] 2025-10-13 16:11:39.545463 | 2025-10-13 16:11:39.545574 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 16:11:39.955962 | localhost | changed 2025-10-13 16:11:39.966323 | 2025-10-13 16:11:39.966480 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 16:11:39.991879 | localhost | ok 2025-10-13 16:11:40.010472 | 2025-10-13 16:11:40.010619 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 16:11:40.396737 | localhost | changed 2025-10-13 16:11:40.402750 | 2025-10-13 16:11:40.402819 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 16:11:41.069502 | localhost | changed 2025-10-13 16:11:41.074884 | 2025-10-13 16:11:41.074945 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 16:11:41.588996 | localhost | Identity added: /var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/tmp/ansible.fydh8x7u (/var/lib/zuul/builds/3aa724cc13be4567afa92007fa605fb2/work/tmp/ansible.fydh8x7u) 2025-10-13 16:11:41.589307 | localhost | ok: Runtime: 0:00:00.013886 2025-10-13 16:11:41.599591 | 2025-10-13 16:11:41.599809 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 16:11:41.905461 | localhost | ok: Runtime: 0:00:00.008433 2025-10-13 16:11:41.910835 | 2025-10-13 16:11:41.910907 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 16:11:41.994919 | localhost | changed 2025-10-13 16:11:42.004655 | 2025-10-13 16:11:42.004857 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 16:11:42.462901 | localhost | changed 2025-10-13 16:11:42.482928 | 2025-10-13 16:11:42.482985 | PLAY [localhost] 2025-10-13 16:11:42.495389 | 2025-10-13 16:11:42.495453 | TASK [Generate bulk log download script] 2025-10-13 16:11:42.513111 | localhost | ok 2025-10-13 16:11:42.525002 | 2025-10-13 16:11:42.525065 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 16:11:42.552508 | localhost | ok: All assertions passed 2025-10-13 16:11:42.557208 | 2025-10-13 16:11:42.557273 | TASK [local-log-download : Create download script] 2025-10-13 16:11:43.018586 | localhost -> localhost | changed 2025-10-13 16:11:43.031041 | 2025-10-13 16:11:43.031125 | TASK [Register quick-download link] 2025-10-13 16:11:43.052794 | localhost | ok 2025-10-13 16:11:43.097967 | 2025-10-13 16:11:43.098068 | PLAY [logserver.rdoproject.org] 2025-10-13 16:11:43.107625 | 2025-10-13 16:11:43.107749 | TASK [Set zuul-log-path fact] 2025-10-13 16:11:43.123527 | logserver.rdoproject.org | ok 2025-10-13 16:11:43.132371 | 2025-10-13 16:11:43.132478 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 16:11:43.159936 | logserver.rdoproject.org | ok 2025-10-13 16:11:43.167755 | 2025-10-13 16:11:43.167839 | TASK [upload-logs : Create log directories] 2025-10-13 16:11:43.778487 | logserver.rdoproject.org | changed 2025-10-13 16:11:43.785241 | 2025-10-13 16:11:43.785369 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 16:11:44.097244 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009112 2025-10-13 16:11:44.106928 | 2025-10-13 16:11:44.107054 | TASK [upload-logs : Upload logs to log server] 2025-10-13 16:11:44.829803 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 16:11:44.832851 | 2025-10-13 16:11:44.832921 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 16:11:44.873069 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 16:11:44.884507 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 16:11:44.891357 | 2025-10-13 16:11:44.891486 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 16:11:44.929519 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 16:11:44.929797 | 2025-10-13 16:11:44.934822 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 16:11:44.939532 | 2025-10-13 16:11:44.939632 | LOOP [upload-logs : Upload console log and json output]