2025-12-03 11:16:18.012886 | Job console starting... 2025-12-03 11:16:18.027414 | Updating repositories 2025-12-03 11:16:18.059887 | Preparing job workspace 2025-12-03 11:16:22.776030 | Running Ansible setup... 2025-12-03 11:16:27.323223 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-03 11:16:27.932101 | 2025-12-03 11:16:27.932213 | PLAY [localhost] 2025-12-03 11:16:27.940809 | 2025-12-03 11:16:27.940890 | TASK [Gathering Facts] 2025-12-03 11:16:28.852246 | localhost | ok 2025-12-03 11:16:28.866345 | 2025-12-03 11:16:28.866444 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-03 11:16:29.277502 | localhost -> localhost | changed 2025-12-03 11:16:29.285243 | 2025-12-03 11:16:29.285364 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-03 11:16:30.196993 | localhost -> localhost | changed 2025-12-03 11:16:30.217555 | 2025-12-03 11:16:30.217720 | TASK [Setup log path fact] 2025-12-03 11:16:30.242603 | localhost | ok 2025-12-03 11:16:30.266678 | 2025-12-03 11:16:30.266827 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-03 11:16:30.296875 | localhost | ok 2025-12-03 11:16:30.308124 | 2025-12-03 11:16:30.308238 | TASK [emit-job-header : Print job information] 2025-12-03 11:16:30.348759 | # Job Information 2025-12-03 11:16:30.348956 | Ansible Version: 2.15.12 2025-12-03 11:16:30.349005 | Job: cifmw-molecule-ci_lvms_storage 2025-12-03 11:16:30.349040 | Pipeline: github-check 2025-12-03 11:16:30.349066 | Executor: ze03.softwarefactory-project.io 2025-12-03 11:16:30.349090 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451 2025-12-03 11:16:30.349115 | Log URL (when completed): https://logserver.rdoproject.org/91b/rdoproject.org/91b96751da524c69a5579d6d010b4670/ 2025-12-03 11:16:30.349140 | Event ID: 4ab514e0-d039-11f0-81e0-fb882bdc02c6 2025-12-03 11:16:30.354583 | 2025-12-03 11:16:30.354675 | LOOP [emit-job-header : Print node information] 2025-12-03 11:16:30.467105 | localhost | ok: 2025-12-03 11:16:30.467416 | localhost | # Node Information 2025-12-03 11:16:30.467480 | localhost | Inventory Hostname: controller 2025-12-03 11:16:30.467547 | localhost | Hostname: np0005543698 2025-12-03 11:16:30.467596 | localhost | Username: zuul 2025-12-03 11:16:30.467641 | localhost | Distro: CentOS 9 2025-12-03 11:16:30.467680 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-03 11:16:30.467718 | localhost | Region: RegionOne 2025-12-03 11:16:30.467796 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-03 11:16:30.467835 | localhost | Product Name: OpenStack Nova 2025-12-03 11:16:30.467869 | localhost | Interface IP: 38.102.83.159 2025-12-03 11:16:30.493588 | 2025-12-03 11:16:30.493696 | PLAY [all] 2025-12-03 11:16:30.506163 | 2025-12-03 11:16:30.506273 | TASK [Gather network facts] 2025-12-03 11:16:31.025452 | controller | ok 2025-12-03 11:16:31.059746 | 2025-12-03 11:16:31.059844 | TASK [include_role : start-zuul-console] 2025-12-03 11:16:31.084232 | controller | ok 2025-12-03 11:16:31.100915 | 2025-12-03 11:16:31.102075 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-03 11:16:31.548815 | controller | ok 2025-12-03 11:16:31.573263 | 2025-12-03 11:16:31.573435 | TASK [include_role : add-build-sshkey] 2025-12-03 11:16:31.607326 | controller | ok 2025-12-03 11:16:31.626641 | 2025-12-03 11:16:31.626769 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-03 11:16:31.895074 | controller -> localhost | ok 2025-12-03 11:16:31.902456 | 2025-12-03 11:16:31.902538 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-03 11:16:31.941556 | controller | ok 2025-12-03 11:16:31.955775 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-03 11:16:31.966472 | 2025-12-03 11:16:31.966547 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-03 11:16:32.512870 | controller -> localhost | Generating public/private rsa key pair. 2025-12-03 11:16:32.513081 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/91b96751da524c69a5579d6d010b4670_id_rsa. 2025-12-03 11:16:32.513113 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/91b96751da524c69a5579d6d010b4670_id_rsa.pub. 2025-12-03 11:16:32.513136 | controller -> localhost | The key fingerprint is: 2025-12-03 11:16:32.513156 | controller -> localhost | SHA256:pKx8aW2YYStWU2qs8L04LX8aAUlfPLTo/MZyPQSFkng zuul-build-sshkey 2025-12-03 11:16:32.513175 | controller -> localhost | The key's randomart image is: 2025-12-03 11:16:32.513193 | controller -> localhost | +---[RSA 3072]----+ 2025-12-03 11:16:32.513210 | controller -> localhost | | .. +o.. | 2025-12-03 11:16:32.513228 | controller -> localhost | | ..oEo+o | 2025-12-03 11:16:32.513246 | controller -> localhost | | o.o.=. | 2025-12-03 11:16:32.513264 | controller -> localhost | | * = . | 2025-12-03 11:16:32.513281 | controller -> localhost | | . # S . | 2025-12-03 11:16:32.513299 | controller -> localhost | | + B % o | 2025-12-03 11:16:32.513316 | controller -> localhost | | B.@ B o | 2025-12-03 11:16:32.513333 | controller -> localhost | | .o=.B. . | 2025-12-03 11:16:32.513350 | controller -> localhost | | .++o | 2025-12-03 11:16:32.513367 | controller -> localhost | +----[SHA256]-----+ 2025-12-03 11:16:32.513410 | controller -> localhost | ok: Runtime: 0:00:00.128899 2025-12-03 11:16:32.519404 | 2025-12-03 11:16:32.519467 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-03 11:16:32.549501 | controller | ok 2025-12-03 11:16:32.561447 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-03 11:16:32.585436 | 2025-12-03 11:16:32.585527 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-03 11:16:32.609924 | controller | skipping: Conditional result was False 2025-12-03 11:16:32.616030 | 2025-12-03 11:16:32.616099 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-03 11:16:33.108540 | controller | changed 2025-12-03 11:16:33.120590 | 2025-12-03 11:16:33.120931 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-03 11:16:33.425263 | controller | ok 2025-12-03 11:16:33.436932 | 2025-12-03 11:16:33.437069 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-03 11:16:34.931707 | controller | changed 2025-12-03 11:16:34.942617 | 2025-12-03 11:16:34.942789 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-03 11:16:35.934827 | controller | changed 2025-12-03 11:16:35.940070 | 2025-12-03 11:16:35.940140 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-03 11:16:35.976279 | controller | skipping: Conditional result was False 2025-12-03 11:16:35.991284 | 2025-12-03 11:16:35.991431 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-03 11:16:36.394846 | controller -> localhost | changed 2025-12-03 11:16:36.404504 | 2025-12-03 11:16:36.404573 | TASK [add-build-sshkey : Add back temp key] 2025-12-03 11:16:36.674448 | controller -> localhost | Identity added: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/91b96751da524c69a5579d6d010b4670_id_rsa (zuul-build-sshkey) 2025-12-03 11:16:36.674876 | controller -> localhost | ok: Runtime: 0:00:00.008715 2025-12-03 11:16:36.690569 | 2025-12-03 11:16:36.690797 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-03 11:16:37.085776 | controller | ok 2025-12-03 11:16:37.097600 | 2025-12-03 11:16:37.097872 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-03 11:16:37.126105 | controller | skipping: Conditional result was False 2025-12-03 11:16:37.147877 | 2025-12-03 11:16:37.148044 | TASK [include_role : validate-host] 2025-12-03 11:16:37.171066 | controller | ok 2025-12-03 11:16:37.200793 | 2025-12-03 11:16:37.200938 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-03 11:16:37.232300 | controller | ok 2025-12-03 11:16:37.239323 | 2025-12-03 11:16:37.239410 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-03 11:16:37.520931 | controller -> localhost | ok 2025-12-03 11:16:37.568261 | 2025-12-03 11:16:37.568462 | TASK [validate-host : Collect information about the host] 2025-12-03 11:16:38.393286 | controller | ok 2025-12-03 11:16:38.408873 | 2025-12-03 11:16:38.408979 | TASK [validate-host : Sanitize hostname] 2025-12-03 11:16:38.460459 | controller | ok 2025-12-03 11:16:38.467616 | 2025-12-03 11:16:38.467759 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-03 11:16:38.952255 | controller -> localhost | changed 2025-12-03 11:16:38.969194 | 2025-12-03 11:16:38.969394 | TASK [validate-host : Collect information about zuul worker] 2025-12-03 11:16:39.414451 | controller | ok 2025-12-03 11:16:39.422085 | 2025-12-03 11:16:39.422169 | TASK [validate-host : Write out all zuul information for each host] 2025-12-03 11:16:39.926393 | controller -> localhost | changed 2025-12-03 11:16:39.949620 | 2025-12-03 11:16:39.949917 | TASK [include_role : prepare-workspace-openshift] 2025-12-03 11:16:39.974665 | controller | skipping: Conditional result was False 2025-12-03 11:16:39.982696 | 2025-12-03 11:16:39.982831 | TASK [include_role : remove-zuul-sshkey] 2025-12-03 11:16:40.009209 | controller | skipping: Conditional result was False 2025-12-03 11:16:40.017144 | 2025-12-03 11:16:40.017233 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-03 11:16:40.282949 | controller | ok: "logs" 2025-12-03 11:16:40.283219 | controller | ok: All items complete 2025-12-03 11:16:40.283256 | 2025-12-03 11:16:41.006718 | controller | ok: "artifacts" 2025-12-03 11:16:41.226377 | controller | ok: "docs" 2025-12-03 11:16:41.236407 | 2025-12-03 11:16:41.236556 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-03 11:16:41.502688 | controller | changed: "logs" 2025-12-03 11:16:41.745064 | controller | changed: "artifacts" 2025-12-03 11:16:41.990627 | controller | changed: "docs" 2025-12-03 11:16:42.024380 | 2025-12-03 11:16:42.024486 | PLAY RECAP 2025-12-03 11:16:42.024528 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-03 11:16:42.024554 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-03 11:16:42.024573 | 2025-12-03 11:16:42.148614 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-03 11:16:42.149542 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-03 11:16:43.844205 | 2025-12-03 11:16:43.844325 | PLAY [localhost] 2025-12-03 11:16:43.861552 | 2025-12-03 11:16:43.861664 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-03 11:16:44.277318 | localhost | ok 2025-12-03 11:16:44.286344 | 2025-12-03 11:16:44.286474 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-03 11:16:45.010937 | localhost | changed 2025-12-03 11:16:45.036341 | 2025-12-03 11:16:45.036479 | PLAY [all] 2025-12-03 11:16:45.052962 | 2025-12-03 11:16:45.053039 | TASK [include_role : prepare-workspace] 2025-12-03 11:16:45.082362 | controller | ok 2025-12-03 11:16:45.098265 | 2025-12-03 11:16:45.098363 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-03 11:16:45.514783 | controller | ok 2025-12-03 11:16:45.534783 | 2025-12-03 11:16:45.534906 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-03 11:16:47.621358 | controller | Output suppressed because no_log was given 2025-12-03 11:16:47.636468 | 2025-12-03 11:16:47.636692 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-03 11:16:47.935819 | controller | changed: "logs" 2025-12-03 11:16:48.200645 | controller | changed: "artifacts" 2025-12-03 11:16:48.443946 | controller | changed: "docs" 2025-12-03 11:16:48.476000 | 2025-12-03 11:16:48.476163 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-03 11:16:48.751901 | controller | changed: "logs" 2025-12-03 11:16:48.752143 | controller | changed: All items complete 2025-12-03 11:16:48.752171 | 2025-12-03 11:16:49.006400 | controller | changed: "artifacts" 2025-12-03 11:16:49.246296 | controller | changed: "docs" 2025-12-03 11:16:49.272710 | 2025-12-03 11:16:49.272877 | TASK [Check if worker can sudo] 2025-12-03 11:16:49.835179 | controller | ok: Runtime: 0:00:00.060156 2025-12-03 11:16:49.848198 | 2025-12-03 11:16:49.848344 | TASK [configure-mirrors : Gather needed facts] 2025-12-03 11:16:49.982215 | controller | skipping: Conditional result was False 2025-12-03 11:16:49.997608 | 2025-12-03 11:16:49.997850 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-03 11:16:50.156869 | controller | ok 2025-12-03 11:16:50.168880 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-03 11:16:50.177979 | 2025-12-03 11:16:50.178138 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-03 11:16:50.530994 | controller | ok 2025-12-03 11:16:50.548281 | 2025-12-03 11:16:50.548448 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-03 11:16:50.607902 | controller | ok: "/var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-03 11:16:50.634576 | 2025-12-03 11:16:50.634934 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-03 11:16:51.639480 | controller | changed 2025-12-03 11:16:51.645136 | 2025-12-03 11:16:51.645200 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-03 11:16:51.702291 | controller | ok: "/var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-03 11:16:51.702452 | controller | ok: All items complete 2025-12-03 11:16:51.702478 | 2025-12-03 11:16:51.746802 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-03 11:16:51.754166 | 2025-12-03 11:16:51.754250 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-03 11:16:52.737862 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-03 11:16:53.689019 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-03 11:16:53.699334 | 2025-12-03 11:16:53.699434 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-03 11:16:54.225849 | controller | changed: section and option added 2025-12-03 11:16:54.246483 | 2025-12-03 11:16:54.246599 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-03 11:16:55.000693 | controller | 29 files removed 2025-12-03 11:16:55.007835 | controller | ok: Item: dnf clean all Runtime: 0:00:00.417878 2025-12-03 11:16:55.007941 | controller | changed: All items complete 2025-12-03 11:16:55.007966 | 2025-12-03 11:17:11.283976 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-03 11:17:11.284086 | controller | DNF version: 4.14.0 2025-12-03 11:17:11.284112 | controller | cachedir: /var/cache/dnf 2025-12-03 11:17:11.284132 | controller | Making cache files for all metadata files. 2025-12-03 11:17:11.284150 | controller | baseos: has expired and will be refreshed. 2025-12-03 11:17:11.284168 | controller | appstream: has expired and will be refreshed. 2025-12-03 11:17:11.284185 | controller | crb: has expired and will be refreshed. 2025-12-03 11:17:11.284211 | controller | extras-common: has expired and will be refreshed. 2025-12-03 11:17:11.284229 | controller | repo: downloading from remote: baseos 2025-12-03 11:17:11.284246 | controller | CentOS Stream 9 - BaseOS 59 MB/s | 8.8 MB 00:00 2025-12-03 11:17:11.284264 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-03 11:17:11.284281 | controller | repo: downloading from remote: appstream 2025-12-03 11:17:11.284298 | controller | CentOS Stream 9 - AppStream 31 MB/s | 25 MB 00:00 2025-12-03 11:17:11.284314 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-03 11:17:11.284330 | controller | repo: downloading from remote: crb 2025-12-03 11:17:11.284346 | controller | CentOS Stream 9 - CRB 24 MB/s | 7.3 MB 00:00 2025-12-03 11:17:11.284364 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-03 11:17:11.284380 | controller | repo: downloading from remote: extras-common 2025-12-03 11:17:11.284397 | controller | CentOS Stream 9 - Extras packages 81 kB/s | 20 kB 00:00 2025-12-03 11:17:11.284414 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-03 11:17:11.284430 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-03 11:17:11.284446 | controller | Completion plugin: Generating completion cache... 2025-12-03 11:17:11.284463 | controller | Metadata cache created. 2025-12-03 11:17:11.284488 | controller | ok: Item: dnf makecache -v Runtime: 0:00:16.014773 2025-12-03 11:17:11.304687 | 2025-12-03 11:17:11.304804 | PLAY RECAP 2025-12-03 11:17:11.304846 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-03 11:17:11.304873 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-03 11:17:11.304892 | 2025-12-03 11:17:11.441308 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-03 11:17:11.442426 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-03 11:17:12.090975 | 2025-12-03 11:17:12.091095 | PLAY [all] 2025-12-03 11:17:12.114194 | 2025-12-03 11:17:12.114284 | TASK [Install binary dependencies] 2025-12-03 11:17:12.164908 | controller | ok 2025-12-03 11:17:12.184556 | 2025-12-03 11:17:12.184676 | TASK [bindep : Include find tasks] 2025-12-03 11:17:12.212980 | controller | ok 2025-12-03 11:17:12.221137 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-03 11:17:12.227191 | 2025-12-03 11:17:12.227254 | TASK [bindep : Look for bindep.txt] 2025-12-03 11:17:12.654714 | controller | ok 2025-12-03 11:17:12.664116 | 2025-12-03 11:17:12.664216 | TASK [bindep : Define bindep_file fact] 2025-12-03 11:17:12.696855 | controller | ok 2025-12-03 11:17:12.704475 | 2025-12-03 11:17:12.704563 | TASK [bindep : Look for other-requirements.txt] 2025-12-03 11:17:12.729694 | controller | skipping: Conditional result was False 2025-12-03 11:17:12.738070 | 2025-12-03 11:17:12.738206 | TASK [bindep : Define bindep_file fact] 2025-12-03 11:17:12.763191 | controller | skipping: Conditional result was False 2025-12-03 11:17:12.773284 | 2025-12-03 11:17:12.773403 | TASK [bindep : Look for bindep fallback file] 2025-12-03 11:17:12.821667 | controller | skipping: Conditional result was False 2025-12-03 11:17:12.828064 | 2025-12-03 11:17:12.828156 | TASK [bindep : Define bindep_file fact] 2025-12-03 11:17:12.852757 | controller | skipping: Conditional result was False 2025-12-03 11:17:12.860047 | 2025-12-03 11:17:12.860139 | TASK [bindep : Include bindep tasks] 2025-12-03 11:17:12.889109 | controller | ok 2025-12-03 11:17:12.896383 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-03 11:17:12.909751 | 2025-12-03 11:17:12.909916 | TASK [bindep : Look for bindep command] 2025-12-03 11:17:12.934658 | controller | skipping: Conditional result was False 2025-12-03 11:17:12.941421 | 2025-12-03 11:17:12.941490 | TASK [bindep : Check for system bindep] 2025-12-03 11:17:13.483930 | controller | ok: Runtime: 0:00:00.008924 2025-12-03 11:17:13.501178 | 2025-12-03 11:17:13.501309 | TASK [bindep : Define bindep_command fact] 2025-12-03 11:17:13.526003 | controller | skipping: Conditional result was False 2025-12-03 11:17:13.537818 | 2025-12-03 11:17:13.537983 | TASK [bindep : Include install tasks] 2025-12-03 11:17:13.571787 | controller | ok 2025-12-03 11:17:13.584086 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-03 11:17:13.597939 | 2025-12-03 11:17:13.598045 | TASK [bindep : Create temp dir for bindep] 2025-12-03 11:17:14.025076 | controller | changed 2025-12-03 11:17:14.031114 | 2025-12-03 11:17:14.031228 | TASK [Ensure we have pip dependencies] 2025-12-03 11:17:14.051818 | controller | ok 2025-12-03 11:17:14.088320 | 2025-12-03 11:17:14.088438 | TASK [ensure-pip : Check if pip is installed] 2025-12-03 06:17:14.364766 | controller | /usr/bin/pip3 2025-12-03 06:17:14.396158 | controller | /usr/bin/python3: No module named wheel 2025-12-03 11:17:14.623153 | controller | ok: Runtime: 0:00:00.042423 2025-12-03 11:17:14.632407 | 2025-12-03 11:17:14.632527 | LOOP [ensure-pip : Install pip from packages] 2025-12-03 11:17:14.695170 | controller | ok: "/var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-03 11:17:14.709134 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-03 11:17:14.720370 | 2025-12-03 11:17:14.720464 | TASK [ensure-pip : Install Python 3 pip] 2025-12-03 11:17:17.198968 | controller | changed 2025-12-03 11:17:17.207303 | 2025-12-03 11:17:17.207395 | TASK [ensure-pip : Check for EPEL repository] 2025-12-03 11:17:17.244488 | controller | skipping: Conditional result was False 2025-12-03 11:17:17.252204 | 2025-12-03 11:17:17.252291 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-03 11:17:17.296831 | controller | skipping: Conditional result was False 2025-12-03 11:17:17.303873 | 2025-12-03 11:17:17.303942 | TASK [ensure-pip : Install Python 2 pip] 2025-12-03 11:17:17.347877 | controller | skipping: Conditional result was False 2025-12-03 11:17:17.355117 | 2025-12-03 11:17:17.355189 | TASK [ensure-pip : Ensure setuptools] 2025-12-03 11:17:17.369056 | controller | skipping: Conditional result was False 2025-12-03 11:17:17.376545 | 2025-12-03 11:17:17.376635 | TASK [ensure-pip : Check for ensurepip module] 2025-12-03 11:17:17.907178 | controller | skipping: Conditional result was False 2025-12-03 11:17:17.916459 | 2025-12-03 11:17:17.916552 | TASK [ensure-pip : Ensure python3-venv] 2025-12-03 11:17:17.934054 | controller | skipping: Conditional result was False 2025-12-03 11:17:17.940761 | 2025-12-03 11:17:17.940849 | TASK [ensure-pip : Install pip from source] 2025-12-03 11:17:17.965182 | controller | skipping: Conditional result was False 2025-12-03 11:17:17.971995 | 2025-12-03 11:17:17.972101 | TASK [ensure-pip : Probe for venv python full path] 2025-12-03 06:17:18.258581 | controller | /usr/bin/python3 2025-12-03 11:17:18.501658 | controller | ok: Runtime: 0:00:00.007268 2025-12-03 11:17:18.507624 | 2025-12-03 11:17:18.507773 | TASK [ensure-pip : Set host default] 2025-12-03 11:17:18.588217 | controller | ok 2025-12-03 11:17:18.593344 | 2025-12-03 11:17:18.593427 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-03 11:17:18.651396 | controller | ok 2025-12-03 11:17:18.669231 | 2025-12-03 11:17:18.669352 | TASK [bindep : Install bindep into temporary venv] 2025-12-03 11:17:24.637022 | controller | changed 2025-12-03 11:17:24.642807 | 2025-12-03 11:17:24.642867 | TASK [bindep : Define bindep_command] 2025-12-03 11:17:24.672854 | controller | ok 2025-12-03 11:17:24.688694 | 2025-12-03 11:17:24.688826 | LOOP [bindep : Include package tasks] 2025-12-03 11:17:24.732637 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-03 11:17:24.732840 | controller | ok: All items complete 2025-12-03 11:17:24.732867 | 2025-12-03 11:17:24.741964 | controller | included: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-03 11:17:24.752521 | 2025-12-03 11:17:24.752579 | TASK [bindep : Define bindep_run fact] 2025-12-03 11:17:24.782679 | controller | ok 2025-12-03 11:17:24.789050 | 2025-12-03 11:17:24.789111 | TASK [bindep : Get list of packages to install from bindep] 2025-12-03 06:17:26.436329 | controller | podman 2025-12-03 06:17:26.480819 | controller | python3-jmespath 2025-12-03 06:17:26.481028 | controller | python3-libvirt 2025-12-03 06:17:26.481038 | controller | python3-lxml 2025-12-03 06:17:26.481049 | controller | python3-netaddr 2025-12-03 11:17:26.827258 | controller | ok: Runtime: 0:00:01.399866 2025-12-03 11:17:26.833463 | 2025-12-03 11:17:26.833550 | TASK [bindep : Install distro packages from bindep] 2025-12-03 11:18:58.252432 | controller | changed 2025-12-03 11:18:58.260957 | 2025-12-03 11:18:58.261059 | TASK [bindep : Check that packages are installed] 2025-12-03 11:19:00.310619 | controller | ok: Runtime: 0:00:01.271812 2025-12-03 11:19:00.316906 | 2025-12-03 11:19:00.317056 | TASK [bindep : Fail if we cannot install all packages] 2025-12-03 11:19:00.342698 | controller | skipping: Conditional result was False 2025-12-03 11:19:00.354949 | 2025-12-03 11:19:00.355072 | TASK [Run test-setup role] 2025-12-03 11:19:00.375595 | controller | ok 2025-12-03 11:19:00.395923 | 2025-12-03 11:19:00.396042 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-03 11:19:00.854301 | controller | ok 2025-12-03 11:19:00.859861 | 2025-12-03 11:19:00.859933 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-03 11:19:01.389886 | controller | skipping: Conditional result was False 2025-12-03 11:19:01.430551 | 2025-12-03 11:19:01.430755 | TASK [bindep : Remove bindep temp dir] 2025-12-03 11:19:01.925373 | controller | ok 2025-12-03 11:19:01.936415 | 2025-12-03 11:19:01.936494 | PLAY RECAP 2025-12-03 11:19:01.936539 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-03 11:19:01.936565 | 2025-12-03 11:19:02.062972 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-03 11:19:02.064770 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-03 11:19:02.723797 | 2025-12-03 11:19:02.723948 | PLAY [all] 2025-12-03 11:19:02.743985 | 2025-12-03 11:19:02.744095 | TASK [Abort when test_command variable is undefined] 2025-12-03 11:19:02.789713 | controller | skipping: Conditional result was False 2025-12-03 11:19:02.796661 | 2025-12-03 11:19:02.796834 | TASK [Convert test_command to list] 2025-12-03 11:19:02.852573 | controller | skipping: Conditional result was False 2025-12-03 11:19:02.858100 | 2025-12-03 11:19:02.858169 | TASK [Use test_command list] 2025-12-03 11:19:02.917759 | controller | ok 2025-12-03 11:19:02.923293 | 2025-12-03 11:19:02.923352 | LOOP [Run test_command] 2025-12-03 11:19:03.359987 | controller | no check to run 2025-12-03 11:19:03.360260 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004598 2025-12-03 11:19:03.411829 | 2025-12-03 11:19:03.411993 | PLAY RECAP 2025-12-03 11:19:03.412077 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-03 11:19:03.412120 | 2025-12-03 11:19:03.541318 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-03 11:19:03.542251 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-03 11:19:04.159044 | 2025-12-03 11:19:04.159153 | PLAY [all] 2025-12-03 11:19:04.179438 | 2025-12-03 11:19:04.179517 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-03 11:19:04.534479 | controller | changed: non-zero return code 2025-12-03 11:19:04.540227 | 2025-12-03 11:19:04.540301 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-03 11:19:04.564876 | controller | skipping: Conditional result was False 2025-12-03 11:19:04.570832 | 2025-12-03 11:19:04.570900 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-03 11:19:04.601318 | 2025-12-03 11:19:04.601439 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-03 11:19:04.631738 | 2025-12-03 11:19:04.631877 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-03 11:19:04.656374 | controller | skipping: Conditional result was False 2025-12-03 11:19:04.662208 | 2025-12-03 11:19:04.662275 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-03 11:19:04.693470 | 2025-12-03 11:19:04.693619 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-03 11:19:04.717533 | controller | skipping: Conditional result was False 2025-12-03 11:19:04.723530 | 2025-12-03 11:19:04.723597 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-03 11:19:04.747998 | controller | skipping: Conditional result was False 2025-12-03 11:19:04.756471 | 2025-12-03 11:19:04.756563 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-03 11:19:04.781448 | controller | skipping: Conditional result was False 2025-12-03 11:19:04.817569 | 2025-12-03 11:19:04.817672 | PLAY RECAP 2025-12-03 11:19:04.817745 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-03 11:19:04.817779 | 2025-12-03 11:19:04.918960 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-03 11:19:04.920133 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-03 11:19:05.504301 | 2025-12-03 11:19:05.504406 | PLAY [all] 2025-12-03 11:19:05.522892 | 2025-12-03 11:19:05.522968 | TASK [include_role : fetch-output] 2025-12-03 11:19:05.572166 | controller | ok 2025-12-03 11:19:05.591006 | 2025-12-03 11:19:05.591086 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-03 11:19:05.645889 | controller | skipping: Conditional result was False 2025-12-03 11:19:05.651544 | 2025-12-03 11:19:05.651610 | TASK [fetch-output : Set log path for single node] 2025-12-03 11:19:05.697871 | controller | ok 2025-12-03 11:19:05.710097 | 2025-12-03 11:19:05.710254 | LOOP [fetch-output : Ensure local output dirs] 2025-12-03 11:19:06.216227 | controller -> localhost | ok: "/var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/logs" 2025-12-03 11:19:06.448809 | controller -> localhost | changed: "/var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/artifacts" 2025-12-03 11:19:06.760454 | controller -> localhost | changed: "/var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/docs" 2025-12-03 11:19:06.775836 | 2025-12-03 11:19:06.776020 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-03 11:19:07.533455 | controller | changed: .d..t...... ./ 2025-12-03 11:19:07.533655 | controller | changed: All items complete 2025-12-03 11:19:07.533682 | 2025-12-03 11:19:08.025776 | controller | changed: .d..t...... ./ 2025-12-03 11:19:08.564281 | controller | changed: .d..t...... ./ 2025-12-03 11:19:08.586008 | 2025-12-03 11:19:08.586146 | TASK [include_role : fetch-output-openshift] 2025-12-03 11:19:08.611156 | controller | skipping: Conditional result was False 2025-12-03 11:19:08.623351 | 2025-12-03 11:19:08.623480 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-03 11:19:09.060703 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014480 2025-12-03 11:19:09.334930 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009367 2025-12-03 11:19:09.388564 | 2025-12-03 11:19:09.388666 | PLAY [all] 2025-12-03 11:19:09.409288 | 2025-12-03 11:19:09.409408 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-03 11:19:09.975182 | controller | changed 2025-12-03 11:19:10.017569 | 2025-12-03 11:19:10.017680 | PLAY RECAP 2025-12-03 11:19:10.017801 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-03 11:19:10.017844 | 2025-12-03 11:19:10.129682 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-03 11:19:10.130596 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-03 11:19:10.769266 | 2025-12-03 11:19:10.769380 | PLAY [localhost] 2025-12-03 11:19:10.790847 | 2025-12-03 11:19:10.790961 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-03 11:19:11.176385 | localhost | changed 2025-12-03 11:19:11.181494 | 2025-12-03 11:19:11.181566 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-03 11:19:11.211370 | localhost | ok 2025-12-03 11:19:11.222461 | 2025-12-03 11:19:11.222552 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-03 11:19:11.604846 | localhost | changed 2025-12-03 11:19:11.633968 | 2025-12-03 11:19:11.634129 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-03 11:19:12.391040 | localhost | changed 2025-12-03 11:19:12.396395 | 2025-12-03 11:19:12.396456 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-03 11:19:12.871374 | localhost | Identity added: /var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/tmp/ansible.3vgvtcbw (/var/lib/zuul/builds/91b96751da524c69a5579d6d010b4670/work/tmp/ansible.3vgvtcbw) 2025-12-03 11:19:12.871576 | localhost | ok: Runtime: 0:00:00.013916 2025-12-03 11:19:12.876342 | 2025-12-03 11:19:12.876408 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-03 11:19:13.181360 | localhost | ok: Runtime: 0:00:00.008730 2025-12-03 11:19:13.186830 | 2025-12-03 11:19:13.186891 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-03 11:19:13.270607 | localhost | changed 2025-12-03 11:19:13.279967 | 2025-12-03 11:19:13.280096 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-03 11:19:13.764025 | localhost | changed 2025-12-03 11:19:13.803959 | 2025-12-03 11:19:13.804042 | PLAY [localhost] 2025-12-03 11:19:13.821267 | 2025-12-03 11:19:13.821354 | TASK [Generate bulk log download script] 2025-12-03 11:19:13.851087 | localhost | ok 2025-12-03 11:19:13.866787 | 2025-12-03 11:19:13.866853 | TASK [local-log-download : Check API endpoint is defined] 2025-12-03 11:19:13.914637 | localhost | ok: All assertions passed 2025-12-03 11:19:13.919298 | 2025-12-03 11:19:13.919360 | TASK [local-log-download : Create download script] 2025-12-03 11:19:14.412159 | localhost -> localhost | changed 2025-12-03 11:19:14.433011 | 2025-12-03 11:19:14.433233 | TASK [Register quick-download link] 2025-12-03 11:19:14.460782 | localhost | ok 2025-12-03 11:19:14.519948 | 2025-12-03 11:19:14.520066 | PLAY [logserver.rdoproject.org] 2025-12-03 11:19:14.534313 | 2025-12-03 11:19:14.534450 | TASK [Set zuul-log-path fact] 2025-12-03 11:19:14.552619 | logserver.rdoproject.org | ok 2025-12-03 11:19:14.566249 | 2025-12-03 11:19:14.566390 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-03 11:19:14.595601 | logserver.rdoproject.org | ok 2025-12-03 11:19:14.603568 | 2025-12-03 11:19:14.603677 | TASK [upload-logs : Create log directories] 2025-12-03 11:19:15.443214 | logserver.rdoproject.org | changed 2025-12-03 11:19:15.451094 | 2025-12-03 11:19:15.451259 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-03 11:19:15.763108 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007905 2025-12-03 11:19:15.767745 | 2025-12-03 11:19:15.767808 | TASK [upload-logs : Upload logs to log server] 2025-12-03 11:19:16.483466 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-03 11:19:16.486796 | 2025-12-03 11:19:16.486869 | LOOP [upload-logs : Compress console log and json output] 2025-12-03 11:19:16.549802 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-03 11:19:16.561144 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-03 11:19:16.566942 | 2025-12-03 11:19:16.567009 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-03 11:19:16.610404 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-03 11:19:16.610862 | 2025-12-03 11:19:16.613471 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-03 11:19:16.630130 | 2025-12-03 11:19:16.630283 | LOOP [upload-logs : Upload console log and json output]