2025-10-13 14:31:41.888555 | Job console starting... 2025-10-13 14:31:41.902168 | Updating repositories 2025-10-13 14:31:41.929727 | Preparing job workspace 2025-10-13 14:31:47.095484 | Running Ansible setup... 2025-10-13 14:31:51.156259 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:31:52.005621 | 2025-10-13 14:31:52.005762 | PLAY [localhost] 2025-10-13 14:31:52.030060 | 2025-10-13 14:31:52.030218 | TASK [Gathering Facts] 2025-10-13 14:31:53.192800 | localhost | ok 2025-10-13 14:31:53.208638 | 2025-10-13 14:31:53.208851 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 14:31:54.011870 | localhost -> localhost | changed 2025-10-13 14:31:54.017974 | 2025-10-13 14:31:54.018054 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 14:31:55.396272 | localhost -> localhost | changed 2025-10-13 14:31:55.410436 | 2025-10-13 14:31:55.410560 | TASK [Setup log path fact] 2025-10-13 14:31:55.431134 | localhost | ok 2025-10-13 14:31:55.445595 | 2025-10-13 14:31:55.445737 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:31:55.474077 | localhost | ok 2025-10-13 14:31:55.483739 | 2025-10-13 14:31:55.483824 | TASK [emit-job-header : Print job information] 2025-10-13 14:31:55.522950 | # Job Information 2025-10-13 14:31:55.523376 | Ansible Version: 2.15.12 2025-10-13 14:31:55.523411 | Job: cifmw-molecule-ipa 2025-10-13 14:31:55.523432 | Pipeline: github-check 2025-10-13 14:31:55.523992 | Executor: ze02.softwarefactory-project.io 2025-10-13 14:31:55.524035 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402 2025-10-13 14:31:55.524058 | Log URL (when completed): https://logserver.rdoproject.org/044/rdoproject.org/0449eca6fd49495f8873b9b80241a6b6/ 2025-10-13 14:31:55.524077 | Event ID: 1ffd4d00-a841-11f0-85e6-969c5520c1b0 2025-10-13 14:31:55.528627 | 2025-10-13 14:31:55.528728 | LOOP [emit-job-header : Print node information] 2025-10-13 14:31:55.659325 | localhost | ok: 2025-10-13 14:31:55.659501 | localhost | # Node Information 2025-10-13 14:31:55.659528 | localhost | Inventory Hostname: controller 2025-10-13 14:31:55.659551 | localhost | Hostname: np0005485055 2025-10-13 14:31:55.659570 | localhost | Username: zuul 2025-10-13 14:31:55.659590 | localhost | Distro: CentOS 9 2025-10-13 14:31:55.659608 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 14:31:55.659625 | localhost | Region: RegionOne 2025-10-13 14:31:55.659642 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 14:31:55.659659 | localhost | Product Name: OpenStack Nova 2025-10-13 14:31:55.659709 | localhost | Interface IP: 38.129.56.76 2025-10-13 14:31:55.698267 | 2025-10-13 14:31:55.698360 | PLAY [all] 2025-10-13 14:31:55.718652 | 2025-10-13 14:31:55.718797 | TASK [Gather network facts] 2025-10-13 14:31:56.220877 | controller | ok 2025-10-13 14:31:56.244620 | 2025-10-13 14:31:56.244759 | TASK [include_role : start-zuul-console] 2025-10-13 14:31:56.263007 | controller | ok 2025-10-13 14:31:56.275095 | 2025-10-13 14:31:56.275167 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 14:31:56.715628 | controller | ok 2025-10-13 14:31:56.734600 | 2025-10-13 14:31:56.734735 | TASK [include_role : add-build-sshkey] 2025-10-13 14:31:56.766532 | controller | ok 2025-10-13 14:31:56.784183 | 2025-10-13 14:31:56.784277 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 14:31:57.287302 | controller -> localhost | ok 2025-10-13 14:31:57.293448 | 2025-10-13 14:31:57.293518 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 14:31:57.351006 | controller | ok 2025-10-13 14:31:57.375418 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 14:31:57.386080 | 2025-10-13 14:31:57.386160 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 14:31:59.096589 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 14:31:59.096863 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/0449eca6fd49495f8873b9b80241a6b6_id_rsa. 2025-10-13 14:31:59.096897 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/0449eca6fd49495f8873b9b80241a6b6_id_rsa.pub. 2025-10-13 14:31:59.096918 | controller -> localhost | The key fingerprint is: 2025-10-13 14:31:59.096937 | controller -> localhost | SHA256:92pqfykavj5tlWVzZVuVDISULNVbtE8P3hbeZSEgQsE zuul-build-sshkey 2025-10-13 14:31:59.096955 | controller -> localhost | The key's randomart image is: 2025-10-13 14:31:59.096973 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 14:31:59.096991 | controller -> localhost | | o+..++*++o+| 2025-10-13 14:31:59.097010 | controller -> localhost | | E...+ ..+*| 2025-10-13 14:31:59.097027 | controller -> localhost | | . ++B| 2025-10-13 14:31:59.097044 | controller -> localhost | | o=*B| 2025-10-13 14:31:59.097062 | controller -> localhost | | S . +.+*| 2025-10-13 14:31:59.097078 | controller -> localhost | | . .o . | 2025-10-13 14:31:59.097095 | controller -> localhost | | .. ... | 2025-10-13 14:31:59.097114 | controller -> localhost | | .o.=.o | 2025-10-13 14:31:59.097131 | controller -> localhost | | o*Ooo | 2025-10-13 14:31:59.097149 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 14:31:59.097195 | controller -> localhost | ok: Runtime: 0:00:00.831978 2025-10-13 14:31:59.113387 | 2025-10-13 14:31:59.113527 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 14:31:59.164652 | controller | ok 2025-10-13 14:31:59.176778 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 14:31:59.198029 | 2025-10-13 14:31:59.198142 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 14:31:59.281395 | controller | skipping: Conditional result was False 2025-10-13 14:31:59.287002 | 2025-10-13 14:31:59.287074 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 14:31:59.880704 | controller | changed 2025-10-13 14:31:59.889505 | 2025-10-13 14:31:59.889590 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 14:32:00.207524 | controller | ok 2025-10-13 14:32:00.212630 | 2025-10-13 14:32:00.212721 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 14:32:01.137887 | controller | changed 2025-10-13 14:32:01.144532 | 2025-10-13 14:32:01.144612 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 14:32:02.198712 | controller | changed 2025-10-13 14:32:02.297411 | 2025-10-13 14:32:02.297534 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 14:32:02.333093 | controller | skipping: Conditional result was False 2025-10-13 14:32:02.341537 | 2025-10-13 14:32:02.341641 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 14:32:03.110960 | controller -> localhost | changed 2025-10-13 14:32:03.126570 | 2025-10-13 14:32:03.126726 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 14:32:03.671825 | controller -> localhost | Identity added: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/0449eca6fd49495f8873b9b80241a6b6_id_rsa (zuul-build-sshkey) 2025-10-13 14:32:03.672023 | controller -> localhost | ok: Runtime: 0:00:00.022981 2025-10-13 14:32:03.677808 | 2025-10-13 14:32:03.677896 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 14:32:04.171346 | controller | ok 2025-10-13 14:32:04.177692 | 2025-10-13 14:32:04.177765 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 14:32:04.222540 | controller | skipping: Conditional result was False 2025-10-13 14:32:04.297049 | 2025-10-13 14:32:04.297178 | TASK [include_role : validate-host] 2025-10-13 14:32:04.328272 | controller | ok 2025-10-13 14:32:04.358783 | 2025-10-13 14:32:04.358894 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 14:32:04.413360 | controller | ok 2025-10-13 14:32:04.424133 | 2025-10-13 14:32:04.424270 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 14:32:04.777345 | controller -> localhost | ok 2025-10-13 14:32:04.785813 | 2025-10-13 14:32:04.785900 | TASK [validate-host : Collect information about the host] 2025-10-13 14:32:05.696848 | controller | ok 2025-10-13 14:32:05.718025 | 2025-10-13 14:32:05.718104 | TASK [validate-host : Sanitize hostname] 2025-10-13 14:32:05.855071 | controller | ok 2025-10-13 14:32:05.861046 | 2025-10-13 14:32:05.861117 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 14:32:06.721084 | controller -> localhost | changed 2025-10-13 14:32:06.727796 | 2025-10-13 14:32:06.727908 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 14:32:07.258562 | controller | ok 2025-10-13 14:32:07.263491 | 2025-10-13 14:32:07.263555 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 14:32:07.755553 | controller -> localhost | changed 2025-10-13 14:32:07.765550 | 2025-10-13 14:32:07.765614 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 14:32:07.789960 | controller | skipping: Conditional result was False 2025-10-13 14:32:07.795325 | 2025-10-13 14:32:07.795389 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 14:32:07.819251 | controller | skipping: Conditional result was False 2025-10-13 14:32:07.824851 | 2025-10-13 14:32:07.824916 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:32:08.184777 | controller | ok: "logs" 2025-10-13 14:32:08.185206 | controller | ok: All items complete 2025-10-13 14:32:08.185252 | 2025-10-13 14:32:08.410583 | controller | ok: "artifacts" 2025-10-13 14:32:08.668983 | controller | ok: "docs" 2025-10-13 14:32:08.685012 | 2025-10-13 14:32:08.685092 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:32:08.971474 | controller | changed: "logs" 2025-10-13 14:32:09.240358 | controller | changed: "artifacts" 2025-10-13 14:32:09.488620 | controller | changed: "docs" 2025-10-13 14:32:09.527406 | 2025-10-13 14:32:09.527531 | PLAY RECAP 2025-10-13 14:32:09.527574 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 14:32:09.527601 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:32:09.527619 | 2025-10-13 14:32:09.673334 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:32:09.674194 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:32:10.358967 | 2025-10-13 14:32:10.359083 | PLAY [localhost] 2025-10-13 14:32:10.375342 | 2025-10-13 14:32:10.375422 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 14:32:10.957168 | localhost | ok 2025-10-13 14:32:10.963354 | 2025-10-13 14:32:10.963429 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 14:32:11.635183 | localhost | changed 2025-10-13 14:32:11.657045 | 2025-10-13 14:32:11.657107 | PLAY [all] 2025-10-13 14:32:11.676645 | 2025-10-13 14:32:11.676744 | TASK [include_role : prepare-workspace] 2025-10-13 14:32:11.705257 | controller | ok 2025-10-13 14:32:11.719701 | 2025-10-13 14:32:11.719787 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 14:32:12.124184 | controller | ok 2025-10-13 14:32:12.134879 | 2025-10-13 14:32:12.134946 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 14:32:13.940521 | controller | Output suppressed because no_log was given 2025-10-13 14:32:13.950264 | 2025-10-13 14:32:13.950328 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:32:14.256932 | controller | changed: "logs" 2025-10-13 14:32:14.475658 | controller | changed: "artifacts" 2025-10-13 14:32:14.722897 | controller | changed: "docs" 2025-10-13 14:32:14.743019 | 2025-10-13 14:32:14.743227 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:32:15.040256 | controller | changed: "logs" 2025-10-13 14:32:15.040505 | controller | changed: All items complete 2025-10-13 14:32:15.040532 | 2025-10-13 14:32:15.275029 | controller | changed: "artifacts" 2025-10-13 14:32:15.529552 | controller | changed: "docs" 2025-10-13 14:32:15.550604 | 2025-10-13 14:32:15.550754 | TASK [Check if worker can sudo] 2025-10-13 14:32:16.124123 | controller | ok: Runtime: 0:00:00.047940 2025-10-13 14:32:16.129659 | 2025-10-13 14:32:16.129756 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 14:32:16.206152 | controller | skipping: Conditional result was False 2025-10-13 14:32:16.213196 | 2025-10-13 14:32:16.213341 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 14:32:16.305835 | controller | ok 2025-10-13 14:32:16.321962 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 14:32:16.414745 | 2025-10-13 14:32:16.414876 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 14:32:16.710190 | controller | ok 2025-10-13 14:32:16.717253 | 2025-10-13 14:32:16.717400 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 14:32:16.783949 | controller | ok: "/var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 14:32:16.793135 | 2025-10-13 14:32:16.793250 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 14:32:17.725318 | controller | changed 2025-10-13 14:32:17.730925 | 2025-10-13 14:32:17.730994 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 14:32:17.794063 | controller | ok: "/var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 14:32:17.794235 | controller | ok: All items complete 2025-10-13 14:32:17.794260 | 2025-10-13 14:32:17.849187 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 14:32:17.857046 | 2025-10-13 14:32:17.857121 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 14:32:18.921333 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 14:32:19.887030 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 14:32:19.900717 | 2025-10-13 14:32:19.900852 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 14:32:20.369573 | controller | changed: section and option added 2025-10-13 14:32:20.411018 | 2025-10-13 14:32:20.411144 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 14:32:21.265336 | controller | 29 files removed 2025-10-13 14:32:21.265703 | controller | ok: Item: dnf clean all Runtime: 0:00:00.482631 2025-10-13 14:32:21.265767 | controller | changed: All items complete 2025-10-13 14:32:21.265798 | 2025-10-13 14:32:31.650030 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-10-13 14:32:31.650164 | controller | DNF version: 4.14.0 2025-10-13 14:32:31.650194 | controller | cachedir: /var/cache/dnf 2025-10-13 14:32:31.650219 | controller | Making cache files for all metadata files. 2025-10-13 14:32:31.650247 | controller | baseos: has expired and will be refreshed. 2025-10-13 14:32:31.650273 | controller | appstream: has expired and will be refreshed. 2025-10-13 14:32:31.650299 | controller | crb: has expired and will be refreshed. 2025-10-13 14:32:31.650335 | controller | extras-common: has expired and will be refreshed. 2025-10-13 14:32:31.650360 | controller | repo: downloading from remote: baseos 2025-10-13 14:32:31.650383 | controller | CentOS Stream 9 - BaseOS 76 MB/s | 8.8 MB 00:00 2025-10-13 14:32:31.650407 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 14:32:31.650450 | controller | repo: downloading from remote: appstream 2025-10-13 14:32:31.650474 | controller | CentOS Stream 9 - AppStream 91 MB/s | 25 MB 00:00 2025-10-13 14:32:31.650497 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 14:32:31.650519 | controller | repo: downloading from remote: crb 2025-10-13 14:32:31.650543 | controller | CentOS Stream 9 - CRB 55 MB/s | 7.2 MB 00:00 2025-10-13 14:32:31.650565 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 14:32:31.650588 | controller | repo: downloading from remote: extras-common 2025-10-13 14:32:31.650611 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-10-13 14:32:31.650634 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 14:32:31.650657 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 14:32:31.650706 | controller | Completion plugin: Generating completion cache... 2025-10-13 14:32:31.650733 | controller | Metadata cache created. 2025-10-13 14:32:31.650768 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.122381 2025-10-13 14:32:31.667788 | 2025-10-13 14:32:31.668021 | PLAY RECAP 2025-10-13 14:32:31.668065 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 14:32:31.668093 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:32:31.668111 | 2025-10-13 14:32:31.908599 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:32:31.909444 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:32:35.955431 | 2025-10-13 14:32:35.955558 | PLAY [all] 2025-10-13 14:32:35.987255 | 2025-10-13 14:32:35.987373 | TASK [Install binary dependencies] 2025-10-13 14:32:36.057652 | controller | ok 2025-10-13 14:32:36.078944 | 2025-10-13 14:32:36.079066 | TASK [bindep : Include find tasks] 2025-10-13 14:32:36.108023 | controller | ok 2025-10-13 14:32:36.116314 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 14:32:36.122298 | 2025-10-13 14:32:36.122362 | TASK [bindep : Look for bindep.txt] 2025-10-13 14:32:36.565937 | controller | ok 2025-10-13 14:32:36.575854 | 2025-10-13 14:32:36.575948 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:32:36.607636 | controller | ok 2025-10-13 14:32:36.616065 | 2025-10-13 14:32:36.616138 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 14:32:36.640307 | controller | skipping: Conditional result was False 2025-10-13 14:32:36.648901 | 2025-10-13 14:32:36.648992 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:32:36.673929 | controller | skipping: Conditional result was False 2025-10-13 14:32:36.681202 | 2025-10-13 14:32:36.681274 | TASK [bindep : Look for bindep fallback file] 2025-10-13 14:32:36.715652 | controller | skipping: Conditional result was False 2025-10-13 14:32:36.722587 | 2025-10-13 14:32:36.722721 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:32:36.746692 | controller | skipping: Conditional result was False 2025-10-13 14:32:36.754238 | 2025-10-13 14:32:36.754323 | TASK [bindep : Include bindep tasks] 2025-10-13 14:32:36.785946 | controller | ok 2025-10-13 14:32:36.793909 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 14:32:36.801750 | 2025-10-13 14:32:36.801830 | TASK [bindep : Look for bindep command] 2025-10-13 14:32:36.826212 | controller | skipping: Conditional result was False 2025-10-13 14:32:36.832423 | 2025-10-13 14:32:36.832484 | TASK [bindep : Check for system bindep] 2025-10-13 14:32:37.378742 | controller | ok: Runtime: 0:00:00.007406 2025-10-13 14:32:37.387912 | 2025-10-13 14:32:37.388028 | TASK [bindep : Define bindep_command fact] 2025-10-13 14:32:37.413391 | controller | skipping: Conditional result was False 2025-10-13 14:32:37.424232 | 2025-10-13 14:32:37.424365 | TASK [bindep : Include install tasks] 2025-10-13 14:32:37.461139 | controller | ok 2025-10-13 14:32:37.473332 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 14:32:37.483856 | 2025-10-13 14:32:37.483997 | TASK [bindep : Create temp dir for bindep] 2025-10-13 14:32:37.852124 | controller | changed 2025-10-13 14:32:37.858498 | 2025-10-13 14:32:37.858709 | TASK [Ensure we have pip dependencies] 2025-10-13 14:32:37.879206 | controller | ok 2025-10-13 14:32:37.919812 | 2025-10-13 14:32:37.919945 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 10:32:38.214957 | controller | /usr/bin/pip3 2025-10-13 10:32:38.235056 | controller | /usr/bin/python3: No module named wheel 2025-10-13 14:32:38.451033 | controller | ok: Runtime: 0:00:00.028451 2025-10-13 14:32:38.463605 | 2025-10-13 14:32:38.463784 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 14:32:38.497951 | controller | ok: "/var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 14:32:38.519895 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 14:32:38.543120 | 2025-10-13 14:32:38.543282 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 14:32:40.906720 | controller | changed 2025-10-13 14:32:40.912466 | 2025-10-13 14:32:40.912533 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 14:32:40.967593 | controller | skipping: Conditional result was False 2025-10-13 14:32:40.973913 | 2025-10-13 14:32:40.974019 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 14:32:41.029549 | controller | skipping: Conditional result was False 2025-10-13 14:32:41.036150 | 2025-10-13 14:32:41.036227 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 14:32:41.080430 | controller | skipping: Conditional result was False 2025-10-13 14:32:41.087312 | 2025-10-13 14:32:41.087380 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 14:32:41.112321 | controller | skipping: Conditional result was False 2025-10-13 14:32:41.119630 | 2025-10-13 14:32:41.119721 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 14:32:41.649742 | controller | skipping: Conditional result was False 2025-10-13 14:32:41.664574 | 2025-10-13 14:32:41.664812 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 14:32:41.696271 | controller | skipping: Conditional result was False 2025-10-13 14:32:41.705550 | 2025-10-13 14:32:41.705726 | TASK [ensure-pip : Install pip from source] 2025-10-13 14:32:41.738270 | controller | skipping: Conditional result was False 2025-10-13 14:32:41.748291 | 2025-10-13 14:32:41.748440 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 10:32:42.059853 | controller | /usr/bin/python3 2025-10-13 14:32:42.297271 | controller | ok: Runtime: 0:00:00.005909 2025-10-13 14:32:42.310145 | 2025-10-13 14:32:42.310265 | TASK [ensure-pip : Set host default] 2025-10-13 14:32:42.389619 | controller | ok 2025-10-13 14:32:42.395013 | 2025-10-13 14:32:42.395086 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 14:32:42.458858 | controller | ok 2025-10-13 14:32:42.472483 | 2025-10-13 14:32:42.472598 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 14:32:46.491055 | controller | changed 2025-10-13 14:32:46.499233 | 2025-10-13 14:32:46.499321 | TASK [bindep : Define bindep_command] 2025-10-13 14:32:46.531987 | controller | ok 2025-10-13 14:32:46.537728 | 2025-10-13 14:32:46.537797 | LOOP [bindep : Include package tasks] 2025-10-13 14:32:46.598097 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 14:32:46.598351 | controller | ok: All items complete 2025-10-13 14:32:46.598380 | 2025-10-13 14:32:46.614051 | controller | included: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 14:32:46.626591 | 2025-10-13 14:32:46.626695 | TASK [bindep : Define bindep_run fact] 2025-10-13 14:32:46.659540 | controller | ok 2025-10-13 14:32:46.667253 | 2025-10-13 14:32:46.667320 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 10:32:48.008850 | controller | podman 2025-10-13 10:32:48.045559 | controller | python3-jmespath 2025-10-13 10:32:48.045616 | controller | python3-libvirt 2025-10-13 10:32:48.045723 | controller | python3-lxml 2025-10-13 10:32:48.045744 | controller | python3-netaddr 2025-10-13 14:32:48.204814 | controller | ok: Runtime: 0:00:01.095451 2025-10-13 14:32:48.213199 | 2025-10-13 14:32:48.213353 | TASK [bindep : Install distro packages from bindep] 2025-10-13 14:33:49.712743 | controller | changed 2025-10-13 14:33:49.718963 | 2025-10-13 14:33:49.719037 | TASK [bindep : Check that packages are installed] 2025-10-13 14:33:51.251918 | controller | ok: Runtime: 0:00:01.120122 2025-10-13 14:33:51.260065 | 2025-10-13 14:33:51.260155 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 14:33:51.312061 | controller | skipping: Conditional result was False 2025-10-13 14:33:51.328968 | 2025-10-13 14:33:51.329108 | TASK [Run test-setup role] 2025-10-13 14:33:51.357096 | controller | ok 2025-10-13 14:33:51.386574 | 2025-10-13 14:33:51.386743 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 14:33:51.614378 | controller | ok 2025-10-13 14:33:51.620496 | 2025-10-13 14:33:51.620638 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 14:33:52.150919 | controller | skipping: Conditional result was False 2025-10-13 14:33:52.186144 | 2025-10-13 14:33:52.186277 | TASK [bindep : Remove bindep temp dir] 2025-10-13 14:33:52.566327 | controller | ok 2025-10-13 14:33:52.578045 | 2025-10-13 14:33:52.578134 | PLAY RECAP 2025-10-13 14:33:52.578176 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 14:33:52.578197 | 2025-10-13 14:33:52.723950 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:33:52.724984 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:33:53.407805 | 2025-10-13 14:33:53.407925 | PLAY [all] 2025-10-13 14:33:53.428149 | 2025-10-13 14:33:53.428221 | TASK [Abort when test_command variable is undefined] 2025-10-13 14:33:53.452804 | controller | skipping: Conditional result was False 2025-10-13 14:33:53.458194 | 2025-10-13 14:33:53.458266 | TASK [Convert test_command to list] 2025-10-13 14:33:53.503782 | controller | skipping: Conditional result was False 2025-10-13 14:33:53.510178 | 2025-10-13 14:33:53.510245 | TASK [Use test_command list] 2025-10-13 14:33:53.561213 | controller | ok 2025-10-13 14:33:53.577125 | 2025-10-13 14:33:53.577252 | LOOP [Run test_command] 2025-10-13 14:33:54.019111 | controller | no check to run 2025-10-13 14:33:54.019342 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008827 2025-10-13 14:33:54.063171 | 2025-10-13 14:33:54.063305 | PLAY RECAP 2025-10-13 14:33:54.063393 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:33:54.063452 | 2025-10-13 14:33:54.204342 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:33:54.205586 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:33:54.980301 | 2025-10-13 14:33:54.980462 | PLAY [all] 2025-10-13 14:33:55.002487 | 2025-10-13 14:33:55.002784 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 14:33:55.341723 | controller | changed: non-zero return code 2025-10-13 14:33:55.353103 | 2025-10-13 14:33:55.353266 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 14:33:55.368444 | controller | skipping: Conditional result was False 2025-10-13 14:33:55.375684 | 2025-10-13 14:33:55.375856 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 14:33:55.423792 | 2025-10-13 14:33:55.423985 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 14:33:55.454627 | 2025-10-13 14:33:55.454839 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 14:33:55.489094 | controller | skipping: Conditional result was False 2025-10-13 14:33:55.497828 | 2025-10-13 14:33:55.497965 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 14:33:55.556054 | 2025-10-13 14:33:55.556269 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 14:33:55.582956 | controller | skipping: Conditional result was False 2025-10-13 14:33:55.590316 | 2025-10-13 14:33:55.590427 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 14:33:55.619355 | controller | skipping: Conditional result was False 2025-10-13 14:33:55.625700 | 2025-10-13 14:33:55.625779 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 14:33:55.640516 | controller | skipping: Conditional result was False 2025-10-13 14:33:55.673053 | 2025-10-13 14:33:55.673164 | PLAY RECAP 2025-10-13 14:33:55.673208 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 14:33:55.673228 | 2025-10-13 14:33:55.807554 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:33:55.808451 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:33:56.471221 | 2025-10-13 14:33:56.471361 | PLAY [all] 2025-10-13 14:33:56.493997 | 2025-10-13 14:33:56.494149 | TASK [include_role : fetch-output] 2025-10-13 14:33:56.524854 | controller | ok 2025-10-13 14:33:56.542871 | 2025-10-13 14:33:56.543003 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 14:33:56.588108 | controller | skipping: Conditional result was False 2025-10-13 14:33:56.593959 | 2025-10-13 14:33:56.594046 | TASK [fetch-output : Set log path for single node] 2025-10-13 14:33:56.633071 | controller | ok 2025-10-13 14:33:56.639788 | 2025-10-13 14:33:56.639875 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 14:33:57.166528 | controller -> localhost | ok: "/var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/logs" 2025-10-13 14:33:57.437163 | controller -> localhost | changed: "/var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/artifacts" 2025-10-13 14:33:57.786368 | controller -> localhost | changed: "/var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/docs" 2025-10-13 14:33:57.797782 | 2025-10-13 14:33:57.797927 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 14:33:58.748504 | controller | changed: .d..t...... ./ 2025-10-13 14:33:58.754610 | controller | changed: All items complete 2025-10-13 14:33:58.754660 | 2025-10-13 14:33:59.443835 | controller | changed: .d..t...... ./ 2025-10-13 14:34:00.096471 | controller | changed: .d..t...... ./ 2025-10-13 14:34:00.112385 | 2025-10-13 14:34:00.112503 | TASK [include_role : fetch-output-openshift] 2025-10-13 14:34:00.142022 | controller | skipping: Conditional result was False 2025-10-13 14:34:00.148404 | 2025-10-13 14:34:00.148479 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 14:34:01.016968 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.020803 2025-10-13 14:34:01.267641 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009611 2025-10-13 14:34:01.302796 | 2025-10-13 14:34:01.302919 | PLAY [all] 2025-10-13 14:34:01.321555 | 2025-10-13 14:34:01.321655 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 14:34:01.782647 | controller | changed 2025-10-13 14:34:01.812840 | 2025-10-13 14:34:01.812953 | PLAY RECAP 2025-10-13 14:34:01.812998 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:34:01.813021 | 2025-10-13 14:34:01.930611 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:34:01.931671 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 14:34:02.633210 | 2025-10-13 14:34:02.633322 | PLAY [localhost] 2025-10-13 14:34:02.658127 | 2025-10-13 14:34:02.658240 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 14:34:03.095382 | localhost | changed 2025-10-13 14:34:03.100635 | 2025-10-13 14:34:03.100732 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 14:34:03.130803 | localhost | ok 2025-10-13 14:34:03.139007 | 2025-10-13 14:34:03.139075 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 14:34:03.565792 | localhost | changed 2025-10-13 14:34:03.571658 | 2025-10-13 14:34:03.571755 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 14:34:04.339958 | localhost | changed 2025-10-13 14:34:04.345181 | 2025-10-13 14:34:04.345263 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 14:34:05.025583 | localhost | Identity added: /var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/tmp/ansible.pqs6nfe7 (/var/lib/zuul/builds/0449eca6fd49495f8873b9b80241a6b6/work/tmp/ansible.pqs6nfe7) 2025-10-13 14:34:05.025824 | localhost | ok: Runtime: 0:00:00.029295 2025-10-13 14:34:05.031879 | 2025-10-13 14:34:05.031984 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 14:34:05.399854 | localhost | ok: Runtime: 0:00:00.006801 2025-10-13 14:34:05.406906 | 2025-10-13 14:34:05.407013 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 14:34:05.461939 | localhost | changed 2025-10-13 14:34:05.467443 | 2025-10-13 14:34:05.467512 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 14:34:05.950232 | localhost | changed 2025-10-13 14:34:05.978613 | 2025-10-13 14:34:05.978753 | PLAY [localhost] 2025-10-13 14:34:05.996296 | 2025-10-13 14:34:05.996379 | TASK [Generate bulk log download script] 2025-10-13 14:34:06.024558 | localhost | ok 2025-10-13 14:34:06.038253 | 2025-10-13 14:34:06.038435 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 14:34:06.067192 | localhost | ok: All assertions passed 2025-10-13 14:34:06.071956 | 2025-10-13 14:34:06.072023 | TASK [local-log-download : Create download script] 2025-10-13 14:34:06.799547 | localhost -> localhost | changed 2025-10-13 14:34:06.809393 | 2025-10-13 14:34:06.809455 | TASK [Register quick-download link] 2025-10-13 14:34:06.866095 | localhost | ok 2025-10-13 14:34:06.882291 | 2025-10-13 14:34:06.882357 | PLAY [logserver.rdoproject.org] 2025-10-13 14:34:06.891822 | 2025-10-13 14:34:06.891880 | TASK [Set zuul-log-path fact] 2025-10-13 14:34:06.908179 | logserver.rdoproject.org | ok 2025-10-13 14:34:06.924889 | 2025-10-13 14:34:06.924986 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:34:06.961747 | logserver.rdoproject.org | ok 2025-10-13 14:34:06.967289 | 2025-10-13 14:34:06.967348 | TASK [upload-logs : Create log directories] 2025-10-13 14:34:07.594134 | logserver.rdoproject.org | changed 2025-10-13 14:34:07.597444 | 2025-10-13 14:34:07.597505 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 14:34:08.004516 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.017632 2025-10-13 14:34:08.009489 | 2025-10-13 14:34:08.009577 | TASK [upload-logs : Upload logs to log server] 2025-10-13 14:34:08.744944 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 14:34:08.748731 | 2025-10-13 14:34:08.748814 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 14:34:08.857500 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:34:08.871854 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:34:08.877581 | 2025-10-13 14:34:08.877761 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 14:34:08.941982 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:34:08.942273 | 2025-10-13 14:34:08.942837 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:34:08.951214 | 2025-10-13 14:34:08.951393 | LOOP [upload-logs : Upload console log and json output]