2025-10-08 08:33:39.632722 | Job console starting... 2025-10-08 08:33:39.657226 | Updating repositories 2025-10-08 08:33:39.696563 | Preparing job workspace 2025-10-08 08:33:43.140055 | Running Ansible setup... 2025-10-08 08:33:46.893115 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 08:33:47.548094 | 2025-10-08 08:33:47.548223 | PLAY [localhost] 2025-10-08 08:33:47.567287 | 2025-10-08 08:33:47.567388 | TASK [Gathering Facts] 2025-10-08 08:33:48.788436 | localhost | ok 2025-10-08 08:33:48.806962 | 2025-10-08 08:33:48.807202 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 08:33:49.201341 | localhost -> localhost | changed 2025-10-08 08:33:49.207012 | 2025-10-08 08:33:49.207120 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 08:33:50.045330 | localhost -> localhost | changed 2025-10-08 08:33:50.055407 | 2025-10-08 08:33:50.055480 | TASK [Setup log path fact] 2025-10-08 08:33:50.072853 | localhost | ok 2025-10-08 08:33:50.083991 | 2025-10-08 08:33:50.084059 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 08:33:50.111540 | localhost | ok 2025-10-08 08:33:50.120907 | 2025-10-08 08:33:50.121036 | TASK [emit-job-header : Print job information] 2025-10-08 08:33:50.184302 | # Job Information 2025-10-08 08:33:50.184509 | Ansible Version: 2.15.12 2025-10-08 08:33:50.184547 | Job: cifmw-molecule-cifmw_setup 2025-10-08 08:33:50.184576 | Pipeline: github-check 2025-10-08 08:33:50.184602 | Executor: ze02.softwarefactory-project.io 2025-10-08 08:33:50.184627 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3373 2025-10-08 08:33:50.184653 | Log URL (when completed): https://logserver.rdoproject.org/e74/rdoproject.org/e74369de09594306aa692513e1807a7f/ 2025-10-08 08:33:50.184737 | Event ID: 3a070520-a421-11f0-9b5a-2d6f635919d0 2025-10-08 08:33:50.190187 | 2025-10-08 08:33:50.190254 | LOOP [emit-job-header : Print node information] 2025-10-08 08:33:50.287381 | localhost | ok: 2025-10-08 08:33:50.287583 | localhost | # Node Information 2025-10-08 08:33:50.287612 | localhost | Inventory Hostname: controller 2025-10-08 08:33:50.287639 | localhost | Hostname: np0005475443 2025-10-08 08:33:50.287695 | localhost | Username: zuul 2025-10-08 08:33:50.287728 | localhost | Distro: CentOS 9 2025-10-08 08:33:50.287748 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 08:33:50.287768 | localhost | Region: RegionOne 2025-10-08 08:33:50.287785 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 08:33:50.287802 | localhost | Product Name: OpenStack Nova 2025-10-08 08:33:50.287819 | localhost | Interface IP: 38.129.56.100 2025-10-08 08:33:50.318531 | 2025-10-08 08:33:50.318687 | PLAY [all] 2025-10-08 08:33:50.325176 | 2025-10-08 08:33:50.325237 | TASK [Gather network facts] 2025-10-08 08:33:50.819262 | controller | ok 2025-10-08 08:33:50.851106 | 2025-10-08 08:33:50.851191 | TASK [include_role : start-zuul-console] 2025-10-08 08:33:50.873227 | controller | ok 2025-10-08 08:33:50.888900 | 2025-10-08 08:33:50.888988 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 08:33:51.336415 | controller | ok 2025-10-08 08:33:51.345424 | 2025-10-08 08:33:51.345484 | TASK [include_role : add-build-sshkey] 2025-10-08 08:33:51.374100 | controller | ok 2025-10-08 08:33:51.388135 | 2025-10-08 08:33:51.388215 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 08:33:51.644996 | controller -> localhost | ok 2025-10-08 08:33:51.658309 | 2025-10-08 08:33:51.658482 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 08:33:51.689160 | controller | ok 2025-10-08 08:33:51.713296 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 08:33:51.737625 | 2025-10-08 08:33:51.737937 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 08:33:52.232615 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 08:33:52.232843 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/e74369de09594306aa692513e1807a7f_id_rsa. 2025-10-08 08:33:52.232874 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/e74369de09594306aa692513e1807a7f_id_rsa.pub. 2025-10-08 08:33:52.232896 | controller -> localhost | The key fingerprint is: 2025-10-08 08:33:52.232916 | controller -> localhost | SHA256:d3I3Zu6JXYCy+sxEk3m2IZZYNZEBwYQqLxyzWGOb/jI zuul-build-sshkey 2025-10-08 08:33:52.232936 | controller -> localhost | The key's randomart image is: 2025-10-08 08:33:52.232954 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 08:33:52.232972 | controller -> localhost | | ++o=+ | 2025-10-08 08:33:52.232991 | controller -> localhost | | . .... | 2025-10-08 08:33:52.233009 | controller -> localhost | | . . | 2025-10-08 08:33:52.233027 | controller -> localhost | | B . o + . | 2025-10-08 08:33:52.233045 | controller -> localhost | | = X S % B * | 2025-10-08 08:33:52.233063 | controller -> localhost | | . * . + @ B o | 2025-10-08 08:33:52.233080 | controller -> localhost | | . . o . . .| 2025-10-08 08:33:52.233099 | controller -> localhost | | E = + o | 2025-10-08 08:33:52.233116 | controller -> localhost | | +. ..+ . + | 2025-10-08 08:33:52.233133 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 08:33:52.233179 | controller -> localhost | ok: Runtime: 0:00:00.048324 2025-10-08 08:33:52.239019 | 2025-10-08 08:33:52.239081 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 08:33:52.257659 | controller | ok 2025-10-08 08:33:52.267083 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 08:33:52.274898 | 2025-10-08 08:33:52.274958 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 08:33:52.298696 | controller | skipping: Conditional result was False 2025-10-08 08:33:52.303929 | 2025-10-08 08:33:52.303992 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 08:33:52.805537 | controller | changed 2025-10-08 08:33:52.810794 | 2025-10-08 08:33:52.810862 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 08:33:53.113215 | controller | ok 2025-10-08 08:33:53.118732 | 2025-10-08 08:33:53.118799 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 08:33:54.010012 | controller | changed 2025-10-08 08:33:54.015228 | 2025-10-08 08:33:54.015297 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 08:33:54.900313 | controller | changed 2025-10-08 08:33:54.921259 | 2025-10-08 08:33:54.921441 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 08:33:54.950212 | controller | skipping: Conditional result was False 2025-10-08 08:33:54.966564 | 2025-10-08 08:33:54.966772 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 08:33:55.352804 | controller -> localhost | changed 2025-10-08 08:33:55.364140 | 2025-10-08 08:33:55.364253 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 08:33:55.621156 | controller -> localhost | Identity added: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/e74369de09594306aa692513e1807a7f_id_rsa (zuul-build-sshkey) 2025-10-08 08:33:55.621343 | controller -> localhost | ok: Runtime: 0:00:00.008253 2025-10-08 08:33:55.627385 | 2025-10-08 08:33:55.627452 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 08:33:55.999098 | controller | ok 2025-10-08 08:33:56.011757 | 2025-10-08 08:33:56.011896 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 08:33:56.039803 | controller | skipping: Conditional result was False 2025-10-08 08:33:56.063170 | 2025-10-08 08:33:56.063401 | TASK [include_role : validate-host] 2025-10-08 08:33:56.109052 | controller | ok 2025-10-08 08:33:56.135257 | 2025-10-08 08:33:56.135446 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 08:33:56.209386 | controller | ok 2025-10-08 08:33:56.214978 | 2025-10-08 08:33:56.215043 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 08:33:56.473637 | controller -> localhost | ok 2025-10-08 08:33:56.479532 | 2025-10-08 08:33:56.479596 | TASK [validate-host : Collect information about the host] 2025-10-08 08:33:57.313049 | controller | ok 2025-10-08 08:33:57.321889 | 2025-10-08 08:33:57.321970 | TASK [validate-host : Sanitize hostname] 2025-10-08 08:33:57.384591 | controller | ok 2025-10-08 08:33:57.391912 | 2025-10-08 08:33:57.392008 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 08:33:57.868559 | controller -> localhost | changed 2025-10-08 08:33:57.874895 | 2025-10-08 08:33:57.874995 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 08:33:58.308281 | controller | ok 2025-10-08 08:33:58.313243 | 2025-10-08 08:33:58.313309 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 08:33:58.916808 | controller -> localhost | changed 2025-10-08 08:33:58.927431 | 2025-10-08 08:33:58.927519 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 08:33:58.941480 | controller | skipping: Conditional result was False 2025-10-08 08:33:58.947329 | 2025-10-08 08:33:58.947403 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 08:33:58.974564 | controller | skipping: Conditional result was False 2025-10-08 08:33:58.979987 | 2025-10-08 08:33:58.980053 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 08:33:59.226437 | controller | ok: "logs" 2025-10-08 08:33:59.226704 | controller | ok: All items complete 2025-10-08 08:33:59.226738 | 2025-10-08 08:33:59.464429 | controller | ok: "artifacts" 2025-10-08 08:33:59.688255 | controller | ok: "docs" 2025-10-08 08:33:59.708888 | 2025-10-08 08:33:59.709091 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 08:34:00.008714 | controller | changed: "logs" 2025-10-08 08:34:00.244973 | controller | changed: "artifacts" 2025-10-08 08:34:00.475100 | controller | changed: "docs" 2025-10-08 08:34:00.509823 | 2025-10-08 08:34:00.509964 | PLAY RECAP 2025-10-08 08:34:00.510024 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 08:34:00.510060 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 08:34:00.510085 | 2025-10-08 08:34:00.618408 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 08:34:00.619206 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 08:34:01.184853 | 2025-10-08 08:34:01.184969 | PLAY [localhost] 2025-10-08 08:34:01.202456 | 2025-10-08 08:34:01.202564 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 08:34:01.615975 | localhost | ok 2025-10-08 08:34:01.621210 | 2025-10-08 08:34:01.621283 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 08:34:02.360461 | localhost | changed 2025-10-08 08:34:02.380603 | 2025-10-08 08:34:02.380667 | PLAY [all] 2025-10-08 08:34:02.396509 | 2025-10-08 08:34:02.396570 | TASK [include_role : prepare-workspace] 2025-10-08 08:34:02.424952 | controller | ok 2025-10-08 08:34:02.439091 | 2025-10-08 08:34:02.439156 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 08:34:02.832439 | controller | ok 2025-10-08 08:34:02.838327 | 2025-10-08 08:34:02.838387 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 08:34:04.513792 | controller | Output suppressed because no_log was given 2025-10-08 08:34:04.523797 | 2025-10-08 08:34:04.523858 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 08:34:04.833105 | controller | changed: "logs" 2025-10-08 08:34:05.060620 | controller | changed: "artifacts" 2025-10-08 08:34:05.343443 | controller | changed: "docs" 2025-10-08 08:34:05.351876 | 2025-10-08 08:34:05.352001 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 08:34:05.664288 | controller | changed: "logs" 2025-10-08 08:34:05.664558 | controller | changed: All items complete 2025-10-08 08:34:05.664599 | 2025-10-08 08:34:05.929773 | controller | changed: "artifacts" 2025-10-08 08:34:06.165288 | controller | changed: "docs" 2025-10-08 08:34:06.202583 | 2025-10-08 08:34:06.202815 | TASK [Check if worker can sudo] 2025-10-08 08:34:06.751961 | controller | ok: Runtime: 0:00:00.040645 2025-10-08 08:34:06.763930 | 2025-10-08 08:34:06.764061 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 08:34:06.842328 | controller | skipping: Conditional result was False 2025-10-08 08:34:06.855402 | 2025-10-08 08:34:06.855567 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 08:34:06.924935 | controller | ok 2025-10-08 08:34:06.941839 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 08:34:06.953855 | 2025-10-08 08:34:06.953971 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 08:34:07.355018 | controller | ok 2025-10-08 08:34:07.363303 | 2025-10-08 08:34:07.363384 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 08:34:07.475922 | controller | ok: "/var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 08:34:07.490658 | 2025-10-08 08:34:07.490837 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 08:34:08.406019 | controller | changed 2025-10-08 08:34:08.424209 | 2025-10-08 08:34:08.424393 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 08:34:08.510050 | controller | ok: "/var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 08:34:08.510310 | controller | ok: All items complete 2025-10-08 08:34:08.510347 | 2025-10-08 08:34:08.588448 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 08:34:08.596910 | 2025-10-08 08:34:08.597000 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 08:34:09.559787 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 08:34:10.358945 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 08:34:10.370247 | 2025-10-08 08:34:10.370316 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 08:34:10.786629 | controller | changed: section and option added 2025-10-08 08:34:10.806745 | 2025-10-08 08:34:10.806841 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 08:34:11.609850 | controller | 29 files removed 2025-10-08 08:34:11.610123 | controller | ok: Item: dnf clean all Runtime: 0:00:00.505683 2025-10-08 08:34:11.610186 | controller | changed: All items complete 2025-10-08 08:34:11.610223 | 2025-10-08 08:34:22.284332 | 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-08 08:34:22.284480 | controller | DNF version: 4.14.0 2025-10-08 08:34:22.284505 | controller | cachedir: /var/cache/dnf 2025-10-08 08:34:22.284526 | controller | Making cache files for all metadata files. 2025-10-08 08:34:22.284547 | controller | baseos: has expired and will be refreshed. 2025-10-08 08:34:22.284574 | controller | appstream: has expired and will be refreshed. 2025-10-08 08:34:22.284602 | controller | crb: has expired and will be refreshed. 2025-10-08 08:34:22.284641 | controller | extras-common: has expired and will be refreshed. 2025-10-08 08:34:22.284659 | controller | repo: downloading from remote: baseos 2025-10-08 08:34:22.284704 | controller | CentOS Stream 9 - BaseOS 56 MB/s | 8.8 MB 00:00 2025-10-08 08:34:22.284722 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 08:34:22.284738 | controller | repo: downloading from remote: appstream 2025-10-08 08:34:22.284754 | controller | CentOS Stream 9 - AppStream 92 MB/s | 25 MB 00:00 2025-10-08 08:34:22.284769 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 08:34:22.284784 | controller | repo: downloading from remote: crb 2025-10-08 08:34:22.284799 | controller | CentOS Stream 9 - CRB 62 MB/s | 7.1 MB 00:00 2025-10-08 08:34:22.284815 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 08:34:22.284830 | controller | repo: downloading from remote: extras-common 2025-10-08 08:34:22.284846 | controller | CentOS Stream 9 - Extras packages 1.0 MB/s | 20 kB 00:00 2025-10-08 08:34:22.284861 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 08:34:22.284877 | controller | Last metadata expiration check: 0:00:01 ago on Wed 08 Oct 2025 04:34:20 AM EDT. 2025-10-08 08:34:22.284893 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 08:34:22.284908 | controller | Completion plugin: Generating completion cache... 2025-10-08 08:34:22.284924 | controller | Metadata cache created. 2025-10-08 08:34:22.284950 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.419526 2025-10-08 08:34:22.317831 | 2025-10-08 08:34:22.318013 | PLAY RECAP 2025-10-08 08:34:22.318105 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 08:34:22.318160 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 08:34:22.318198 | 2025-10-08 08:34:22.441393 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 08:34:22.442601 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 08:34:23.003870 | 2025-10-08 08:34:23.003985 | PLAY [all] 2025-10-08 08:34:23.024473 | 2025-10-08 08:34:23.024557 | TASK [Install binary dependencies] 2025-10-08 08:34:23.093684 | controller | ok 2025-10-08 08:34:23.112757 | 2025-10-08 08:34:23.112841 | TASK [bindep : Include find tasks] 2025-10-08 08:34:23.151714 | controller | ok 2025-10-08 08:34:23.159093 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 08:34:23.164748 | 2025-10-08 08:34:23.164810 | TASK [bindep : Look for bindep.txt] 2025-10-08 08:34:23.650308 | controller | ok 2025-10-08 08:34:23.665728 | 2025-10-08 08:34:23.665870 | TASK [bindep : Define bindep_file fact] 2025-10-08 08:34:23.699359 | controller | ok 2025-10-08 08:34:23.706918 | 2025-10-08 08:34:23.707033 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 08:34:23.722766 | controller | skipping: Conditional result was False 2025-10-08 08:34:23.731231 | 2025-10-08 08:34:23.731323 | TASK [bindep : Define bindep_file fact] 2025-10-08 08:34:23.755884 | controller | skipping: Conditional result was False 2025-10-08 08:34:23.763654 | 2025-10-08 08:34:23.763769 | TASK [bindep : Look for bindep fallback file] 2025-10-08 08:34:23.798631 | controller | skipping: Conditional result was False 2025-10-08 08:34:23.806240 | 2025-10-08 08:34:23.806330 | TASK [bindep : Define bindep_file fact] 2025-10-08 08:34:23.841280 | controller | skipping: Conditional result was False 2025-10-08 08:34:23.849140 | 2025-10-08 08:34:23.849231 | TASK [bindep : Include bindep tasks] 2025-10-08 08:34:23.879688 | controller | ok 2025-10-08 08:34:23.886245 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 08:34:23.893831 | 2025-10-08 08:34:23.893893 | TASK [bindep : Look for bindep command] 2025-10-08 08:34:23.917804 | controller | skipping: Conditional result was False 2025-10-08 08:34:23.928221 | 2025-10-08 08:34:23.928314 | TASK [bindep : Check for system bindep] 2025-10-08 08:34:24.465526 | controller | ok: Runtime: 0:00:00.004340 2025-10-08 08:34:24.471835 | 2025-10-08 08:34:24.471904 | TASK [bindep : Define bindep_command fact] 2025-10-08 08:34:24.497049 | controller | skipping: Conditional result was False 2025-10-08 08:34:24.504774 | 2025-10-08 08:34:24.504843 | TASK [bindep : Include install tasks] 2025-10-08 08:34:24.534605 | controller | ok 2025-10-08 08:34:24.543395 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 08:34:24.552853 | 2025-10-08 08:34:24.552918 | TASK [bindep : Create temp dir for bindep] 2025-10-08 08:34:24.911956 | controller | changed 2025-10-08 08:34:24.917407 | 2025-10-08 08:34:24.917472 | TASK [Ensure we have pip dependencies] 2025-10-08 08:34:24.936636 | controller | ok 2025-10-08 08:34:24.962376 | 2025-10-08 08:34:24.962508 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 04:34:25.261129 | controller | /usr/bin/pip3 2025-10-08 04:34:25.307120 | controller | /usr/bin/python3: No module named wheel 2025-10-08 08:34:25.494967 | controller | ok: Runtime: 0:00:00.059690 2025-10-08 08:34:25.515743 | 2025-10-08 08:34:25.515981 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 08:34:25.565868 | controller | ok: "/var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 08:34:25.583872 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 08:34:25.595992 | 2025-10-08 08:34:25.596188 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 08:34:27.886926 | controller | changed 2025-10-08 08:34:27.894251 | 2025-10-08 08:34:27.894335 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 08:34:27.960424 | controller | skipping: Conditional result was False 2025-10-08 08:34:27.969572 | 2025-10-08 08:34:27.969694 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 08:34:28.015570 | controller | skipping: Conditional result was False 2025-10-08 08:34:28.021934 | 2025-10-08 08:34:28.021998 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 08:34:28.065969 | controller | skipping: Conditional result was False 2025-10-08 08:34:28.084048 | 2025-10-08 08:34:28.084248 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 08:34:28.112045 | controller | skipping: Conditional result was False 2025-10-08 08:34:28.122259 | 2025-10-08 08:34:28.122374 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 08:34:28.673169 | controller | skipping: Conditional result was False 2025-10-08 08:34:28.686468 | 2025-10-08 08:34:28.686623 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 08:34:28.716529 | controller | skipping: Conditional result was False 2025-10-08 08:34:28.725386 | 2025-10-08 08:34:28.725537 | TASK [ensure-pip : Install pip from source] 2025-10-08 08:34:28.750649 | controller | skipping: Conditional result was False 2025-10-08 08:34:28.758769 | 2025-10-08 08:34:28.758856 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 04:34:29.062590 | controller | /usr/bin/python3 2025-10-08 08:34:29.301476 | controller | ok: Runtime: 0:00:00.005523 2025-10-08 08:34:29.309773 | 2025-10-08 08:34:29.309861 | TASK [ensure-pip : Set host default] 2025-10-08 08:34:29.389125 | controller | ok 2025-10-08 08:34:29.401032 | 2025-10-08 08:34:29.401171 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 08:34:29.458667 | controller | ok 2025-10-08 08:34:29.473815 | 2025-10-08 08:34:29.473906 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 08:34:33.535805 | controller | changed 2025-10-08 08:34:33.542899 | 2025-10-08 08:34:33.542963 | TASK [bindep : Define bindep_command] 2025-10-08 08:34:33.582546 | controller | ok 2025-10-08 08:34:33.587953 | 2025-10-08 08:34:33.588021 | LOOP [bindep : Include package tasks] 2025-10-08 08:34:33.641053 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 08:34:33.641195 | controller | ok: All items complete 2025-10-08 08:34:33.641219 | 2025-10-08 08:34:33.649645 | controller | included: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 08:34:33.661298 | 2025-10-08 08:34:33.661395 | TASK [bindep : Define bindep_run fact] 2025-10-08 08:34:33.690888 | controller | ok 2025-10-08 08:34:33.696445 | 2025-10-08 08:34:33.696543 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 04:34:35.040860 | controller | podman 2025-10-08 04:34:35.067953 | controller | python3-jmespath 2025-10-08 04:34:35.068020 | controller | python3-libvirt 2025-10-08 04:34:35.068028 | controller | python3-lxml 2025-10-08 04:34:35.068035 | controller | python3-netaddr 2025-10-08 08:34:35.239857 | controller | ok: Runtime: 0:00:01.108380 2025-10-08 08:34:35.248552 | 2025-10-08 08:34:35.248676 | TASK [bindep : Install distro packages from bindep] 2025-10-08 08:35:36.818484 | controller | changed 2025-10-08 08:35:36.830874 | 2025-10-08 08:35:36.831039 | TASK [bindep : Check that packages are installed] 2025-10-08 08:35:38.395416 | controller | ok: Runtime: 0:00:01.195408 2025-10-08 08:35:38.410105 | 2025-10-08 08:35:38.410262 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 08:35:38.451313 | controller | skipping: Conditional result was False 2025-10-08 08:35:38.463340 | 2025-10-08 08:35:38.463409 | TASK [Run test-setup role] 2025-10-08 08:35:38.485154 | controller | ok 2025-10-08 08:35:38.507776 | 2025-10-08 08:35:38.507941 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 08:35:38.772115 | controller | ok 2025-10-08 08:35:38.778157 | 2025-10-08 08:35:38.778239 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 08:35:39.308552 | controller | skipping: Conditional result was False 2025-10-08 08:35:39.360760 | 2025-10-08 08:35:39.360904 | TASK [bindep : Remove bindep temp dir] 2025-10-08 08:35:39.731175 | controller | ok 2025-10-08 08:35:39.741751 | 2025-10-08 08:35:39.741819 | PLAY RECAP 2025-10-08 08:35:39.741862 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 08:35:39.741890 | 2025-10-08 08:35:39.863205 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 08:35:39.864292 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 08:35:40.413173 | 2025-10-08 08:35:40.413264 | PLAY [all] 2025-10-08 08:35:40.434796 | 2025-10-08 08:35:40.434915 | TASK [Abort when test_command variable is undefined] 2025-10-08 08:35:40.470441 | controller | skipping: Conditional result was False 2025-10-08 08:35:40.476062 | 2025-10-08 08:35:40.476136 | TASK [Convert test_command to list] 2025-10-08 08:35:40.520239 | controller | skipping: Conditional result was False 2025-10-08 08:35:40.527733 | 2025-10-08 08:35:40.527819 | TASK [Use test_command list] 2025-10-08 08:35:40.581917 | controller | ok 2025-10-08 08:35:40.587265 | 2025-10-08 08:35:40.587326 | LOOP [Run test_command] 2025-10-08 08:35:40.972445 | controller | no check to run 2025-10-08 08:35:40.972740 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004557 2025-10-08 08:35:41.023992 | 2025-10-08 08:35:41.024115 | PLAY RECAP 2025-10-08 08:35:41.024170 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 08:35:41.024211 | 2025-10-08 08:35:41.126430 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 08:35:41.128636 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 08:35:41.745120 | 2025-10-08 08:35:41.745251 | PLAY [all] 2025-10-08 08:35:41.766983 | 2025-10-08 08:35:41.767119 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 08:35:42.109510 | controller | changed: non-zero return code 2025-10-08 08:35:42.117061 | 2025-10-08 08:35:42.117163 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 08:35:42.142288 | controller | skipping: Conditional result was False 2025-10-08 08:35:42.151277 | 2025-10-08 08:35:42.151381 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 08:35:42.186306 | 2025-10-08 08:35:42.186506 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 08:35:42.220351 | 2025-10-08 08:35:42.220552 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 08:35:42.237225 | controller | skipping: Conditional result was False 2025-10-08 08:35:42.248305 | 2025-10-08 08:35:42.248505 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 08:35:42.287689 | 2025-10-08 08:35:42.287970 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 08:35:42.305358 | controller | skipping: Conditional result was False 2025-10-08 08:35:42.321224 | 2025-10-08 08:35:42.321423 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 08:35:42.352174 | controller | skipping: Conditional result was False 2025-10-08 08:35:42.358245 | 2025-10-08 08:35:42.358387 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 08:35:42.383471 | controller | skipping: Conditional result was False 2025-10-08 08:35:42.407863 | 2025-10-08 08:35:42.407990 | PLAY RECAP 2025-10-08 08:35:42.408035 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 08:35:42.408057 | 2025-10-08 08:35:42.499210 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 08:35:42.500124 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 08:35:43.071727 | 2025-10-08 08:35:43.071841 | PLAY [all] 2025-10-08 08:35:43.091102 | 2025-10-08 08:35:43.091193 | TASK [include_role : fetch-output] 2025-10-08 08:35:43.130339 | controller | ok 2025-10-08 08:35:43.147574 | 2025-10-08 08:35:43.147695 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 08:35:43.212533 | controller | skipping: Conditional result was False 2025-10-08 08:35:43.218604 | 2025-10-08 08:35:43.218683 | TASK [fetch-output : Set log path for single node] 2025-10-08 08:35:43.257736 | controller | ok 2025-10-08 08:35:43.262784 | 2025-10-08 08:35:43.262847 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 08:35:43.741003 | controller -> localhost | ok: "/var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/logs" 2025-10-08 08:35:44.008701 | controller -> localhost | changed: "/var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/artifacts" 2025-10-08 08:35:44.272345 | controller -> localhost | changed: "/var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/docs" 2025-10-08 08:35:44.286699 | 2025-10-08 08:35:44.286820 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 08:35:45.032772 | controller | changed: .d..t...... ./ 2025-10-08 08:35:45.033172 | controller | changed: All items complete 2025-10-08 08:35:45.033238 | 2025-10-08 08:35:45.560809 | controller | changed: .d..t...... ./ 2025-10-08 08:35:46.050451 | controller | changed: .d..t...... ./ 2025-10-08 08:35:46.067368 | 2025-10-08 08:35:46.067505 | TASK [include_role : fetch-output-openshift] 2025-10-08 08:35:46.093963 | controller | skipping: Conditional result was False 2025-10-08 08:35:46.103244 | 2025-10-08 08:35:46.103341 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 08:35:46.556485 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012499 2025-10-08 08:35:46.828257 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013153 2025-10-08 08:35:46.886510 | 2025-10-08 08:35:46.886637 | PLAY [all] 2025-10-08 08:35:46.907366 | 2025-10-08 08:35:46.907454 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 08:35:47.354966 | controller | changed 2025-10-08 08:35:47.402889 | 2025-10-08 08:35:47.403006 | PLAY RECAP 2025-10-08 08:35:47.403061 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 08:35:47.403088 | 2025-10-08 08:35:47.542508 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 08:35:47.543349 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 08:35:48.199409 | 2025-10-08 08:35:48.199535 | PLAY [localhost] 2025-10-08 08:35:48.218716 | 2025-10-08 08:35:48.218840 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 08:35:48.624643 | localhost | changed 2025-10-08 08:35:48.629399 | 2025-10-08 08:35:48.629508 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 08:35:48.657983 | localhost | ok 2025-10-08 08:35:48.666444 | 2025-10-08 08:35:48.666515 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 08:35:49.000382 | localhost | changed 2025-10-08 08:35:49.005776 | 2025-10-08 08:35:49.005859 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 08:35:49.820013 | localhost | changed 2025-10-08 08:35:49.825413 | 2025-10-08 08:35:49.825505 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 08:35:50.282388 | localhost | Identity added: /var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/tmp/ansible.w08qm5le (/var/lib/zuul/builds/e74369de09594306aa692513e1807a7f/work/tmp/ansible.w08qm5le) 2025-10-08 08:35:50.282570 | localhost | ok: Runtime: 0:00:00.012650 2025-10-08 08:35:50.287187 | 2025-10-08 08:35:50.287262 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 08:35:50.570362 | localhost | ok: Runtime: 0:00:00.007223 2025-10-08 08:35:50.575096 | 2025-10-08 08:35:50.575161 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 08:35:50.624492 | localhost | changed 2025-10-08 08:35:50.628815 | 2025-10-08 08:35:50.628882 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 08:35:50.993867 | localhost | changed 2025-10-08 08:35:51.031959 | 2025-10-08 08:35:51.032065 | PLAY [localhost] 2025-10-08 08:35:51.049601 | 2025-10-08 08:35:51.049714 | TASK [Generate bulk log download script] 2025-10-08 08:35:51.071549 | localhost | ok 2025-10-08 08:35:51.088391 | 2025-10-08 08:35:51.088486 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 08:35:51.139171 | localhost | ok: All assertions passed 2025-10-08 08:35:51.147073 | 2025-10-08 08:35:51.147162 | TASK [local-log-download : Create download script] 2025-10-08 08:35:51.639747 | localhost -> localhost | changed 2025-10-08 08:35:51.648740 | 2025-10-08 08:35:51.648819 | TASK [Register quick-download link] 2025-10-08 08:35:51.677571 | localhost | ok 2025-10-08 08:35:51.721154 | 2025-10-08 08:35:51.721252 | PLAY [logserver.rdoproject.org] 2025-10-08 08:35:51.730659 | 2025-10-08 08:35:51.730754 | TASK [Set zuul-log-path fact] 2025-10-08 08:35:51.747212 | logserver.rdoproject.org | ok 2025-10-08 08:35:51.756005 | 2025-10-08 08:35:51.756076 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 08:35:51.782906 | logserver.rdoproject.org | ok 2025-10-08 08:35:51.788328 | 2025-10-08 08:35:51.788396 | TASK [upload-logs : Create log directories] 2025-10-08 08:35:52.468209 | logserver.rdoproject.org | changed 2025-10-08 08:35:52.472084 | 2025-10-08 08:35:52.472160 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 08:35:52.827753 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009353 2025-10-08 08:35:52.834823 | 2025-10-08 08:35:52.834923 | TASK [upload-logs : Upload logs to log server] 2025-10-08 08:35:53.558976 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 08:35:53.565759 | 2025-10-08 08:35:53.565908 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 08:35:53.641304 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 08:35:53.654133 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 08:35:53.662449 | 2025-10-08 08:35:53.662696 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 08:35:53.732199 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 08:35:53.732466 | 2025-10-08 08:35:53.737360 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 08:35:53.749415 | 2025-10-08 08:35:53.749629 | LOOP [upload-logs : Upload console log and json output]