2025-10-13 14:45:03.912843 | Job console starting... 2025-10-13 14:45:03.923585 | Updating repositories 2025-10-13 14:45:03.942260 | Preparing job workspace 2025-10-13 14:45:09.915394 | Running Ansible setup... 2025-10-13 14:45:17.028658 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:45:19.936663 | 2025-10-13 14:45:19.939978 | PLAY [localhost] 2025-10-13 14:45:19.975925 | 2025-10-13 14:45:19.976175 | TASK [Gathering Facts] 2025-10-13 14:45:22.167724 | localhost | ok 2025-10-13 14:45:22.188185 | 2025-10-13 14:45:22.188360 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 14:45:23.396147 | localhost -> localhost | changed 2025-10-13 14:45:23.404946 | 2025-10-13 14:45:23.405140 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 14:45:25.191860 | localhost -> localhost | changed 2025-10-13 14:45:25.203853 | 2025-10-13 14:45:25.204003 | TASK [Setup log path fact] 2025-10-13 14:45:25.267729 | localhost | ok 2025-10-13 14:45:25.329139 | 2025-10-13 14:45:25.329352 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:45:25.378974 | localhost | ok 2025-10-13 14:45:25.405880 | 2025-10-13 14:45:25.406729 | TASK [emit-job-header : Print job information] 2025-10-13 14:45:25.496249 | # Job Information 2025-10-13 14:45:25.496607 | Ansible Version: 2.15.12 2025-10-13 14:45:25.496642 | Job: cifmw-molecule-ipa 2025-10-13 14:45:25.496664 | Pipeline: github-check 2025-10-13 14:45:25.496684 | Executor: ze01.softwarefactory-project.io 2025-10-13 14:45:25.496702 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402 2025-10-13 14:45:25.496723 | Log URL (when completed): https://logserver.rdoproject.org/a20/rdoproject.org/a20ccd5363d744cea9f6f4bbcff7a695/ 2025-10-13 14:45:25.496743 | Event ID: f7c86a20-a842-11f0-8f69-fd957689b554 2025-10-13 14:45:25.505529 | 2025-10-13 14:45:25.505685 | LOOP [emit-job-header : Print node information] 2025-10-13 14:45:25.700630 | localhost | ok: 2025-10-13 14:45:25.700859 | localhost | # Node Information 2025-10-13 14:45:25.700894 | localhost | Inventory Hostname: controller 2025-10-13 14:45:25.700923 | localhost | Hostname: np0005485193 2025-10-13 14:45:25.700948 | localhost | Username: zuul 2025-10-13 14:45:25.700971 | localhost | Distro: CentOS 9 2025-10-13 14:45:25.700991 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 14:45:25.701011 | localhost | Region: RegionOne 2025-10-13 14:45:25.701121 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 14:45:25.701146 | localhost | Product Name: OpenStack Nova 2025-10-13 14:45:25.701165 | localhost | Interface IP: 38.129.56.217 2025-10-13 14:45:25.744738 | 2025-10-13 14:45:25.744857 | PLAY [all] 2025-10-13 14:45:25.756261 | 2025-10-13 14:45:25.756381 | TASK [Gather network facts] 2025-10-13 14:45:26.298094 | controller | ok 2025-10-13 14:45:26.323160 | 2025-10-13 14:45:26.323319 | TASK [include_role : start-zuul-console] 2025-10-13 14:45:26.346121 | controller | ok 2025-10-13 14:45:26.362042 | 2025-10-13 14:45:26.362172 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 14:45:26.980676 | controller | ok 2025-10-13 14:45:26.998962 | 2025-10-13 14:45:26.999124 | TASK [include_role : add-build-sshkey] 2025-10-13 14:45:27.093639 | controller | ok 2025-10-13 14:45:27.169170 | 2025-10-13 14:45:27.169377 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 14:45:27.896978 | controller -> localhost | ok 2025-10-13 14:45:27.904046 | 2025-10-13 14:45:27.904190 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 14:45:27.948258 | controller | ok 2025-10-13 14:45:27.973599 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 14:45:27.983647 | 2025-10-13 14:45:27.983820 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 14:45:29.661452 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 14:45:29.661670 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/a20ccd5363d744cea9f6f4bbcff7a695_id_rsa. 2025-10-13 14:45:29.661702 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/a20ccd5363d744cea9f6f4bbcff7a695_id_rsa.pub. 2025-10-13 14:45:29.661725 | controller -> localhost | The key fingerprint is: 2025-10-13 14:45:29.661745 | controller -> localhost | SHA256:uBdg55zKCqVRJlhuvyovuvIM1bqkkw3WEqI20KYHhqQ zuul-build-sshkey 2025-10-13 14:45:29.661767 | controller -> localhost | The key's randomart image is: 2025-10-13 14:45:29.661786 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 14:45:29.661804 | controller -> localhost | | . | 2025-10-13 14:45:29.661823 | controller -> localhost | | = | 2025-10-13 14:45:29.661842 | controller -> localhost | |=.+ o o . | 2025-10-13 14:45:29.661861 | controller -> localhost | |E+o* . * . | 2025-10-13 14:45:29.661880 | controller -> localhost | |=+= + . S | 2025-10-13 14:45:29.661898 | controller -> localhost | |+*.* o o . | 2025-10-13 14:45:29.661916 | controller -> localhost | |+=B . + . | 2025-10-13 14:45:29.661934 | controller -> localhost | |*=.+ . . | 2025-10-13 14:45:29.661952 | controller -> localhost | |*B* . | 2025-10-13 14:45:29.661979 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 14:45:29.662051 | controller -> localhost | ok: Runtime: 0:00:00.730317 2025-10-13 14:45:29.669812 | 2025-10-13 14:45:29.669895 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 14:45:29.744658 | controller | ok 2025-10-13 14:45:29.783904 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 14:45:29.805585 | 2025-10-13 14:45:29.805749 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 14:45:29.862142 | controller | skipping: Conditional result was False 2025-10-13 14:45:29.870191 | 2025-10-13 14:45:29.870388 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 14:45:30.642980 | controller | changed 2025-10-13 14:45:30.656158 | 2025-10-13 14:45:30.656310 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 14:45:31.016564 | controller | ok 2025-10-13 14:45:31.022453 | 2025-10-13 14:45:31.022611 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 14:45:32.143433 | controller | changed 2025-10-13 14:45:32.149798 | 2025-10-13 14:45:32.149909 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 14:45:33.224056 | controller | changed 2025-10-13 14:45:33.234647 | 2025-10-13 14:45:33.234794 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 14:45:33.277808 | controller | skipping: Conditional result was False 2025-10-13 14:45:33.287672 | 2025-10-13 14:45:33.287831 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 14:45:34.019697 | controller -> localhost | changed 2025-10-13 14:45:34.080373 | 2025-10-13 14:45:34.080538 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 14:45:34.735139 | controller -> localhost | Identity added: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/a20ccd5363d744cea9f6f4bbcff7a695_id_rsa (zuul-build-sshkey) 2025-10-13 14:45:34.735427 | controller -> localhost | ok: Runtime: 0:00:00.023800 2025-10-13 14:45:34.744087 | 2025-10-13 14:45:34.744258 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 14:45:35.167592 | controller | ok 2025-10-13 14:45:35.183980 | 2025-10-13 14:45:35.184219 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 14:45:35.249969 | controller | skipping: Conditional result was False 2025-10-13 14:45:35.263177 | 2025-10-13 14:45:35.263322 | TASK [include_role : validate-host] 2025-10-13 14:45:35.313433 | controller | ok 2025-10-13 14:45:35.346670 | 2025-10-13 14:45:35.346826 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 14:45:35.424109 | controller | ok 2025-10-13 14:45:35.436460 | 2025-10-13 14:45:35.436633 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 14:45:35.845646 | controller -> localhost | ok 2025-10-13 14:45:35.853431 | 2025-10-13 14:45:35.853597 | TASK [validate-host : Collect information about the host] 2025-10-13 14:45:36.698383 | controller | ok 2025-10-13 14:45:36.734811 | 2025-10-13 14:45:36.734984 | TASK [validate-host : Sanitize hostname] 2025-10-13 14:45:36.797770 | controller | ok 2025-10-13 14:45:36.819052 | 2025-10-13 14:45:36.819207 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 14:45:37.529999 | controller -> localhost | changed 2025-10-13 14:45:37.536865 | 2025-10-13 14:45:37.536993 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 14:45:38.081493 | controller | ok 2025-10-13 14:45:38.092124 | 2025-10-13 14:45:38.092228 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 14:45:38.725250 | controller -> localhost | changed 2025-10-13 14:45:38.737432 | 2025-10-13 14:45:38.738069 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 14:45:38.758174 | controller | skipping: Conditional result was False 2025-10-13 14:45:38.764385 | 2025-10-13 14:45:38.764516 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 14:45:38.809743 | controller | skipping: Conditional result was False 2025-10-13 14:45:38.816907 | 2025-10-13 14:45:38.817089 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:45:39.176596 | controller | ok: "logs" 2025-10-13 14:45:39.176852 | controller | ok: All items complete 2025-10-13 14:45:39.176878 | 2025-10-13 14:45:39.423932 | controller | ok: "artifacts" 2025-10-13 14:45:39.684536 | controller | ok: "docs" 2025-10-13 14:45:39.697471 | 2025-10-13 14:45:39.697593 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:45:39.997287 | controller | changed: "logs" 2025-10-13 14:45:40.272769 | controller | changed: "artifacts" 2025-10-13 14:45:40.495522 | controller | changed: "docs" 2025-10-13 14:45:40.548461 | 2025-10-13 14:45:40.548598 | PLAY RECAP 2025-10-13 14:45:40.548657 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 14:45:40.548693 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:45:40.548717 | 2025-10-13 14:45:40.817224 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:45:40.818090 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:45:41.720909 | 2025-10-13 14:45:41.721111 | PLAY [localhost] 2025-10-13 14:45:41.745222 | 2025-10-13 14:45:41.745437 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 14:45:42.337111 | localhost | ok 2025-10-13 14:45:42.345744 | 2025-10-13 14:45:42.346011 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 14:45:43.428434 | localhost | changed 2025-10-13 14:45:43.461767 | 2025-10-13 14:45:43.461906 | PLAY [all] 2025-10-13 14:45:43.479600 | 2025-10-13 14:45:43.479691 | TASK [include_role : prepare-workspace] 2025-10-13 14:45:43.512881 | controller | ok 2025-10-13 14:45:43.546282 | 2025-10-13 14:45:43.546473 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 14:45:44.173589 | controller | ok 2025-10-13 14:45:44.195850 | 2025-10-13 14:45:44.196116 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 14:45:46.872010 | controller | Output suppressed because no_log was given 2025-10-13 14:45:46.907788 | 2025-10-13 14:45:46.907945 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:45:47.258293 | controller | changed: "logs" 2025-10-13 14:45:47.486836 | controller | changed: "artifacts" 2025-10-13 14:45:47.726470 | controller | changed: "docs" 2025-10-13 14:45:47.742794 | 2025-10-13 14:45:47.742951 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:45:48.073357 | controller | changed: "logs" 2025-10-13 14:45:48.074158 | controller | changed: All items complete 2025-10-13 14:45:48.074204 | 2025-10-13 14:45:48.362706 | controller | changed: "artifacts" 2025-10-13 14:45:48.632648 | controller | changed: "docs" 2025-10-13 14:45:48.678296 | 2025-10-13 14:45:48.678445 | TASK [Check if worker can sudo] 2025-10-13 14:45:49.769867 | controller | ok: Runtime: 0:00:00.041170 2025-10-13 14:45:49.776963 | 2025-10-13 14:45:49.777096 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 14:45:50.012249 | controller | skipping: Conditional result was False 2025-10-13 14:45:50.020862 | 2025-10-13 14:45:50.020943 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 14:45:50.351169 | controller | ok 2025-10-13 14:45:50.371244 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 14:45:50.402964 | 2025-10-13 14:45:50.403107 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 14:45:50.786495 | controller | ok 2025-10-13 14:45:50.795592 | 2025-10-13 14:45:50.795747 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 14:45:50.944275 | controller | ok: "/var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 14:45:50.963707 | 2025-10-13 14:45:50.963887 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 14:45:52.118123 | controller | changed 2025-10-13 14:45:52.131550 | 2025-10-13 14:45:52.131757 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 14:45:52.282507 | controller | ok: "/var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 14:45:52.282753 | controller | ok: All items complete 2025-10-13 14:45:52.282792 | 2025-10-13 14:45:52.438959 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 14:45:52.463575 | 2025-10-13 14:45:52.463756 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 14:45:53.657769 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 14:45:54.590325 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 14:45:54.606171 | 2025-10-13 14:45:54.606360 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 14:45:55.323303 | controller | changed: section and option added 2025-10-13 14:45:55.422916 | 2025-10-13 14:45:55.423128 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 14:45:56.875507 | controller | 29 files removed 2025-10-13 14:45:56.882176 | controller | ok: Item: dnf clean all Runtime: 0:00:00.988374 2025-10-13 14:45:56.882330 | controller | changed: All items complete 2025-10-13 14:45:56.882362 | 2025-10-13 14:46:07.589557 | 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:46:07.589691 | controller | DNF version: 4.14.0 2025-10-13 14:46:07.589718 | controller | cachedir: /var/cache/dnf 2025-10-13 14:46:07.589738 | controller | Making cache files for all metadata files. 2025-10-13 14:46:07.589758 | controller | baseos: has expired and will be refreshed. 2025-10-13 14:46:07.589776 | controller | appstream: has expired and will be refreshed. 2025-10-13 14:46:07.589794 | controller | crb: has expired and will be refreshed. 2025-10-13 14:46:07.589824 | controller | extras-common: has expired and will be refreshed. 2025-10-13 14:46:07.589843 | controller | repo: downloading from remote: baseos 2025-10-13 14:46:07.589861 | controller | CentOS Stream 9 - BaseOS 56 MB/s | 8.8 MB 00:00 2025-10-13 14:46:07.589879 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 14:46:07.589896 | controller | repo: downloading from remote: appstream 2025-10-13 14:46:07.589913 | controller | CentOS Stream 9 - AppStream 91 MB/s | 25 MB 00:00 2025-10-13 14:46:07.589931 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 14:46:07.589948 | controller | repo: downloading from remote: crb 2025-10-13 14:46:07.589964 | controller | CentOS Stream 9 - CRB 57 MB/s | 7.2 MB 00:00 2025-10-13 14:46:07.589981 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 14:46:07.589998 | controller | repo: downloading from remote: extras-common 2025-10-13 14:46:07.590032 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-10-13 14:46:07.590069 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 14:46:07.590105 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 14:46:07.590128 | controller | Completion plugin: Generating completion cache... 2025-10-13 14:46:07.590147 | controller | Metadata cache created. 2025-10-13 14:46:07.590179 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.412529 2025-10-13 14:46:07.686057 | 2025-10-13 14:46:07.686227 | PLAY RECAP 2025-10-13 14:46:07.686279 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 14:46:07.686305 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:46:07.686323 | 2025-10-13 14:46:07.904708 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:46:07.905655 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:46:08.627155 | 2025-10-13 14:46:08.627318 | PLAY [all] 2025-10-13 14:46:08.654070 | 2025-10-13 14:46:08.654254 | TASK [Install binary dependencies] 2025-10-13 14:46:08.719935 | controller | ok 2025-10-13 14:46:08.749463 | 2025-10-13 14:46:08.749670 | TASK [bindep : Include find tasks] 2025-10-13 14:46:08.783150 | controller | ok 2025-10-13 14:46:08.792085 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 14:46:08.799328 | 2025-10-13 14:46:08.799474 | TASK [bindep : Look for bindep.txt] 2025-10-13 14:46:09.255814 | controller | ok 2025-10-13 14:46:09.263093 | 2025-10-13 14:46:09.263237 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:46:09.302800 | controller | ok 2025-10-13 14:46:09.317623 | 2025-10-13 14:46:09.317865 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 14:46:09.344427 | controller | skipping: Conditional result was False 2025-10-13 14:46:09.352716 | 2025-10-13 14:46:09.352911 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:46:09.379142 | controller | skipping: Conditional result was False 2025-10-13 14:46:09.390077 | 2025-10-13 14:46:09.390552 | TASK [bindep : Look for bindep fallback file] 2025-10-13 14:46:09.426199 | controller | skipping: Conditional result was False 2025-10-13 14:46:09.436320 | 2025-10-13 14:46:09.436504 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:46:09.462338 | controller | skipping: Conditional result was False 2025-10-13 14:46:09.469621 | 2025-10-13 14:46:09.469779 | TASK [bindep : Include bindep tasks] 2025-10-13 14:46:09.515196 | controller | ok 2025-10-13 14:46:09.524840 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 14:46:09.539502 | 2025-10-13 14:46:09.539686 | TASK [bindep : Look for bindep command] 2025-10-13 14:46:09.588294 | controller | skipping: Conditional result was False 2025-10-13 14:46:09.599515 | 2025-10-13 14:46:09.599688 | TASK [bindep : Check for system bindep] 2025-10-13 14:46:10.143720 | controller | ok: Runtime: 0:00:00.004670 2025-10-13 14:46:10.152157 | 2025-10-13 14:46:10.152303 | TASK [bindep : Define bindep_command fact] 2025-10-13 14:46:10.177726 | controller | skipping: Conditional result was False 2025-10-13 14:46:10.187204 | 2025-10-13 14:46:10.187487 | TASK [bindep : Include install tasks] 2025-10-13 14:46:10.229522 | controller | ok 2025-10-13 14:46:10.241867 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 14:46:10.253408 | 2025-10-13 14:46:10.253554 | TASK [bindep : Create temp dir for bindep] 2025-10-13 14:46:10.691245 | controller | changed 2025-10-13 14:46:10.702661 | 2025-10-13 14:46:10.703047 | TASK [Ensure we have pip dependencies] 2025-10-13 14:46:10.728886 | controller | ok 2025-10-13 14:46:10.768336 | 2025-10-13 14:46:10.768481 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 10:46:11.045282 | controller | /usr/bin/pip3 2025-10-13 10:46:11.065978 | controller | /usr/bin/python3: No module named wheel 2025-10-13 14:46:11.310568 | controller | ok: Runtime: 0:00:00.030140 2025-10-13 14:46:11.326151 | 2025-10-13 14:46:11.326372 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 14:46:11.367112 | controller | ok: "/var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 14:46:11.387040 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 14:46:11.399828 | 2025-10-13 14:46:11.399976 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 14:46:15.132441 | controller | changed 2025-10-13 14:46:15.140090 | 2025-10-13 14:46:15.140257 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 14:46:15.196397 | controller | skipping: Conditional result was False 2025-10-13 14:46:15.204645 | 2025-10-13 14:46:15.204772 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 14:46:15.251568 | controller | skipping: Conditional result was False 2025-10-13 14:46:15.259466 | 2025-10-13 14:46:15.259623 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 14:46:15.310632 | controller | skipping: Conditional result was False 2025-10-13 14:46:15.318449 | 2025-10-13 14:46:15.318625 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 14:46:15.343600 | controller | skipping: Conditional result was False 2025-10-13 14:46:15.356135 | 2025-10-13 14:46:15.356331 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 14:46:15.920304 | controller | skipping: Conditional result was False 2025-10-13 14:46:15.940774 | 2025-10-13 14:46:15.940998 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 14:46:15.967786 | controller | skipping: Conditional result was False 2025-10-13 14:46:15.977366 | 2025-10-13 14:46:15.977563 | TASK [ensure-pip : Install pip from source] 2025-10-13 14:46:15.995095 | controller | skipping: Conditional result was False 2025-10-13 14:46:16.005047 | 2025-10-13 14:46:16.005243 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 10:46:16.333350 | controller | /usr/bin/python3 2025-10-13 14:46:16.549620 | controller | ok: Runtime: 0:00:00.005371 2025-10-13 14:46:16.557391 | 2025-10-13 14:46:16.557724 | TASK [ensure-pip : Set host default] 2025-10-13 14:46:16.610031 | controller | ok 2025-10-13 14:46:16.615559 | 2025-10-13 14:46:16.615671 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 14:46:16.683532 | controller | ok 2025-10-13 14:46:16.694994 | 2025-10-13 14:46:16.695148 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 14:46:21.193982 | controller | changed 2025-10-13 14:46:21.201452 | 2025-10-13 14:46:21.201603 | TASK [bindep : Define bindep_command] 2025-10-13 14:46:21.234238 | controller | ok 2025-10-13 14:46:21.240237 | 2025-10-13 14:46:21.240348 | LOOP [bindep : Include package tasks] 2025-10-13 14:46:21.307472 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 14:46:21.307677 | controller | ok: All items complete 2025-10-13 14:46:21.307720 | 2025-10-13 14:46:21.326600 | controller | included: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 14:46:21.349624 | 2025-10-13 14:46:21.349829 | TASK [bindep : Define bindep_run fact] 2025-10-13 14:46:21.390876 | controller | ok 2025-10-13 14:46:21.401104 | 2025-10-13 14:46:21.401262 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 10:46:22.676629 | controller | podman 2025-10-13 10:46:22.704813 | controller | python3-jmespath 2025-10-13 10:46:22.704864 | controller | python3-libvirt 2025-10-13 10:46:22.704872 | controller | python3-lxml 2025-10-13 10:46:22.704880 | controller | python3-netaddr 2025-10-13 14:46:22.946139 | controller | ok: Runtime: 0:00:01.052313 2025-10-13 14:46:22.955847 | 2025-10-13 14:46:22.956129 | TASK [bindep : Install distro packages from bindep] 2025-10-13 14:47:28.454249 | controller | changed 2025-10-13 14:47:28.468723 | 2025-10-13 14:47:28.468876 | TASK [bindep : Check that packages are installed] 2025-10-13 14:47:30.016087 | controller | ok: Runtime: 0:00:01.120029 2025-10-13 14:47:30.033995 | 2025-10-13 14:47:30.034242 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 14:47:30.062367 | controller | skipping: Conditional result was False 2025-10-13 14:47:30.080144 | 2025-10-13 14:47:30.080499 | TASK [Run test-setup role] 2025-10-13 14:47:30.105373 | controller | ok 2025-10-13 14:47:30.129465 | 2025-10-13 14:47:30.129599 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 14:47:30.344682 | controller | ok 2025-10-13 14:47:30.350935 | 2025-10-13 14:47:30.351092 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 14:47:30.885465 | controller | skipping: Conditional result was False 2025-10-13 14:47:30.926422 | 2025-10-13 14:47:30.926567 | TASK [bindep : Remove bindep temp dir] 2025-10-13 14:47:31.327428 | controller | ok 2025-10-13 14:47:31.337994 | 2025-10-13 14:47:31.338109 | PLAY RECAP 2025-10-13 14:47:31.338153 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 14:47:31.338173 | 2025-10-13 14:47:31.476965 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:47:31.477993 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:47:32.202607 | 2025-10-13 14:47:32.202778 | PLAY [all] 2025-10-13 14:47:32.234198 | 2025-10-13 14:47:32.234366 | TASK [Abort when test_command variable is undefined] 2025-10-13 14:47:32.269752 | controller | skipping: Conditional result was False 2025-10-13 14:47:32.276533 | 2025-10-13 14:47:32.276662 | TASK [Convert test_command to list] 2025-10-13 14:47:32.322331 | controller | skipping: Conditional result was False 2025-10-13 14:47:32.329562 | 2025-10-13 14:47:32.329664 | TASK [Use test_command list] 2025-10-13 14:47:32.390288 | controller | ok 2025-10-13 14:47:32.396335 | 2025-10-13 14:47:32.396431 | LOOP [Run test_command] 2025-10-13 14:47:32.833575 | controller | no check to run 2025-10-13 14:47:32.833781 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005717 2025-10-13 14:47:32.866504 | 2025-10-13 14:47:32.866614 | PLAY RECAP 2025-10-13 14:47:32.866658 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:47:32.866679 | 2025-10-13 14:47:33.014784 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:47:33.015915 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:47:33.745492 | 2025-10-13 14:47:33.745654 | PLAY [all] 2025-10-13 14:47:33.769313 | 2025-10-13 14:47:33.769476 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 14:47:34.153844 | controller | changed: non-zero return code 2025-10-13 14:47:34.172413 | 2025-10-13 14:47:34.172625 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 14:47:34.226919 | controller | skipping: Conditional result was False 2025-10-13 14:47:34.233260 | 2025-10-13 14:47:34.233389 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 14:47:34.265056 | 2025-10-13 14:47:34.265223 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 14:47:34.295761 | 2025-10-13 14:47:34.295943 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 14:47:34.312354 | controller | skipping: Conditional result was False 2025-10-13 14:47:34.320412 | 2025-10-13 14:47:34.320732 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 14:47:34.353967 | 2025-10-13 14:47:34.354210 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 14:47:34.382857 | controller | skipping: Conditional result was False 2025-10-13 14:47:34.389353 | 2025-10-13 14:47:34.389460 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 14:47:34.404572 | controller | skipping: Conditional result was False 2025-10-13 14:47:34.411607 | 2025-10-13 14:47:34.411727 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 14:47:34.426731 | controller | skipping: Conditional result was False 2025-10-13 14:47:34.457819 | 2025-10-13 14:47:34.457947 | PLAY RECAP 2025-10-13 14:47:34.458008 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 14:47:34.458094 | 2025-10-13 14:47:34.611531 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:47:34.612635 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:47:35.306399 | 2025-10-13 14:47:35.306534 | PLAY [all] 2025-10-13 14:47:35.334331 | 2025-10-13 14:47:35.334517 | TASK [include_role : fetch-output] 2025-10-13 14:47:35.376987 | controller | ok 2025-10-13 14:47:35.399460 | 2025-10-13 14:47:35.399615 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 14:47:35.465804 | controller | skipping: Conditional result was False 2025-10-13 14:47:35.474142 | 2025-10-13 14:47:35.474305 | TASK [fetch-output : Set log path for single node] 2025-10-13 14:47:35.520940 | controller | ok 2025-10-13 14:47:35.541151 | 2025-10-13 14:47:35.541303 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 14:47:36.014119 | controller -> localhost | ok: "/var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/logs" 2025-10-13 14:47:36.288694 | controller -> localhost | changed: "/var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/artifacts" 2025-10-13 14:47:36.582574 | controller -> localhost | changed: "/var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/docs" 2025-10-13 14:47:36.602688 | 2025-10-13 14:47:36.602829 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 14:47:37.367969 | controller | changed: .d..t...... ./ 2025-10-13 14:47:37.368818 | controller | changed: All items complete 2025-10-13 14:47:37.368880 | 2025-10-13 14:47:37.835248 | controller | changed: .d..t...... ./ 2025-10-13 14:47:38.275100 | controller | changed: .d..t...... ./ 2025-10-13 14:47:38.294660 | 2025-10-13 14:47:38.294784 | TASK [include_role : fetch-output-openshift] 2025-10-13 14:47:38.309211 | controller | skipping: Conditional result was False 2025-10-13 14:47:38.317758 | 2025-10-13 14:47:38.317892 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 14:47:38.813813 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.021014 2025-10-13 14:47:39.064993 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012543 2025-10-13 14:47:39.122519 | 2025-10-13 14:47:39.122719 | PLAY [all] 2025-10-13 14:47:39.146032 | 2025-10-13 14:47:39.146194 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 14:47:39.630743 | controller | changed 2025-10-13 14:47:39.673468 | 2025-10-13 14:47:39.673620 | PLAY RECAP 2025-10-13 14:47:39.673681 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:47:39.673712 | 2025-10-13 14:47:39.841556 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:47:39.842390 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 14:47:40.610479 | 2025-10-13 14:47:40.610615 | PLAY [localhost] 2025-10-13 14:47:40.636448 | 2025-10-13 14:47:40.636598 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 14:47:41.107694 | localhost | changed 2025-10-13 14:47:41.113457 | 2025-10-13 14:47:41.113569 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 14:47:41.145795 | localhost | ok 2025-10-13 14:47:41.157245 | 2025-10-13 14:47:41.157396 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 14:47:41.545727 | localhost | changed 2025-10-13 14:47:41.552009 | 2025-10-13 14:47:41.552112 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 14:47:42.286825 | localhost | changed 2025-10-13 14:47:42.292842 | 2025-10-13 14:47:42.292925 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 14:47:42.754734 | localhost | Identity added: /var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/tmp/ansible.4x7f2nt4 (/var/lib/zuul/builds/a20ccd5363d744cea9f6f4bbcff7a695/work/tmp/ansible.4x7f2nt4) 2025-10-13 14:47:42.754950 | localhost | ok: Runtime: 0:00:00.020830 2025-10-13 14:47:42.759348 | 2025-10-13 14:47:42.759419 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 14:47:43.041270 | localhost | ok: Runtime: 0:00:00.005867 2025-10-13 14:47:43.046278 | 2025-10-13 14:47:43.046347 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 14:47:43.107332 | localhost | changed 2025-10-13 14:47:43.112272 | 2025-10-13 14:47:43.112353 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 14:47:43.559899 | localhost | changed 2025-10-13 14:47:43.597703 | 2025-10-13 14:47:43.597823 | PLAY [localhost] 2025-10-13 14:47:43.613174 | 2025-10-13 14:47:43.613273 | TASK [Generate bulk log download script] 2025-10-13 14:47:43.642611 | localhost | ok 2025-10-13 14:47:43.661706 | 2025-10-13 14:47:43.661851 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 14:47:43.691491 | localhost | ok: All assertions passed 2025-10-13 14:47:43.696291 | 2025-10-13 14:47:43.696354 | TASK [local-log-download : Create download script] 2025-10-13 14:47:44.164528 | localhost -> localhost | changed 2025-10-13 14:47:44.174153 | 2025-10-13 14:47:44.174237 | TASK [Register quick-download link] 2025-10-13 14:47:44.204827 | localhost | ok 2025-10-13 14:47:44.251969 | 2025-10-13 14:47:44.252105 | PLAY [logserver.rdoproject.org] 2025-10-13 14:47:44.263397 | 2025-10-13 14:47:44.263476 | TASK [Set zuul-log-path fact] 2025-10-13 14:47:44.291006 | logserver.rdoproject.org | ok 2025-10-13 14:47:44.300747 | 2025-10-13 14:47:44.300855 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:47:44.328248 | logserver.rdoproject.org | ok 2025-10-13 14:47:44.333905 | 2025-10-13 14:47:44.333974 | TASK [upload-logs : Create log directories] 2025-10-13 14:47:45.015800 | logserver.rdoproject.org | changed 2025-10-13 14:47:45.024242 | 2025-10-13 14:47:45.024352 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 14:47:45.359318 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006824 2025-10-13 14:47:45.365006 | 2025-10-13 14:47:45.365579 | TASK [upload-logs : Upload logs to log server] 2025-10-13 14:47:46.080050 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 14:47:46.083794 | 2025-10-13 14:47:46.083874 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 14:47:46.151389 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:47:46.153498 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:47:46.157795 | 2025-10-13 14:47:46.157936 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 14:47:46.204920 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:47:46.205255 | 2025-10-13 14:47:46.205935 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:47:46.210427 | 2025-10-13 14:47:46.210562 | LOOP [upload-logs : Upload console log and json output]