2025-10-07 07:28:23.388080 | Job console starting... 2025-10-07 07:28:23.397505 | Updating repositories 2025-10-07 07:28:23.432831 | Preparing job workspace 2025-10-07 07:28:27.961798 | Running Ansible setup... 2025-10-07 07:28:32.188895 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 07:28:32.859782 | 2025-10-07 07:28:32.859917 | PLAY [localhost] 2025-10-07 07:28:32.870154 | 2025-10-07 07:28:32.870278 | TASK [Gathering Facts] 2025-10-07 07:28:33.936762 | localhost | ok 2025-10-07 07:28:33.950840 | 2025-10-07 07:28:33.951070 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-07 07:28:34.373213 | localhost -> localhost | changed 2025-10-07 07:28:34.379558 | 2025-10-07 07:28:34.379633 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-07 07:28:35.341648 | localhost -> localhost | changed 2025-10-07 07:28:35.350824 | 2025-10-07 07:28:35.350914 | TASK [Setup log path fact] 2025-10-07 07:28:35.370678 | localhost | ok 2025-10-07 07:28:35.382439 | 2025-10-07 07:28:35.382539 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 07:28:35.415213 | localhost | ok 2025-10-07 07:28:35.423794 | 2025-10-07 07:28:35.423921 | TASK [emit-job-header : Print job information] 2025-10-07 07:28:35.464681 | # Job Information 2025-10-07 07:28:35.464874 | Ansible Version: 2.15.12 2025-10-07 07:28:35.464917 | Job: cifmw-molecule-ci_lvms_storage 2025-10-07 07:28:35.464952 | Pipeline: github-check 2025-10-07 07:28:35.464982 | Executor: ze01.softwarefactory-project.io 2025-10-07 07:28:35.465040 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366 2025-10-07 07:28:35.465083 | Log URL (when completed): https://logserver.rdoproject.org/643/rdoproject.org/64315f8a51f54b4b98da6e42fa5e3565/ 2025-10-07 07:28:35.465116 | Event ID: 0b3e6df0-a34f-11f0-8d70-8afb6d89ca3c 2025-10-07 07:28:35.470734 | 2025-10-07 07:28:35.470925 | LOOP [emit-job-header : Print node information] 2025-10-07 07:28:35.599129 | localhost | ok: 2025-10-07 07:28:35.599309 | localhost | # Node Information 2025-10-07 07:28:35.599335 | localhost | Inventory Hostname: controller 2025-10-07 07:28:35.599358 | localhost | Hostname: np0005472989 2025-10-07 07:28:35.599541 | localhost | Username: zuul 2025-10-07 07:28:35.599570 | localhost | Distro: CentOS 9 2025-10-07 07:28:35.599589 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-07 07:28:35.599607 | localhost | Region: RegionOne 2025-10-07 07:28:35.599623 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-07 07:28:35.599640 | localhost | Product Name: OpenStack Nova 2025-10-07 07:28:35.599656 | localhost | Interface IP: 38.102.83.32 2025-10-07 07:28:35.630365 | 2025-10-07 07:28:35.630472 | PLAY [all] 2025-10-07 07:28:35.638504 | 2025-10-07 07:28:35.638812 | TASK [Gather network facts] 2025-10-07 07:28:36.131258 | controller | ok 2025-10-07 07:28:36.161212 | 2025-10-07 07:28:36.161340 | TASK [include_role : start-zuul-console] 2025-10-07 07:28:36.211214 | controller | ok 2025-10-07 07:28:36.224421 | 2025-10-07 07:28:36.224509 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-07 07:28:36.694158 | controller | ok 2025-10-07 07:28:36.707603 | 2025-10-07 07:28:36.707728 | TASK [include_role : add-build-sshkey] 2025-10-07 07:28:36.733682 | controller | ok 2025-10-07 07:28:36.757335 | 2025-10-07 07:28:36.757457 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-07 07:28:37.123368 | controller -> localhost | ok 2025-10-07 07:28:37.130286 | 2025-10-07 07:28:37.130395 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-07 07:28:37.159581 | controller | ok 2025-10-07 07:28:37.173624 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-07 07:28:37.179970 | 2025-10-07 07:28:37.180077 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-07 07:28:37.745818 | controller -> localhost | Generating public/private rsa key pair. 2025-10-07 07:28:37.746094 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/64315f8a51f54b4b98da6e42fa5e3565_id_rsa. 2025-10-07 07:28:37.746128 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/64315f8a51f54b4b98da6e42fa5e3565_id_rsa.pub. 2025-10-07 07:28:37.746151 | controller -> localhost | The key fingerprint is: 2025-10-07 07:28:37.746171 | controller -> localhost | SHA256:isgpBnBiioKhORBBs4f5ubhu3OeqV9vSuG6BDRrYuY4 zuul-build-sshkey 2025-10-07 07:28:37.746192 | controller -> localhost | The key's randomart image is: 2025-10-07 07:28:37.746211 | controller -> localhost | +---[RSA 3072]----+ 2025-10-07 07:28:37.746228 | controller -> localhost | |++ | 2025-10-07 07:28:37.746247 | controller -> localhost | | .= | 2025-10-07 07:28:37.746265 | controller -> localhost | |**.o | 2025-10-07 07:28:37.746284 | controller -> localhost | |X*=.. | 2025-10-07 07:28:37.746301 | controller -> localhost | |X o++ S | 2025-10-07 07:28:37.746320 | controller -> localhost | |o+o+.= . | 2025-10-07 07:28:37.746338 | controller -> localhost | |o==.o B | 2025-10-07 07:28:37.746358 | controller -> localhost | |E+oo * o | 2025-10-07 07:28:37.746377 | controller -> localhost | |o+o.*+o | 2025-10-07 07:28:37.746395 | controller -> localhost | +----[SHA256]-----+ 2025-10-07 07:28:37.746444 | controller -> localhost | ok: Runtime: 0:00:00.099734 2025-10-07 07:28:37.752355 | 2025-10-07 07:28:37.752428 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-07 07:28:37.773671 | controller | ok 2025-10-07 07:28:37.783802 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-07 07:28:37.792686 | 2025-10-07 07:28:37.792784 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-07 07:28:37.817610 | controller | skipping: Conditional result was False 2025-10-07 07:28:37.824518 | 2025-10-07 07:28:37.824607 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-07 07:28:38.326120 | controller | changed 2025-10-07 07:28:38.333431 | 2025-10-07 07:28:38.333554 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-07 07:28:38.612613 | controller | ok 2025-10-07 07:28:38.628668 | 2025-10-07 07:28:38.628862 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-07 07:28:39.562280 | controller | changed 2025-10-07 07:28:39.576678 | 2025-10-07 07:28:39.577090 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-07 07:28:40.523690 | controller | changed 2025-10-07 07:28:40.529444 | 2025-10-07 07:28:40.529540 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-07 07:28:40.554541 | controller | skipping: Conditional result was False 2025-10-07 07:28:40.560933 | 2025-10-07 07:28:40.561133 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-07 07:28:40.965570 | controller -> localhost | changed 2025-10-07 07:28:40.976839 | 2025-10-07 07:28:40.976972 | TASK [add-build-sshkey : Add back temp key] 2025-10-07 07:28:41.298278 | controller -> localhost | Identity added: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/64315f8a51f54b4b98da6e42fa5e3565_id_rsa (zuul-build-sshkey) 2025-10-07 07:28:41.298569 | controller -> localhost | ok: Runtime: 0:00:00.007662 2025-10-07 07:28:41.306373 | 2025-10-07 07:28:41.306454 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-07 07:28:41.740951 | controller | ok 2025-10-07 07:28:41.753256 | 2025-10-07 07:28:41.753361 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-07 07:28:41.779810 | controller | skipping: Conditional result was False 2025-10-07 07:28:41.790670 | 2025-10-07 07:28:41.790774 | TASK [include_role : validate-host] 2025-10-07 07:28:41.810293 | controller | ok 2025-10-07 07:28:41.835646 | 2025-10-07 07:28:41.835774 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-07 07:28:41.885521 | controller | ok 2025-10-07 07:28:41.890389 | 2025-10-07 07:28:41.890463 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-07 07:28:42.183832 | controller -> localhost | ok 2025-10-07 07:28:42.189828 | 2025-10-07 07:28:42.189904 | TASK [validate-host : Collect information about the host] 2025-10-07 07:28:43.074018 | controller | ok 2025-10-07 07:28:43.083686 | 2025-10-07 07:28:43.083769 | TASK [validate-host : Sanitize hostname] 2025-10-07 07:28:43.148565 | controller | ok 2025-10-07 07:28:43.159175 | 2025-10-07 07:28:43.159321 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-07 07:28:43.624592 | controller -> localhost | changed 2025-10-07 07:28:43.634655 | 2025-10-07 07:28:43.634801 | TASK [validate-host : Collect information about zuul worker] 2025-10-07 07:28:44.077839 | controller | ok 2025-10-07 07:28:44.092473 | 2025-10-07 07:28:44.092668 | TASK [validate-host : Write out all zuul information for each host] 2025-10-07 07:28:44.581378 | controller -> localhost | changed 2025-10-07 07:28:44.611507 | 2025-10-07 07:28:44.611703 | TASK [include_role : prepare-workspace-openshift] 2025-10-07 07:28:44.649207 | controller | skipping: Conditional result was False 2025-10-07 07:28:44.660524 | 2025-10-07 07:28:44.660664 | TASK [include_role : remove-zuul-sshkey] 2025-10-07 07:28:44.687667 | controller | skipping: Conditional result was False 2025-10-07 07:28:44.696664 | 2025-10-07 07:28:44.696815 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 07:28:44.999412 | controller | ok: "logs" 2025-10-07 07:28:44.999654 | controller | ok: All items complete 2025-10-07 07:28:44.999686 | 2025-10-07 07:28:45.267392 | controller | ok: "artifacts" 2025-10-07 07:28:45.501631 | controller | ok: "docs" 2025-10-07 07:28:45.510633 | 2025-10-07 07:28:45.510814 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 07:28:45.813152 | controller | changed: "logs" 2025-10-07 07:28:46.055177 | controller | changed: "artifacts" 2025-10-07 07:28:46.334303 | controller | changed: "docs" 2025-10-07 07:28:46.360744 | 2025-10-07 07:28:46.360834 | PLAY RECAP 2025-10-07 07:28:46.360877 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-07 07:28:46.360905 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 07:28:46.360924 | 2025-10-07 07:28:46.482986 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 07:28:46.483816 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 07:28:47.139944 | 2025-10-07 07:28:47.140100 | PLAY [localhost] 2025-10-07 07:28:47.156649 | 2025-10-07 07:28:47.156756 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-07 07:28:47.544582 | localhost | ok 2025-10-07 07:28:47.549965 | 2025-10-07 07:28:47.550094 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-07 07:28:48.251482 | localhost | changed 2025-10-07 07:28:48.272576 | 2025-10-07 07:28:48.272688 | PLAY [all] 2025-10-07 07:28:48.289890 | 2025-10-07 07:28:48.290003 | TASK [include_role : prepare-workspace] 2025-10-07 07:28:48.320136 | controller | ok 2025-10-07 07:28:48.335074 | 2025-10-07 07:28:48.335178 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-07 07:28:48.848106 | controller | ok 2025-10-07 07:28:48.858399 | 2025-10-07 07:28:48.858504 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-07 07:28:50.754764 | controller | Output suppressed because no_log was given 2025-10-07 07:28:50.791287 | 2025-10-07 07:28:50.791439 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 07:28:51.102107 | controller | changed: "logs" 2025-10-07 07:28:51.353457 | controller | changed: "artifacts" 2025-10-07 07:28:51.560551 | controller | changed: "docs" 2025-10-07 07:28:51.594376 | 2025-10-07 07:28:51.594554 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 07:28:51.915360 | controller | changed: "logs" 2025-10-07 07:28:51.915689 | controller | changed: All items complete 2025-10-07 07:28:51.915729 | 2025-10-07 07:28:52.188537 | controller | changed: "artifacts" 2025-10-07 07:28:52.470606 | controller | changed: "docs" 2025-10-07 07:28:52.488254 | 2025-10-07 07:28:52.488361 | TASK [Check if worker can sudo] 2025-10-07 07:28:53.022356 | controller | ok: Runtime: 0:00:00.060827 2025-10-07 07:28:53.030551 | 2025-10-07 07:28:53.030763 | TASK [configure-mirrors : Gather needed facts] 2025-10-07 07:28:53.088223 | controller | skipping: Conditional result was False 2025-10-07 07:28:53.107415 | 2025-10-07 07:28:53.107643 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-07 07:28:53.196593 | controller | ok 2025-10-07 07:28:53.213583 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-07 07:28:53.268839 | 2025-10-07 07:28:53.268962 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-07 07:28:53.574474 | controller | ok 2025-10-07 07:28:53.587932 | 2025-10-07 07:28:53.588131 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-07 07:28:53.644126 | controller | ok: "/var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-07 07:28:53.660128 | 2025-10-07 07:28:53.660319 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-07 07:28:54.661367 | controller | changed 2025-10-07 07:28:54.670473 | 2025-10-07 07:28:54.670700 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-07 07:28:54.743166 | controller | ok: "/var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-07 07:28:54.743420 | controller | ok: All items complete 2025-10-07 07:28:54.743460 | 2025-10-07 07:28:54.832696 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-07 07:28:54.843361 | 2025-10-07 07:28:54.843455 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-07 07:28:55.902773 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-07 07:28:56.846896 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-07 07:28:56.859336 | 2025-10-07 07:28:56.859495 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-07 07:28:57.382062 | controller | changed: section and option added 2025-10-07 07:28:57.405206 | 2025-10-07 07:28:57.405322 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-07 07:28:58.333778 | controller | 29 files removed 2025-10-07 07:28:58.334463 | controller | ok: Item: dnf clean all Runtime: 0:00:00.548438 2025-10-07 07:28:58.334565 | controller | changed: All items complete 2025-10-07 07:28:58.334638 | 2025-10-07 07:29:08.527544 | 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 07:29:08.527660 | controller | DNF version: 4.14.0 2025-10-07 07:29:08.527686 | controller | cachedir: /var/cache/dnf 2025-10-07 07:29:08.527709 | controller | Making cache files for all metadata files. 2025-10-07 07:29:08.527731 | controller | baseos: has expired and will be refreshed. 2025-10-07 07:29:08.527751 | controller | appstream: has expired and will be refreshed. 2025-10-07 07:29:08.527770 | controller | crb: has expired and will be refreshed. 2025-10-07 07:29:08.527812 | controller | extras-common: has expired and will be refreshed. 2025-10-07 07:29:08.527832 | controller | repo: downloading from remote: baseos 2025-10-07 07:29:08.527852 | controller | CentOS Stream 9 - BaseOS 64 MB/s | 8.8 MB 00:00 2025-10-07 07:29:08.527870 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-07 07:29:08.527889 | controller | repo: downloading from remote: appstream 2025-10-07 07:29:08.527908 | controller | CentOS Stream 9 - AppStream 94 MB/s | 25 MB 00:00 2025-10-07 07:29:08.527927 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-07 07:29:08.527944 | controller | repo: downloading from remote: crb 2025-10-07 07:29:08.527988 | controller | CentOS Stream 9 - CRB 75 MB/s | 7.1 MB 00:00 2025-10-07 07:29:08.528008 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-07 07:29:08.528047 | controller | repo: downloading from remote: extras-common 2025-10-07 07:29:08.528068 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-10-07 07:29:08.528085 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-07 07:29:08.528102 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-07 07:29:08.528118 | controller | Completion plugin: Generating completion cache... 2025-10-07 07:29:08.528134 | controller | Metadata cache created. 2025-10-07 07:29:08.528162 | controller | ok: Item: dnf makecache -v Runtime: 0:00:09.910424 2025-10-07 07:29:08.544785 | 2025-10-07 07:29:08.544887 | PLAY RECAP 2025-10-07 07:29:08.544943 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-07 07:29:08.544974 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 07:29:08.544993 | 2025-10-07 07:29:08.688172 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 07:29:08.689565 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 07:29:09.431185 | 2025-10-07 07:29:09.431340 | PLAY [all] 2025-10-07 07:29:09.455836 | 2025-10-07 07:29:09.455983 | TASK [Install binary dependencies] 2025-10-07 07:29:09.507235 | controller | ok 2025-10-07 07:29:09.529956 | 2025-10-07 07:29:09.530143 | TASK [bindep : Include find tasks] 2025-10-07 07:29:09.560867 | controller | ok 2025-10-07 07:29:09.569054 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-07 07:29:09.575734 | 2025-10-07 07:29:09.575826 | TASK [bindep : Look for bindep.txt] 2025-10-07 07:29:09.984280 | controller | ok 2025-10-07 07:29:09.993918 | 2025-10-07 07:29:09.994088 | TASK [bindep : Define bindep_file fact] 2025-10-07 07:29:10.065118 | controller | ok 2025-10-07 07:29:10.070680 | 2025-10-07 07:29:10.070784 | TASK [bindep : Look for other-requirements.txt] 2025-10-07 07:29:10.096622 | controller | skipping: Conditional result was False 2025-10-07 07:29:10.105780 | 2025-10-07 07:29:10.105977 | TASK [bindep : Define bindep_file fact] 2025-10-07 07:29:10.134264 | controller | skipping: Conditional result was False 2025-10-07 07:29:10.141242 | 2025-10-07 07:29:10.141348 | TASK [bindep : Look for bindep fallback file] 2025-10-07 07:29:10.165705 | controller | skipping: Conditional result was False 2025-10-07 07:29:10.172288 | 2025-10-07 07:29:10.172402 | TASK [bindep : Define bindep_file fact] 2025-10-07 07:29:10.196741 | controller | skipping: Conditional result was False 2025-10-07 07:29:10.203085 | 2025-10-07 07:29:10.203190 | TASK [bindep : Include bindep tasks] 2025-10-07 07:29:10.234565 | controller | ok 2025-10-07 07:29:10.241507 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-07 07:29:10.250193 | 2025-10-07 07:29:10.250313 | TASK [bindep : Look for bindep command] 2025-10-07 07:29:10.275129 | controller | skipping: Conditional result was False 2025-10-07 07:29:10.281616 | 2025-10-07 07:29:10.281728 | TASK [bindep : Check for system bindep] 2025-10-07 07:29:10.830479 | controller | ok: Runtime: 0:00:00.007743 2025-10-07 07:29:10.840002 | 2025-10-07 07:29:10.840152 | TASK [bindep : Define bindep_command fact] 2025-10-07 07:29:10.872976 | controller | skipping: Conditional result was False 2025-10-07 07:29:10.885522 | 2025-10-07 07:29:10.885656 | TASK [bindep : Include install tasks] 2025-10-07 07:29:10.943997 | controller | ok 2025-10-07 07:29:10.962365 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-07 07:29:10.989060 | 2025-10-07 07:29:10.989942 | TASK [bindep : Create temp dir for bindep] 2025-10-07 07:29:11.395119 | controller | changed 2025-10-07 07:29:11.406706 | 2025-10-07 07:29:11.406836 | TASK [Ensure we have pip dependencies] 2025-10-07 07:29:11.437403 | controller | ok 2025-10-07 07:29:11.490007 | 2025-10-07 07:29:11.490198 | TASK [ensure-pip : Check if pip is installed] 2025-10-07 03:29:11.832307 | controller | /usr/bin/pip3 2025-10-07 03:29:11.875292 | controller | /usr/bin/python3: No module named wheel 2025-10-07 07:29:12.034379 | controller | ok: Runtime: 0:00:00.058048 2025-10-07 07:29:12.041548 | 2025-10-07 07:29:12.041616 | LOOP [ensure-pip : Install pip from packages] 2025-10-07 07:29:12.104356 | controller | ok: "/var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-07 07:29:12.123207 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-07 07:29:12.138582 | 2025-10-07 07:29:12.138721 | TASK [ensure-pip : Install Python 3 pip] 2025-10-07 07:29:14.745844 | controller | changed 2025-10-07 07:29:14.755164 | 2025-10-07 07:29:14.755288 | TASK [ensure-pip : Check for EPEL repository] 2025-10-07 07:29:14.831632 | controller | skipping: Conditional result was False 2025-10-07 07:29:14.839272 | 2025-10-07 07:29:14.839394 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-07 07:29:14.895994 | controller | skipping: Conditional result was False 2025-10-07 07:29:14.903471 | 2025-10-07 07:29:14.903613 | TASK [ensure-pip : Install Python 2 pip] 2025-10-07 07:29:14.939766 | controller | skipping: Conditional result was False 2025-10-07 07:29:14.947096 | 2025-10-07 07:29:14.947232 | TASK [ensure-pip : Ensure setuptools] 2025-10-07 07:29:14.972351 | controller | skipping: Conditional result was False 2025-10-07 07:29:14.979584 | 2025-10-07 07:29:14.979695 | TASK [ensure-pip : Check for ensurepip module] 2025-10-07 07:29:15.509620 | controller | skipping: Conditional result was False 2025-10-07 07:29:15.517062 | 2025-10-07 07:29:15.517170 | TASK [ensure-pip : Ensure python3-venv] 2025-10-07 07:29:15.541956 | controller | skipping: Conditional result was False 2025-10-07 07:29:15.548208 | 2025-10-07 07:29:15.548279 | TASK [ensure-pip : Install pip from source] 2025-10-07 07:29:15.562191 | controller | skipping: Conditional result was False 2025-10-07 07:29:15.568897 | 2025-10-07 07:29:15.568985 | TASK [ensure-pip : Probe for venv python full path] 2025-10-07 03:29:15.846440 | controller | /usr/bin/python3 2025-10-07 07:29:16.101851 | controller | ok: Runtime: 0:00:00.008168 2025-10-07 07:29:16.109936 | 2025-10-07 07:29:16.110098 | TASK [ensure-pip : Set host default] 2025-10-07 07:29:16.185520 | controller | ok 2025-10-07 07:29:16.192876 | 2025-10-07 07:29:16.192998 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-07 07:29:16.248459 | controller | ok 2025-10-07 07:29:16.263149 | 2025-10-07 07:29:16.263293 | TASK [bindep : Install bindep into temporary venv] 2025-10-07 07:29:20.234386 | controller | changed 2025-10-07 07:29:20.246509 | 2025-10-07 07:29:20.246656 | TASK [bindep : Define bindep_command] 2025-10-07 07:29:20.284503 | controller | ok 2025-10-07 07:29:20.299230 | 2025-10-07 07:29:20.299370 | LOOP [bindep : Include package tasks] 2025-10-07 07:29:20.365269 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-07 07:29:20.365502 | controller | ok: All items complete 2025-10-07 07:29:20.365545 | 2025-10-07 07:29:20.379427 | controller | included: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-07 07:29:20.392322 | 2025-10-07 07:29:20.392428 | TASK [bindep : Define bindep_run fact] 2025-10-07 07:29:20.421599 | controller | ok 2025-10-07 07:29:20.427905 | 2025-10-07 07:29:20.428040 | TASK [bindep : Get list of packages to install from bindep] 2025-10-07 03:29:21.684188 | controller | podman 2025-10-07 03:29:21.709782 | controller | python3-jmespath 2025-10-07 03:29:21.709995 | controller | python3-libvirt 2025-10-07 03:29:21.710015 | controller | python3-lxml 2025-10-07 03:29:21.710030 | controller | python3-netaddr 2025-10-07 07:29:21.975850 | controller | ok: Runtime: 0:00:00.999699 2025-10-07 07:29:21.989734 | 2025-10-07 07:29:21.989937 | TASK [bindep : Install distro packages from bindep] 2025-10-07 07:30:22.594232 | controller | changed 2025-10-07 07:30:22.602473 | 2025-10-07 07:30:22.602594 | TASK [bindep : Check that packages are installed] 2025-10-07 07:30:24.180952 | controller | ok: Runtime: 0:00:01.236710 2025-10-07 07:30:24.194262 | 2025-10-07 07:30:24.194458 | TASK [bindep : Fail if we cannot install all packages] 2025-10-07 07:30:24.232355 | controller | skipping: Conditional result was False 2025-10-07 07:30:24.257320 | 2025-10-07 07:30:24.257548 | TASK [Run test-setup role] 2025-10-07 07:30:24.287984 | controller | ok 2025-10-07 07:30:24.325997 | 2025-10-07 07:30:24.326186 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-07 07:30:24.576278 | controller | ok 2025-10-07 07:30:24.584467 | 2025-10-07 07:30:24.584595 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-07 07:30:25.127781 | controller | skipping: Conditional result was False 2025-10-07 07:30:25.177381 | 2025-10-07 07:30:25.177587 | TASK [bindep : Remove bindep temp dir] 2025-10-07 07:30:25.636854 | controller | ok 2025-10-07 07:30:25.648535 | 2025-10-07 07:30:25.648629 | PLAY RECAP 2025-10-07 07:30:25.648670 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-07 07:30:25.648691 | 2025-10-07 07:30:25.754714 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 07:30:25.755615 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 07:30:26.349531 | 2025-10-07 07:30:26.349646 | PLAY [all] 2025-10-07 07:30:26.370175 | 2025-10-07 07:30:26.370279 | TASK [Abort when test_command variable is undefined] 2025-10-07 07:30:26.405163 | controller | skipping: Conditional result was False 2025-10-07 07:30:26.412057 | 2025-10-07 07:30:26.412152 | TASK [Convert test_command to list] 2025-10-07 07:30:26.446081 | controller | skipping: Conditional result was False 2025-10-07 07:30:26.453050 | 2025-10-07 07:30:26.453120 | TASK [Use test_command list] 2025-10-07 07:30:26.510385 | controller | ok 2025-10-07 07:30:26.523738 | 2025-10-07 07:30:26.523884 | LOOP [Run test_command] 2025-10-07 07:30:26.967471 | controller | no check to run 2025-10-07 07:30:26.967709 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007299 2025-10-07 07:30:27.024922 | 2025-10-07 07:30:27.025061 | PLAY RECAP 2025-10-07 07:30:27.025119 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 07:30:27.025147 | 2025-10-07 07:30:27.133654 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 07:30:27.134985 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 07:30:27.720745 | 2025-10-07 07:30:27.720861 | PLAY [all] 2025-10-07 07:30:27.742562 | 2025-10-07 07:30:27.742686 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-07 07:30:28.203215 | controller | changed: non-zero return code 2025-10-07 07:30:28.210776 | 2025-10-07 07:30:28.210912 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-07 07:30:28.237164 | controller | skipping: Conditional result was False 2025-10-07 07:30:28.246320 | 2025-10-07 07:30:28.246480 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-07 07:30:28.280844 | 2025-10-07 07:30:28.281065 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-07 07:30:28.315593 | 2025-10-07 07:30:28.315797 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-07 07:30:28.330929 | controller | skipping: Conditional result was False 2025-10-07 07:30:28.340268 | 2025-10-07 07:30:28.340427 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-07 07:30:28.365515 | 2025-10-07 07:30:28.366164 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-07 07:30:28.381369 | controller | skipping: Conditional result was False 2025-10-07 07:30:28.389924 | 2025-10-07 07:30:28.390108 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-07 07:30:28.404847 | controller | skipping: Conditional result was False 2025-10-07 07:30:28.414213 | 2025-10-07 07:30:28.414371 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-07 07:30:28.430209 | controller | skipping: Conditional result was False 2025-10-07 07:30:28.466717 | 2025-10-07 07:30:28.466821 | PLAY RECAP 2025-10-07 07:30:28.466863 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-07 07:30:28.466884 | 2025-10-07 07:30:28.595400 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 07:30:28.596526 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 07:30:29.257759 | 2025-10-07 07:30:29.257899 | PLAY [all] 2025-10-07 07:30:29.279885 | 2025-10-07 07:30:29.280044 | TASK [include_role : fetch-output] 2025-10-07 07:30:29.311936 | controller | ok 2025-10-07 07:30:29.335094 | 2025-10-07 07:30:29.335236 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-07 07:30:29.401555 | controller | skipping: Conditional result was False 2025-10-07 07:30:29.409530 | 2025-10-07 07:30:29.409667 | TASK [fetch-output : Set log path for single node] 2025-10-07 07:30:29.452171 | controller | ok 2025-10-07 07:30:29.459127 | 2025-10-07 07:30:29.459275 | LOOP [fetch-output : Ensure local output dirs] 2025-10-07 07:30:29.940207 | controller -> localhost | ok: "/var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/logs" 2025-10-07 07:30:30.219032 | controller -> localhost | changed: "/var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/artifacts" 2025-10-07 07:30:30.439395 | controller -> localhost | changed: "/var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/docs" 2025-10-07 07:30:30.452424 | 2025-10-07 07:30:30.452623 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-07 07:30:31.234560 | controller | changed: .d..t...... ./ 2025-10-07 07:30:31.236094 | controller | changed: All items complete 2025-10-07 07:30:31.236151 | 2025-10-07 07:30:31.733863 | controller | changed: .d..t...... ./ 2025-10-07 07:30:32.226244 | controller | changed: .d..t...... ./ 2025-10-07 07:30:32.244217 | 2025-10-07 07:30:32.244380 | TASK [include_role : fetch-output-openshift] 2025-10-07 07:30:32.260798 | controller | skipping: Conditional result was False 2025-10-07 07:30:32.270629 | 2025-10-07 07:30:32.270787 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-07 07:30:32.704707 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010078 2025-10-07 07:30:32.961031 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.011267 2025-10-07 07:30:32.997117 | 2025-10-07 07:30:32.997329 | PLAY [all] 2025-10-07 07:30:33.012312 | 2025-10-07 07:30:33.012394 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-07 07:30:33.516588 | controller | changed 2025-10-07 07:30:33.581279 | 2025-10-07 07:30:33.581589 | PLAY RECAP 2025-10-07 07:30:33.581681 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 07:30:33.581724 | 2025-10-07 07:30:33.701708 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 07:30:33.702512 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-07 07:30:34.372999 | 2025-10-07 07:30:34.373157 | PLAY [localhost] 2025-10-07 07:30:34.392698 | 2025-10-07 07:30:34.392815 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-07 07:30:34.785083 | localhost | changed 2025-10-07 07:30:34.790127 | 2025-10-07 07:30:34.790246 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-07 07:30:34.829142 | localhost | ok 2025-10-07 07:30:34.837702 | 2025-10-07 07:30:34.837822 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-07 07:30:35.256380 | localhost | changed 2025-10-07 07:30:35.268355 | 2025-10-07 07:30:35.268506 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-07 07:30:35.931668 | localhost | changed 2025-10-07 07:30:35.937733 | 2025-10-07 07:30:35.937867 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-07 07:30:36.389947 | localhost | Identity added: /var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/tmp/ansible.rdd58onm (/var/lib/zuul/builds/64315f8a51f54b4b98da6e42fa5e3565/work/tmp/ansible.rdd58onm) 2025-10-07 07:30:36.390225 | localhost | ok: Runtime: 0:00:00.014668 2025-10-07 07:30:36.394956 | 2025-10-07 07:30:36.396057 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-07 07:30:36.661651 | localhost | ok: Runtime: 0:00:00.006385 2025-10-07 07:30:36.667177 | 2025-10-07 07:30:36.667288 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-07 07:30:36.727895 | localhost | changed 2025-10-07 07:30:36.732337 | 2025-10-07 07:30:36.732434 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-07 07:30:37.173514 | localhost | changed 2025-10-07 07:30:37.208532 | 2025-10-07 07:30:37.208716 | PLAY [localhost] 2025-10-07 07:30:37.229062 | 2025-10-07 07:30:37.229225 | TASK [Generate bulk log download script] 2025-10-07 07:30:37.249819 | localhost | ok 2025-10-07 07:30:37.264073 | 2025-10-07 07:30:37.264227 | TASK [local-log-download : Check API endpoint is defined] 2025-10-07 07:30:37.304637 | localhost | ok: All assertions passed 2025-10-07 07:30:37.309655 | 2025-10-07 07:30:37.309752 | TASK [local-log-download : Create download script] 2025-10-07 07:30:37.734150 | localhost -> localhost | changed 2025-10-07 07:30:37.743561 | 2025-10-07 07:30:37.743678 | TASK [Register quick-download link] 2025-10-07 07:30:37.762003 | localhost | ok 2025-10-07 07:30:37.810508 | 2025-10-07 07:30:37.810607 | PLAY [logserver.rdoproject.org] 2025-10-07 07:30:37.821349 | 2025-10-07 07:30:37.821467 | TASK [Set zuul-log-path fact] 2025-10-07 07:30:37.839470 | logserver.rdoproject.org | ok 2025-10-07 07:30:37.849965 | 2025-10-07 07:30:37.850108 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 07:30:37.887628 | logserver.rdoproject.org | ok 2025-10-07 07:30:37.894078 | 2025-10-07 07:30:37.894200 | TASK [upload-logs : Create log directories] 2025-10-07 07:30:38.581564 | logserver.rdoproject.org | changed 2025-10-07 07:30:38.587720 | 2025-10-07 07:30:38.587866 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-07 07:30:38.895883 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008191 2025-10-07 07:30:38.903082 | 2025-10-07 07:30:38.903217 | TASK [upload-logs : Upload logs to log server] 2025-10-07 07:30:39.590071 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-07 07:30:39.594613 | 2025-10-07 07:30:39.594776 | LOOP [upload-logs : Compress console log and json output] 2025-10-07 07:30:39.652108 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 07:30:39.661845 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 07:30:39.676950 | 2025-10-07 07:30:39.677320 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-07 07:30:39.734269 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 07:30:39.734561 | 2025-10-07 07:30:39.740423 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 07:30:39.748272 | 2025-10-07 07:30:39.748424 | LOOP [upload-logs : Upload console log and json output]