2025-10-07 14:33:14.004861 | Job console starting... 2025-10-07 14:33:14.013799 | Updating repositories 2025-10-07 14:33:14.036997 | Preparing job workspace 2025-10-07 14:33:17.886703 | Running Ansible setup... 2025-10-07 14:33:21.818139 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 14:33:22.374100 | 2025-10-07 14:33:22.374209 | PLAY [localhost] 2025-10-07 14:33:22.382873 | 2025-10-07 14:33:22.382943 | TASK [Gathering Facts] 2025-10-07 14:33:23.419496 | localhost | ok 2025-10-07 14:33:23.433663 | 2025-10-07 14:33:23.433787 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-07 14:33:23.881001 | localhost -> localhost | changed 2025-10-07 14:33:23.886809 | 2025-10-07 14:33:23.886877 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-07 14:33:24.672794 | localhost -> localhost | changed 2025-10-07 14:33:24.682001 | 2025-10-07 14:33:24.682129 | TASK [Setup log path fact] 2025-10-07 14:33:24.699799 | localhost | ok 2025-10-07 14:33:24.722180 | 2025-10-07 14:33:24.722337 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 14:33:24.750678 | localhost | ok 2025-10-07 14:33:24.761678 | 2025-10-07 14:33:24.761770 | TASK [emit-job-header : Print job information] 2025-10-07 14:33:24.798969 | # Job Information 2025-10-07 14:33:24.799126 | Ansible Version: 2.15.12 2025-10-07 14:33:24.799154 | Job: cifmw-molecule-ci_lvms_storage 2025-10-07 14:33:24.799174 | Pipeline: github-check 2025-10-07 14:33:24.799193 | Executor: ze01.softwarefactory-project.io 2025-10-07 14:33:24.799211 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366 2025-10-07 14:33:24.799230 | Log URL (when completed): https://logserver.rdoproject.org/4bc/rdoproject.org/4bc0e502fb844aaabcb569edf09d52b8/ 2025-10-07 14:33:24.799248 | Event ID: 640e52c0-a38a-11f0-87db-ca38cb57bc1b 2025-10-07 14:33:24.803301 | 2025-10-07 14:33:24.803364 | LOOP [emit-job-header : Print node information] 2025-10-07 14:33:24.896062 | localhost | ok: 2025-10-07 14:33:24.896214 | localhost | # Node Information 2025-10-07 14:33:24.896240 | localhost | Inventory Hostname: controller 2025-10-07 14:33:24.896262 | localhost | Hostname: np0005474053 2025-10-07 14:33:24.896281 | localhost | Username: zuul 2025-10-07 14:33:24.896301 | localhost | Distro: CentOS 9 2025-10-07 14:33:24.896318 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-07 14:33:24.896335 | localhost | Region: RegionOne 2025-10-07 14:33:24.896351 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-07 14:33:24.896368 | localhost | Product Name: OpenStack Nova 2025-10-07 14:33:24.896384 | localhost | Interface IP: 38.129.56.238 2025-10-07 14:33:24.918130 | 2025-10-07 14:33:24.918293 | PLAY [all] 2025-10-07 14:33:24.931467 | 2025-10-07 14:33:24.931581 | TASK [Gather network facts] 2025-10-07 14:33:25.439545 | controller | ok 2025-10-07 14:33:25.468329 | 2025-10-07 14:33:25.468545 | TASK [include_role : start-zuul-console] 2025-10-07 14:33:25.522159 | controller | ok 2025-10-07 14:33:25.547842 | 2025-10-07 14:33:25.547958 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-07 14:33:25.946764 | controller | ok 2025-10-07 14:33:25.966572 | 2025-10-07 14:33:25.966692 | TASK [include_role : add-build-sshkey] 2025-10-07 14:33:26.018831 | controller | ok 2025-10-07 14:33:26.032841 | 2025-10-07 14:33:26.032926 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-07 14:33:26.255641 | controller -> localhost | ok 2025-10-07 14:33:26.276108 | 2025-10-07 14:33:26.276224 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-07 14:33:26.315992 | controller | ok 2025-10-07 14:33:26.369429 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-07 14:33:26.393823 | 2025-10-07 14:33:26.393951 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-07 14:33:27.305268 | controller -> localhost | Generating public/private rsa key pair. 2025-10-07 14:33:27.305487 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/4bc0e502fb844aaabcb569edf09d52b8_id_rsa. 2025-10-07 14:33:27.305518 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/4bc0e502fb844aaabcb569edf09d52b8_id_rsa.pub. 2025-10-07 14:33:27.305540 | controller -> localhost | The key fingerprint is: 2025-10-07 14:33:27.305561 | controller -> localhost | SHA256:LKtANekqUAd58RCoU+xxeJjqNk4nFCrln4i0mh1sW7c zuul-build-sshkey 2025-10-07 14:33:27.305580 | controller -> localhost | The key's randomart image is: 2025-10-07 14:33:27.305598 | controller -> localhost | +---[RSA 3072]----+ 2025-10-07 14:33:27.305616 | controller -> localhost | | ..*+o | 2025-10-07 14:33:27.305635 | controller -> localhost | | .@.++ | 2025-10-07 14:33:27.305654 | controller -> localhost | |.Bo== . | 2025-10-07 14:33:27.305673 | controller -> localhost | |*+o+ . . | 2025-10-07 14:33:27.305691 | controller -> localhost | |*+oo... S | 2025-10-07 14:33:27.305709 | controller -> localhost | |oO=o+ .o | 2025-10-07 14:33:27.305726 | controller -> localhost | |*+*+ ... | 2025-10-07 14:33:27.305747 | controller -> localhost | |ooo. .E | 2025-10-07 14:33:27.305766 | controller -> localhost | | . | 2025-10-07 14:33:27.305783 | controller -> localhost | +----[SHA256]-----+ 2025-10-07 14:33:27.305823 | controller -> localhost | ok: Runtime: 0:00:00.153180 2025-10-07 14:33:27.311849 | 2025-10-07 14:33:27.311915 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-07 14:33:27.343501 | controller | ok 2025-10-07 14:33:27.357821 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-07 14:33:27.376145 | 2025-10-07 14:33:27.376595 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-07 14:33:27.400606 | controller | skipping: Conditional result was False 2025-10-07 14:33:27.410950 | 2025-10-07 14:33:27.411079 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-07 14:33:28.041883 | controller | changed 2025-10-07 14:33:28.048779 | 2025-10-07 14:33:28.048873 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-07 14:33:28.362967 | controller | ok 2025-10-07 14:33:28.369437 | 2025-10-07 14:33:28.369543 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-07 14:33:29.185713 | controller | changed 2025-10-07 14:33:29.195382 | 2025-10-07 14:33:29.195859 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-07 14:33:30.050010 | controller | changed 2025-10-07 14:33:30.058932 | 2025-10-07 14:33:30.059008 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-07 14:33:30.102208 | controller | skipping: Conditional result was False 2025-10-07 14:33:30.108303 | 2025-10-07 14:33:30.108372 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-07 14:33:30.459543 | controller -> localhost | changed 2025-10-07 14:33:30.471479 | 2025-10-07 14:33:30.473812 | TASK [add-build-sshkey : Add back temp key] 2025-10-07 14:33:30.797793 | controller -> localhost | Identity added: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/4bc0e502fb844aaabcb569edf09d52b8_id_rsa (zuul-build-sshkey) 2025-10-07 14:33:30.798167 | controller -> localhost | ok: Runtime: 0:00:00.015256 2025-10-07 14:33:30.814183 | 2025-10-07 14:33:30.814350 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-07 14:33:31.196992 | controller | ok 2025-10-07 14:33:31.204151 | 2025-10-07 14:33:31.204289 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-07 14:33:31.239297 | controller | skipping: Conditional result was False 2025-10-07 14:33:31.253429 | 2025-10-07 14:33:31.253557 | TASK [include_role : validate-host] 2025-10-07 14:33:31.276482 | controller | ok 2025-10-07 14:33:31.301957 | 2025-10-07 14:33:31.302078 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-07 14:33:31.331625 | controller | ok 2025-10-07 14:33:31.336876 | 2025-10-07 14:33:31.336936 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-07 14:33:31.647762 | controller -> localhost | ok 2025-10-07 14:33:31.654562 | 2025-10-07 14:33:31.654662 | TASK [validate-host : Collect information about the host] 2025-10-07 14:33:32.409263 | controller | ok 2025-10-07 14:33:32.432154 | 2025-10-07 14:33:32.432282 | TASK [validate-host : Sanitize hostname] 2025-10-07 14:33:32.483472 | controller | ok 2025-10-07 14:33:32.488591 | 2025-10-07 14:33:32.488656 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-07 14:33:32.950373 | controller -> localhost | changed 2025-10-07 14:33:32.957172 | 2025-10-07 14:33:32.957241 | TASK [validate-host : Collect information about zuul worker] 2025-10-07 14:33:33.383831 | controller | ok 2025-10-07 14:33:33.392889 | 2025-10-07 14:33:33.393043 | TASK [validate-host : Write out all zuul information for each host] 2025-10-07 14:33:33.889844 | controller -> localhost | changed 2025-10-07 14:33:33.902047 | 2025-10-07 14:33:33.902156 | TASK [include_role : prepare-workspace-openshift] 2025-10-07 14:33:33.916825 | controller | skipping: Conditional result was False 2025-10-07 14:33:33.923067 | 2025-10-07 14:33:33.923171 | TASK [include_role : remove-zuul-sshkey] 2025-10-07 14:33:33.951093 | controller | skipping: Conditional result was False 2025-10-07 14:33:33.957039 | 2025-10-07 14:33:33.957128 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 14:33:34.205051 | controller | ok: "logs" 2025-10-07 14:33:34.205334 | controller | ok: All items complete 2025-10-07 14:33:34.205376 | 2025-10-07 14:33:34.414771 | controller | ok: "artifacts" 2025-10-07 14:33:34.653916 | controller | ok: "docs" 2025-10-07 14:33:34.660751 | 2025-10-07 14:33:34.660857 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 14:33:34.943222 | controller | changed: "logs" 2025-10-07 14:33:35.182395 | controller | changed: "artifacts" 2025-10-07 14:33:35.488102 | controller | changed: "docs" 2025-10-07 14:33:35.520558 | 2025-10-07 14:33:35.520738 | PLAY RECAP 2025-10-07 14:33:35.520792 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-07 14:33:35.520818 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 14:33:35.520835 | 2025-10-07 14:33:35.653304 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 14:33:35.654308 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 14:33:36.274298 | 2025-10-07 14:33:36.274421 | PLAY [localhost] 2025-10-07 14:33:36.291522 | 2025-10-07 14:33:36.291643 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-07 14:33:36.657374 | localhost | ok 2025-10-07 14:33:36.665766 | 2025-10-07 14:33:36.665849 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-07 14:33:37.278989 | localhost | changed 2025-10-07 14:33:37.299003 | 2025-10-07 14:33:37.299077 | PLAY [all] 2025-10-07 14:33:37.314342 | 2025-10-07 14:33:37.314403 | TASK [include_role : prepare-workspace] 2025-10-07 14:33:37.332711 | controller | ok 2025-10-07 14:33:37.347110 | 2025-10-07 14:33:37.347178 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-07 14:33:37.733848 | controller | ok 2025-10-07 14:33:37.742186 | 2025-10-07 14:33:37.742533 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-07 14:33:40.064211 | controller | Output suppressed because no_log was given 2025-10-07 14:33:40.084518 | 2025-10-07 14:33:40.084669 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 14:33:40.381286 | controller | changed: "logs" 2025-10-07 14:33:40.646138 | controller | changed: "artifacts" 2025-10-07 14:33:40.863600 | controller | changed: "docs" 2025-10-07 14:33:40.879470 | 2025-10-07 14:33:40.879692 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 14:33:41.141344 | controller | changed: "logs" 2025-10-07 14:33:41.141680 | controller | changed: All items complete 2025-10-07 14:33:41.141708 | 2025-10-07 14:33:41.376283 | controller | changed: "artifacts" 2025-10-07 14:33:41.608607 | controller | changed: "docs" 2025-10-07 14:33:41.627333 | 2025-10-07 14:33:41.627477 | TASK [Check if worker can sudo] 2025-10-07 14:33:42.168831 | controller | ok: Runtime: 0:00:00.062477 2025-10-07 14:33:42.174421 | 2025-10-07 14:33:42.174499 | TASK [configure-mirrors : Gather needed facts] 2025-10-07 14:33:42.248900 | controller | skipping: Conditional result was False 2025-10-07 14:33:42.254907 | 2025-10-07 14:33:42.254989 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-07 14:33:42.326094 | controller | ok 2025-10-07 14:33:42.334130 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-07 14:33:42.339666 | 2025-10-07 14:33:42.339725 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-07 14:33:42.713186 | controller | ok 2025-10-07 14:33:42.723552 | 2025-10-07 14:33:42.724463 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-07 14:33:42.815633 | controller | ok: "/var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-07 14:33:42.842776 | 2025-10-07 14:33:42.842975 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-07 14:33:43.694476 | controller | changed 2025-10-07 14:33:43.702207 | 2025-10-07 14:33:43.702311 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-07 14:33:43.797600 | controller | ok: "/var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-07 14:33:43.797805 | controller | ok: All items complete 2025-10-07 14:33:43.797843 | 2025-10-07 14:33:43.860101 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-07 14:33:43.866576 | 2025-10-07 14:33:43.866650 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-07 14:33:44.779685 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-07 14:33:45.602949 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-07 14:33:45.610668 | 2025-10-07 14:33:45.610770 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-07 14:33:46.060107 | controller | changed: section and option added 2025-10-07 14:33:46.083154 | 2025-10-07 14:33:46.083286 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-07 14:33:46.887244 | controller | 29 files removed 2025-10-07 14:33:46.887568 | controller | ok: Item: dnf clean all Runtime: 0:00:00.482658 2025-10-07 14:33:46.887631 | controller | changed: All items complete 2025-10-07 14:33:46.887660 | 2025-10-07 14:33:58.444960 | 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-07 14:33:58.445664 | controller | DNF version: 4.14.0 2025-10-07 14:33:58.445723 | controller | cachedir: /var/cache/dnf 2025-10-07 14:33:58.445755 | controller | Making cache files for all metadata files. 2025-10-07 14:33:58.445782 | controller | baseos: has expired and will be refreshed. 2025-10-07 14:33:58.445807 | controller | appstream: has expired and will be refreshed. 2025-10-07 14:33:58.445831 | controller | crb: has expired and will be refreshed. 2025-10-07 14:33:58.445871 | controller | extras-common: has expired and will be refreshed. 2025-10-07 14:33:58.445898 | controller | repo: downloading from remote: baseos 2025-10-07 14:33:58.445923 | controller | CentOS Stream 9 - BaseOS 61 MB/s | 8.8 MB 00:00 2025-10-07 14:33:58.445944 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-07 14:33:58.445960 | controller | repo: downloading from remote: appstream 2025-10-07 14:33:58.445976 | controller | CentOS Stream 9 - AppStream 68 MB/s | 25 MB 00:00 2025-10-07 14:33:58.445992 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-07 14:33:58.446009 | controller | repo: downloading from remote: crb 2025-10-07 14:33:58.446051 | controller | CentOS Stream 9 - CRB 64 MB/s | 7.1 MB 00:00 2025-10-07 14:33:58.446070 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-07 14:33:58.446087 | controller | repo: downloading from remote: extras-common 2025-10-07 14:33:58.446109 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-10-07 14:33:58.446132 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-07 14:33:58.446153 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-07 14:33:58.446172 | controller | Completion plugin: Generating completion cache... 2025-10-07 14:33:58.446188 | controller | Metadata cache created. 2025-10-07 14:33:58.446222 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.304136 2025-10-07 14:33:58.468828 | 2025-10-07 14:33:58.468922 | PLAY RECAP 2025-10-07 14:33:58.468962 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-07 14:33:58.468990 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 14:33:58.469009 | 2025-10-07 14:33:58.610430 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 14:33:58.611335 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 14:33:59.251653 | 2025-10-07 14:33:59.251779 | PLAY [all] 2025-10-07 14:33:59.279440 | 2025-10-07 14:33:59.279592 | TASK [Install binary dependencies] 2025-10-07 14:33:59.329836 | controller | ok 2025-10-07 14:33:59.355335 | 2025-10-07 14:33:59.355465 | TASK [bindep : Include find tasks] 2025-10-07 14:33:59.383902 | controller | ok 2025-10-07 14:33:59.391945 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-07 14:33:59.397966 | 2025-10-07 14:33:59.398047 | TASK [bindep : Look for bindep.txt] 2025-10-07 14:33:59.782304 | controller | ok 2025-10-07 14:33:59.791420 | 2025-10-07 14:33:59.791577 | TASK [bindep : Define bindep_file fact] 2025-10-07 14:33:59.826954 | controller | ok 2025-10-07 14:33:59.838182 | 2025-10-07 14:33:59.838375 | TASK [bindep : Look for other-requirements.txt] 2025-10-07 14:33:59.867418 | controller | skipping: Conditional result was False 2025-10-07 14:33:59.876203 | 2025-10-07 14:33:59.876349 | TASK [bindep : Define bindep_file fact] 2025-10-07 14:33:59.903718 | controller | skipping: Conditional result was False 2025-10-07 14:33:59.913856 | 2025-10-07 14:33:59.913960 | TASK [bindep : Look for bindep fallback file] 2025-10-07 14:33:59.939621 | controller | skipping: Conditional result was False 2025-10-07 14:33:59.948524 | 2025-10-07 14:33:59.948634 | TASK [bindep : Define bindep_file fact] 2025-10-07 14:33:59.973503 | controller | skipping: Conditional result was False 2025-10-07 14:33:59.982595 | 2025-10-07 14:33:59.982691 | TASK [bindep : Include bindep tasks] 2025-10-07 14:34:00.018199 | controller | ok 2025-10-07 14:34:00.028782 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-07 14:34:00.040661 | 2025-10-07 14:34:00.040745 | TASK [bindep : Look for bindep command] 2025-10-07 14:34:00.075603 | controller | skipping: Conditional result was False 2025-10-07 14:34:00.084443 | 2025-10-07 14:34:00.084532 | TASK [bindep : Check for system bindep] 2025-10-07 14:34:00.627403 | controller | ok: Runtime: 0:00:00.005471 2025-10-07 14:34:00.636972 | 2025-10-07 14:34:00.637113 | TASK [bindep : Define bindep_command fact] 2025-10-07 14:34:00.672369 | controller | skipping: Conditional result was False 2025-10-07 14:34:00.681307 | 2025-10-07 14:34:00.681498 | TASK [bindep : Include install tasks] 2025-10-07 14:34:00.734408 | controller | ok 2025-10-07 14:34:00.746404 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-07 14:34:00.759072 | 2025-10-07 14:34:00.759151 | TASK [bindep : Create temp dir for bindep] 2025-10-07 14:34:01.154089 | controller | changed 2025-10-07 14:34:01.162360 | 2025-10-07 14:34:01.162465 | TASK [Ensure we have pip dependencies] 2025-10-07 14:34:01.185881 | controller | ok 2025-10-07 14:34:01.224419 | 2025-10-07 14:34:01.224549 | TASK [ensure-pip : Check if pip is installed] 2025-10-07 10:34:01.514559 | controller | /usr/bin/pip3 2025-10-07 10:34:01.556966 | controller | /usr/bin/python3: No module named wheel 2025-10-07 14:34:01.770351 | controller | ok: Runtime: 0:00:00.059440 2025-10-07 14:34:01.782385 | 2025-10-07 14:34:01.782537 | LOOP [ensure-pip : Install pip from packages] 2025-10-07 14:34:01.816220 | controller | ok: "/var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-07 14:34:01.832410 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-07 14:34:01.848703 | 2025-10-07 14:34:01.848843 | TASK [ensure-pip : Install Python 3 pip] 2025-10-07 14:34:04.406779 | controller | changed 2025-10-07 14:34:04.419201 | 2025-10-07 14:34:04.419334 | TASK [ensure-pip : Check for EPEL repository] 2025-10-07 14:34:04.477200 | controller | skipping: Conditional result was False 2025-10-07 14:34:04.491232 | 2025-10-07 14:34:04.491398 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-07 14:34:04.539409 | controller | skipping: Conditional result was False 2025-10-07 14:34:04.552912 | 2025-10-07 14:34:04.553078 | TASK [ensure-pip : Install Python 2 pip] 2025-10-07 14:34:04.600546 | controller | skipping: Conditional result was False 2025-10-07 14:34:04.615241 | 2025-10-07 14:34:04.615387 | TASK [ensure-pip : Ensure setuptools] 2025-10-07 14:34:04.641712 | controller | skipping: Conditional result was False 2025-10-07 14:34:04.653713 | 2025-10-07 14:34:04.653849 | TASK [ensure-pip : Check for ensurepip module] 2025-10-07 14:34:05.202265 | controller | skipping: Conditional result was False 2025-10-07 14:34:05.211126 | 2025-10-07 14:34:05.211366 | TASK [ensure-pip : Ensure python3-venv] 2025-10-07 14:34:05.225994 | controller | skipping: Conditional result was False 2025-10-07 14:34:05.234515 | 2025-10-07 14:34:05.234604 | TASK [ensure-pip : Install pip from source] 2025-10-07 14:34:05.249055 | controller | skipping: Conditional result was False 2025-10-07 14:34:05.257478 | 2025-10-07 14:34:05.257567 | TASK [ensure-pip : Probe for venv python full path] 2025-10-07 10:34:05.555993 | controller | /usr/bin/python3 2025-10-07 14:34:05.796929 | controller | ok: Runtime: 0:00:00.010465 2025-10-07 14:34:05.805521 | 2025-10-07 14:34:05.805630 | TASK [ensure-pip : Set host default] 2025-10-07 14:34:05.868129 | controller | ok 2025-10-07 14:34:05.875386 | 2025-10-07 14:34:05.875487 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-07 14:34:05.971002 | controller | ok 2025-10-07 14:34:05.995908 | 2025-10-07 14:34:05.996114 | TASK [bindep : Install bindep into temporary venv] 2025-10-07 14:34:10.808218 | controller | changed 2025-10-07 14:34:10.815806 | 2025-10-07 14:34:10.815902 | TASK [bindep : Define bindep_command] 2025-10-07 14:34:10.856671 | controller | ok 2025-10-07 14:34:10.862811 | 2025-10-07 14:34:10.862924 | LOOP [bindep : Include package tasks] 2025-10-07 14:34:10.938570 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-07 14:34:10.938806 | controller | ok: All items complete 2025-10-07 14:34:10.938849 | 2025-10-07 14:34:10.955545 | controller | included: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-07 14:34:10.970380 | 2025-10-07 14:34:10.970523 | TASK [bindep : Define bindep_run fact] 2025-10-07 14:34:10.993367 | controller | ok 2025-10-07 14:34:10.999009 | 2025-10-07 14:34:10.999149 | TASK [bindep : Get list of packages to install from bindep] 2025-10-07 10:34:12.383158 | controller | podman 2025-10-07 10:34:12.423724 | controller | python3-jmespath 2025-10-07 10:34:12.423809 | controller | python3-libvirt 2025-10-07 10:34:12.423820 | controller | python3-lxml 2025-10-07 10:34:12.423831 | controller | python3-netaddr 2025-10-07 14:34:12.540576 | controller | ok: Runtime: 0:00:01.171742 2025-10-07 14:34:12.553822 | 2025-10-07 14:34:12.554201 | TASK [bindep : Install distro packages from bindep] 2025-10-07 14:35:19.922359 | controller | changed 2025-10-07 14:35:19.932499 | 2025-10-07 14:35:19.932621 | TASK [bindep : Check that packages are installed] 2025-10-07 14:35:22.027529 | controller | ok: Runtime: 0:00:01.279998 2025-10-07 14:35:22.035798 | 2025-10-07 14:35:22.035879 | TASK [bindep : Fail if we cannot install all packages] 2025-10-07 14:35:22.071440 | controller | skipping: Conditional result was False 2025-10-07 14:35:22.086893 | 2025-10-07 14:35:22.086998 | TASK [Run test-setup role] 2025-10-07 14:35:22.108400 | controller | ok 2025-10-07 14:35:22.126681 | 2025-10-07 14:35:22.126782 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-07 14:35:22.439815 | controller | ok 2025-10-07 14:35:22.452203 | 2025-10-07 14:35:22.452354 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-07 14:35:22.998910 | controller | skipping: Conditional result was False 2025-10-07 14:35:23.049938 | 2025-10-07 14:35:23.050127 | TASK [bindep : Remove bindep temp dir] 2025-10-07 14:35:23.467505 | controller | ok 2025-10-07 14:35:23.497762 | 2025-10-07 14:35:23.497944 | PLAY RECAP 2025-10-07 14:35:23.498110 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-07 14:35:23.498190 | 2025-10-07 14:35:23.623750 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 14:35:23.624931 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 14:35:24.220483 | 2025-10-07 14:35:24.220594 | PLAY [all] 2025-10-07 14:35:24.241226 | 2025-10-07 14:35:24.241312 | TASK [Abort when test_command variable is undefined] 2025-10-07 14:35:24.275586 | controller | skipping: Conditional result was False 2025-10-07 14:35:24.281533 | 2025-10-07 14:35:24.281608 | TASK [Convert test_command to list] 2025-10-07 14:35:24.336084 | controller | skipping: Conditional result was False 2025-10-07 14:35:24.343227 | 2025-10-07 14:35:24.343326 | TASK [Use test_command list] 2025-10-07 14:35:24.403390 | controller | ok 2025-10-07 14:35:24.408975 | 2025-10-07 14:35:24.409071 | LOOP [Run test_command] 2025-10-07 14:35:24.871453 | controller | no check to run 2025-10-07 14:35:24.871820 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006759 2025-10-07 14:35:24.926721 | 2025-10-07 14:35:24.927142 | PLAY RECAP 2025-10-07 14:35:24.927207 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 14:35:24.927236 | 2025-10-07 14:35:25.033348 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 14:35:25.035129 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 14:35:25.628169 | 2025-10-07 14:35:25.628333 | PLAY [all] 2025-10-07 14:35:25.654961 | 2025-10-07 14:35:25.655124 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-07 14:35:25.987436 | controller | changed: non-zero return code 2025-10-07 14:35:25.999971 | 2025-10-07 14:35:26.000245 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-07 14:35:26.028839 | controller | skipping: Conditional result was False 2025-10-07 14:35:26.047059 | 2025-10-07 14:35:26.047255 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-07 14:35:26.091583 | 2025-10-07 14:35:26.092235 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-07 14:35:26.126146 | 2025-10-07 14:35:26.126580 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-07 14:35:26.153162 | controller | skipping: Conditional result was False 2025-10-07 14:35:26.163096 | 2025-10-07 14:35:26.163345 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-07 14:35:26.199104 | 2025-10-07 14:35:26.199319 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-07 14:35:26.226878 | controller | skipping: Conditional result was False 2025-10-07 14:35:26.235817 | 2025-10-07 14:35:26.235925 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-07 14:35:26.252142 | controller | skipping: Conditional result was False 2025-10-07 14:35:26.263344 | 2025-10-07 14:35:26.263484 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-07 14:35:26.280044 | controller | skipping: Conditional result was False 2025-10-07 14:35:26.317297 | 2025-10-07 14:35:26.317398 | PLAY RECAP 2025-10-07 14:35:26.317439 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-07 14:35:26.317461 | 2025-10-07 14:35:26.427229 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 14:35:26.429449 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 14:35:27.103263 | 2025-10-07 14:35:27.103378 | PLAY [all] 2025-10-07 14:35:27.122128 | 2025-10-07 14:35:27.122241 | TASK [include_role : fetch-output] 2025-10-07 14:35:27.151213 | controller | ok 2025-10-07 14:35:27.169444 | 2025-10-07 14:35:27.169564 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-07 14:35:27.224650 | controller | skipping: Conditional result was False 2025-10-07 14:35:27.232653 | 2025-10-07 14:35:27.232765 | TASK [fetch-output : Set log path for single node] 2025-10-07 14:35:27.265348 | controller | ok 2025-10-07 14:35:27.272351 | 2025-10-07 14:35:27.272440 | LOOP [fetch-output : Ensure local output dirs] 2025-10-07 14:35:27.754863 | controller -> localhost | ok: "/var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/logs" 2025-10-07 14:35:28.038347 | controller -> localhost | changed: "/var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/artifacts" 2025-10-07 14:35:28.276546 | controller -> localhost | changed: "/var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/docs" 2025-10-07 14:35:28.311629 | 2025-10-07 14:35:28.311899 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-07 14:35:29.041143 | controller | changed: .d..t...... ./ 2025-10-07 14:35:29.041415 | controller | changed: All items complete 2025-10-07 14:35:29.041457 | 2025-10-07 14:35:29.538968 | controller | changed: .d..t...... ./ 2025-10-07 14:35:30.088655 | controller | changed: .d..t...... ./ 2025-10-07 14:35:30.121823 | 2025-10-07 14:35:30.122073 | TASK [include_role : fetch-output-openshift] 2025-10-07 14:35:30.138464 | controller | skipping: Conditional result was False 2025-10-07 14:35:30.147256 | 2025-10-07 14:35:30.147376 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-07 14:35:30.612356 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010480 2025-10-07 14:35:30.879186 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.011085 2025-10-07 14:35:30.933173 | 2025-10-07 14:35:30.933405 | PLAY [all] 2025-10-07 14:35:30.955372 | 2025-10-07 14:35:30.955498 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-07 14:35:31.435558 | controller | changed 2025-10-07 14:35:31.463179 | 2025-10-07 14:35:31.463288 | PLAY RECAP 2025-10-07 14:35:31.463355 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 14:35:31.463393 | 2025-10-07 14:35:31.565746 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 14:35:31.567394 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-07 14:35:32.135081 | 2025-10-07 14:35:32.135238 | PLAY [localhost] 2025-10-07 14:35:32.153305 | 2025-10-07 14:35:32.153393 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-07 14:35:32.588955 | localhost | changed 2025-10-07 14:35:32.594184 | 2025-10-07 14:35:32.594276 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-07 14:35:32.636891 | localhost | ok 2025-10-07 14:35:32.646972 | 2025-10-07 14:35:32.647119 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-07 14:35:33.032797 | localhost | changed 2025-10-07 14:35:33.038926 | 2025-10-07 14:35:33.039003 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-07 14:35:33.730027 | localhost | changed 2025-10-07 14:35:33.735401 | 2025-10-07 14:35:33.735987 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-07 14:35:34.140374 | localhost | Identity added: /var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/tmp/ansible.gtqsjxkr (/var/lib/zuul/builds/4bc0e502fb844aaabcb569edf09d52b8/work/tmp/ansible.gtqsjxkr) 2025-10-07 14:35:34.140588 | localhost | ok: Runtime: 0:00:00.011377 2025-10-07 14:35:34.147646 | 2025-10-07 14:35:34.148567 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-07 14:35:34.400521 | localhost | ok: Runtime: 0:00:00.006004 2025-10-07 14:35:34.410462 | 2025-10-07 14:35:34.410601 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-07 14:35:34.474056 | localhost | changed 2025-10-07 14:35:34.480078 | 2025-10-07 14:35:34.480164 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-07 14:35:34.896899 | localhost | changed 2025-10-07 14:35:34.936448 | 2025-10-07 14:35:34.936559 | PLAY [localhost] 2025-10-07 14:35:34.955404 | 2025-10-07 14:35:34.955499 | TASK [Generate bulk log download script] 2025-10-07 14:35:34.979264 | localhost | ok 2025-10-07 14:35:34.999209 | 2025-10-07 14:35:34.999345 | TASK [local-log-download : Check API endpoint is defined] 2025-10-07 14:35:35.040133 | localhost | ok: All assertions passed 2025-10-07 14:35:35.046827 | 2025-10-07 14:35:35.046942 | TASK [local-log-download : Create download script] 2025-10-07 14:35:35.476904 | localhost -> localhost | changed 2025-10-07 14:35:35.504587 | 2025-10-07 14:35:35.504726 | TASK [Register quick-download link] 2025-10-07 14:35:35.526805 | localhost | ok 2025-10-07 14:35:35.581359 | 2025-10-07 14:35:35.581454 | PLAY [logserver.rdoproject.org] 2025-10-07 14:35:35.591952 | 2025-10-07 14:35:35.592037 | TASK [Set zuul-log-path fact] 2025-10-07 14:35:35.609275 | logserver.rdoproject.org | ok 2025-10-07 14:35:35.619711 | 2025-10-07 14:35:35.619775 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 14:35:35.646669 | logserver.rdoproject.org | ok 2025-10-07 14:35:35.651787 | 2025-10-07 14:35:35.651853 | TASK [upload-logs : Create log directories] 2025-10-07 14:35:36.386443 | logserver.rdoproject.org | changed 2025-10-07 14:35:36.393687 | 2025-10-07 14:35:36.393827 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-07 14:35:36.690258 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007489 2025-10-07 14:35:36.697642 | 2025-10-07 14:35:36.697752 | TASK [upload-logs : Upload logs to log server] 2025-10-07 14:35:37.349170 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-07 14:35:37.355777 | 2025-10-07 14:35:37.355913 | LOOP [upload-logs : Compress console log and json output] 2025-10-07 14:35:37.401896 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 14:35:37.410821 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 14:35:37.425650 | 2025-10-07 14:35:37.425818 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-07 14:35:37.472547 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 14:35:37.472833 | 2025-10-07 14:35:37.475473 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 14:35:37.489577 | 2025-10-07 14:35:37.489710 | LOOP [upload-logs : Upload console log and json output]