2025-10-14 07:15:08.675605 | Job console starting... 2025-10-14 07:15:08.687813 | Updating repositories 2025-10-14 07:15:08.721434 | Preparing job workspace 2025-10-14 07:15:13.290874 | Running Ansible setup... 2025-10-14 07:15:17.247282 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-14 07:15:18.019680 | 2025-10-14 07:15:18.019788 | PLAY [localhost] 2025-10-14 07:15:18.028275 | 2025-10-14 07:15:18.028346 | TASK [Gathering Facts] 2025-10-14 07:15:18.924140 | localhost | ok 2025-10-14 07:15:18.961103 | 2025-10-14 07:15:18.961275 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-14 07:15:19.429141 | localhost -> localhost | changed 2025-10-14 07:15:19.434989 | 2025-10-14 07:15:19.435089 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-14 07:15:20.437984 | localhost -> localhost | changed 2025-10-14 07:15:20.447519 | 2025-10-14 07:15:20.447609 | TASK [Setup log path fact] 2025-10-14 07:15:20.466595 | localhost | ok 2025-10-14 07:15:20.479552 | 2025-10-14 07:15:20.479630 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-14 07:15:20.506695 | localhost | ok 2025-10-14 07:15:20.520887 | 2025-10-14 07:15:20.520968 | TASK [emit-job-header : Print job information] 2025-10-14 07:15:20.559357 | # Job Information 2025-10-14 07:15:20.559496 | Ansible Version: 2.15.12 2025-10-14 07:15:20.559521 | Job: cifmw-molecule-ci_dcn_site 2025-10-14 07:15:20.559541 | Pipeline: github-check 2025-10-14 07:15:20.559559 | Executor: ze01.softwarefactory-project.io 2025-10-14 07:15:20.559578 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-14 07:15:20.559597 | Log URL (when completed): https://logserver.rdoproject.org/c2e/rdoproject.org/c2e4abbbece34ff799455390a87739ce/ 2025-10-14 07:15:20.559615 | Event ID: 345da600-a8cd-11f0-86c5-939673711c42 2025-10-14 07:15:20.563449 | 2025-10-14 07:15:20.563507 | LOOP [emit-job-header : Print node information] 2025-10-14 07:15:20.706078 | localhost | ok: 2025-10-14 07:15:20.706220 | localhost | # Node Information 2025-10-14 07:15:20.706246 | localhost | Inventory Hostname: controller 2025-10-14 07:15:20.706270 | localhost | Hostname: np0005486967 2025-10-14 07:15:20.706289 | localhost | Username: zuul 2025-10-14 07:15:20.706309 | localhost | Distro: CentOS 9 2025-10-14 07:15:20.706329 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-14 07:15:20.706347 | localhost | Region: RegionOne 2025-10-14 07:15:20.706363 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-14 07:15:20.706379 | localhost | Product Name: OpenStack Nova 2025-10-14 07:15:20.706394 | localhost | Interface IP: 38.102.83.182 2025-10-14 07:15:20.727548 | 2025-10-14 07:15:20.727601 | PLAY [all] 2025-10-14 07:15:20.738505 | 2025-10-14 07:15:20.738567 | TASK [Gather network facts] 2025-10-14 07:15:21.259714 | controller | ok 2025-10-14 07:15:21.289163 | 2025-10-14 07:15:21.289310 | TASK [include_role : start-zuul-console] 2025-10-14 07:15:21.323579 | controller | ok 2025-10-14 07:15:21.335884 | 2025-10-14 07:15:21.335971 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-14 07:15:21.781318 | controller | ok 2025-10-14 07:15:21.791804 | 2025-10-14 07:15:21.791900 | TASK [include_role : add-build-sshkey] 2025-10-14 07:15:21.810591 | controller | ok 2025-10-14 07:15:21.824281 | 2025-10-14 07:15:21.824348 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-14 07:15:22.040760 | controller -> localhost | ok 2025-10-14 07:15:22.046417 | 2025-10-14 07:15:22.046480 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-14 07:15:22.089862 | controller | ok 2025-10-14 07:15:22.106946 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-14 07:15:22.113614 | 2025-10-14 07:15:22.113675 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-14 07:15:22.681379 | controller -> localhost | Generating public/private rsa key pair. 2025-10-14 07:15:22.681676 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/c2e4abbbece34ff799455390a87739ce_id_rsa. 2025-10-14 07:15:22.681718 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/c2e4abbbece34ff799455390a87739ce_id_rsa.pub. 2025-10-14 07:15:22.681748 | controller -> localhost | The key fingerprint is: 2025-10-14 07:15:22.681775 | controller -> localhost | SHA256:lNrUXs02Zo19pIcXaX6oPlDPX90atlkC7n5qmcZTUP0 zuul-build-sshkey 2025-10-14 07:15:22.681802 | controller -> localhost | The key's randomart image is: 2025-10-14 07:15:22.681828 | controller -> localhost | +---[RSA 3072]----+ 2025-10-14 07:15:22.681852 | controller -> localhost | | oo| 2025-10-14 07:15:22.681877 | controller -> localhost | | o o.Xo| 2025-10-14 07:15:22.681901 | controller -> localhost | | + . ..&.B| 2025-10-14 07:15:22.681925 | controller -> localhost | | = . .++.=E| 2025-10-14 07:15:22.681948 | controller -> localhost | | . S .o * +| 2025-10-14 07:15:22.681972 | controller -> localhost | | . o B =| 2025-10-14 07:15:22.681994 | controller -> localhost | | = = O.| 2025-10-14 07:15:22.682060 | controller -> localhost | | @ = .| 2025-10-14 07:15:22.682093 | controller -> localhost | | +o= | 2025-10-14 07:15:22.682119 | controller -> localhost | +----[SHA256]-----+ 2025-10-14 07:15:22.682179 | controller -> localhost | ok: Runtime: 0:00:00.154661 2025-10-14 07:15:22.689546 | 2025-10-14 07:15:22.689608 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-14 07:15:22.718931 | controller | ok 2025-10-14 07:15:22.728543 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-14 07:15:22.736670 | 2025-10-14 07:15:22.736733 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-14 07:15:22.760792 | controller | skipping: Conditional result was False 2025-10-14 07:15:22.766366 | 2025-10-14 07:15:22.766441 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-14 07:15:23.259735 | controller | changed 2025-10-14 07:15:23.268524 | 2025-10-14 07:15:23.268645 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-14 07:15:23.558495 | controller | ok 2025-10-14 07:15:23.566459 | 2025-10-14 07:15:23.566570 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-14 07:15:24.527842 | controller | changed 2025-10-14 07:15:24.535593 | 2025-10-14 07:15:24.535709 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-14 07:15:25.542421 | controller | changed 2025-10-14 07:15:25.551319 | 2025-10-14 07:15:25.551445 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-14 07:15:25.565133 | controller | skipping: Conditional result was False 2025-10-14 07:15:25.571838 | 2025-10-14 07:15:25.571910 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-14 07:15:26.006089 | controller -> localhost | changed 2025-10-14 07:15:26.020732 | 2025-10-14 07:15:26.020857 | TASK [add-build-sshkey : Add back temp key] 2025-10-14 07:15:26.298862 | controller -> localhost | Identity added: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/c2e4abbbece34ff799455390a87739ce_id_rsa (zuul-build-sshkey) 2025-10-14 07:15:26.299179 | controller -> localhost | ok: Runtime: 0:00:00.009065 2025-10-14 07:15:26.304809 | 2025-10-14 07:15:26.304868 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-14 07:15:26.679670 | controller | ok 2025-10-14 07:15:26.684513 | 2025-10-14 07:15:26.684582 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-14 07:15:26.753230 | controller | skipping: Conditional result was False 2025-10-14 07:15:26.765373 | 2025-10-14 07:15:26.765450 | TASK [include_role : validate-host] 2025-10-14 07:15:26.809556 | controller | ok 2025-10-14 07:15:26.838008 | 2025-10-14 07:15:26.838152 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-14 07:15:26.867175 | controller | ok 2025-10-14 07:15:26.872048 | 2025-10-14 07:15:26.872109 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-14 07:15:27.139920 | controller -> localhost | ok 2025-10-14 07:15:27.146460 | 2025-10-14 07:15:27.146547 | TASK [validate-host : Collect information about the host] 2025-10-14 07:15:28.018810 | controller | ok 2025-10-14 07:15:28.037106 | 2025-10-14 07:15:28.037217 | TASK [validate-host : Sanitize hostname] 2025-10-14 07:15:28.142769 | controller | ok 2025-10-14 07:15:28.148099 | 2025-10-14 07:15:28.148180 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-14 07:15:28.630116 | controller -> localhost | changed 2025-10-14 07:15:28.636714 | 2025-10-14 07:15:28.636787 | TASK [validate-host : Collect information about zuul worker] 2025-10-14 07:15:29.125222 | controller | ok 2025-10-14 07:15:29.130084 | 2025-10-14 07:15:29.130147 | TASK [validate-host : Write out all zuul information for each host] 2025-10-14 07:15:29.708513 | controller -> localhost | changed 2025-10-14 07:15:29.728665 | 2025-10-14 07:15:29.728775 | TASK [include_role : prepare-workspace-openshift] 2025-10-14 07:15:29.747917 | controller | skipping: Conditional result was False 2025-10-14 07:15:29.753896 | 2025-10-14 07:15:29.754034 | TASK [include_role : remove-zuul-sshkey] 2025-10-14 07:15:29.809444 | controller | skipping: Conditional result was False 2025-10-14 07:15:29.815656 | 2025-10-14 07:15:29.815748 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-14 07:15:30.116723 | controller | ok: "logs" 2025-10-14 07:15:30.117053 | controller | ok: All items complete 2025-10-14 07:15:30.117099 | 2025-10-14 07:15:30.327252 | controller | ok: "artifacts" 2025-10-14 07:15:30.551938 | controller | ok: "docs" 2025-10-14 07:15:30.560591 | 2025-10-14 07:15:30.560717 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-14 07:15:30.944184 | controller | changed: "logs" 2025-10-14 07:15:31.230634 | controller | changed: "artifacts" 2025-10-14 07:15:31.496402 | controller | changed: "docs" 2025-10-14 07:15:31.548512 | 2025-10-14 07:15:31.548642 | PLAY RECAP 2025-10-14 07:15:31.548691 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-14 07:15:31.548717 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-14 07:15:31.548736 | 2025-10-14 07:15:31.744751 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-14 07:15:31.746068 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-14 07:15:32.853712 | 2025-10-14 07:15:32.853862 | PLAY [localhost] 2025-10-14 07:15:32.870488 | 2025-10-14 07:15:32.870567 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-14 07:15:33.296607 | localhost | ok 2025-10-14 07:15:33.302366 | 2025-10-14 07:15:33.302445 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-14 07:15:34.054489 | localhost | changed 2025-10-14 07:15:34.081010 | 2025-10-14 07:15:34.081142 | PLAY [all] 2025-10-14 07:15:34.102910 | 2025-10-14 07:15:34.103089 | TASK [include_role : prepare-workspace] 2025-10-14 07:15:34.131292 | controller | ok 2025-10-14 07:15:34.146782 | 2025-10-14 07:15:34.146875 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-14 07:15:34.587744 | controller | ok 2025-10-14 07:15:34.596040 | 2025-10-14 07:15:34.596115 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-14 07:15:36.505784 | controller | Output suppressed because no_log was given 2025-10-14 07:15:36.519867 | 2025-10-14 07:15:36.519976 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-14 07:15:36.805090 | controller | changed: "logs" 2025-10-14 07:15:37.027633 | controller | changed: "artifacts" 2025-10-14 07:15:37.240465 | controller | changed: "docs" 2025-10-14 07:15:37.254164 | 2025-10-14 07:15:37.254311 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-14 07:15:37.547418 | controller | changed: "logs" 2025-10-14 07:15:37.547649 | controller | changed: All items complete 2025-10-14 07:15:37.547677 | 2025-10-14 07:15:37.750259 | controller | changed: "artifacts" 2025-10-14 07:15:38.016545 | controller | changed: "docs" 2025-10-14 07:15:38.042827 | 2025-10-14 07:15:38.042990 | TASK [Check if worker can sudo] 2025-10-14 07:15:38.604287 | controller | ok: Runtime: 0:00:00.059380 2025-10-14 07:15:38.613054 | 2025-10-14 07:15:38.613156 | TASK [configure-mirrors : Gather needed facts] 2025-10-14 07:15:38.659218 | controller | skipping: Conditional result was False 2025-10-14 07:15:38.669293 | 2025-10-14 07:15:38.669406 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-14 07:15:38.742046 | controller | ok 2025-10-14 07:15:38.750995 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-14 07:15:38.757889 | 2025-10-14 07:15:38.757997 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-14 07:15:39.073578 | controller | ok 2025-10-14 07:15:39.085495 | 2025-10-14 07:15:39.085583 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-14 07:15:39.177938 | controller | ok: "/var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-14 07:15:39.187518 | 2025-10-14 07:15:39.187633 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-14 07:15:40.159626 | controller | changed 2025-10-14 07:15:40.165005 | 2025-10-14 07:15:40.165090 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-14 07:15:40.219750 | controller | ok: "/var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-14 07:15:40.220041 | controller | ok: All items complete 2025-10-14 07:15:40.220076 | 2025-10-14 07:15:40.274116 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-14 07:15:40.289531 | 2025-10-14 07:15:40.289676 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-14 07:15:41.236629 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-14 07:15:42.149831 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-14 07:15:42.172398 | 2025-10-14 07:15:42.172628 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-14 07:15:42.725790 | controller | changed: section and option added 2025-10-14 07:15:42.755595 | 2025-10-14 07:15:42.755735 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-14 07:15:43.612152 | controller | 29 files removed 2025-10-14 07:15:43.612368 | controller | ok: Item: dnf clean all Runtime: 0:00:00.475942 2025-10-14 07:15:43.612408 | controller | changed: All items complete 2025-10-14 07:15:43.612429 | 2025-10-14 07:15:54.121968 | 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-14 07:15:54.122498 | controller | DNF version: 4.14.0 2025-10-14 07:15:54.122539 | controller | cachedir: /var/cache/dnf 2025-10-14 07:15:54.122563 | controller | Making cache files for all metadata files. 2025-10-14 07:15:54.122583 | controller | baseos: has expired and will be refreshed. 2025-10-14 07:15:54.122602 | controller | appstream: has expired and will be refreshed. 2025-10-14 07:15:54.122620 | controller | crb: has expired and will be refreshed. 2025-10-14 07:15:54.122645 | controller | extras-common: has expired and will be refreshed. 2025-10-14 07:15:54.122664 | controller | repo: downloading from remote: baseos 2025-10-14 07:15:54.122683 | controller | CentOS Stream 9 - BaseOS 85 MB/s | 8.8 MB 00:00 2025-10-14 07:15:54.122704 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-14 07:15:54.122724 | controller | repo: downloading from remote: appstream 2025-10-14 07:15:54.122742 | controller | CentOS Stream 9 - AppStream 98 MB/s | 25 MB 00:00 2025-10-14 07:15:54.122760 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-14 07:15:54.122778 | controller | repo: downloading from remote: crb 2025-10-14 07:15:54.122796 | controller | CentOS Stream 9 - CRB 96 MB/s | 7.2 MB 00:00 2025-10-14 07:15:54.122815 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-14 07:15:54.122832 | controller | repo: downloading from remote: extras-common 2025-10-14 07:15:54.122850 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-14 07:15:54.122868 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-14 07:15:54.122911 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-14 07:15:54.122931 | controller | Completion plugin: Generating completion cache... 2025-10-14 07:15:54.122950 | controller | Metadata cache created. 2025-10-14 07:15:54.122977 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.205738 2025-10-14 07:15:54.141699 | 2025-10-14 07:15:54.141794 | PLAY RECAP 2025-10-14 07:15:54.141838 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-14 07:15:54.141865 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-14 07:15:54.141884 | 2025-10-14 07:15:54.306408 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-14 07:15:54.307218 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-14 07:15:55.495534 | 2025-10-14 07:15:55.495688 | PLAY [all] 2025-10-14 07:15:55.532886 | 2025-10-14 07:15:55.533007 | TASK [Install binary dependencies] 2025-10-14 07:15:55.641619 | controller | ok 2025-10-14 07:15:55.687970 | 2025-10-14 07:15:55.688154 | TASK [bindep : Include find tasks] 2025-10-14 07:15:55.752828 | controller | ok 2025-10-14 07:15:55.766778 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-14 07:15:55.784379 | 2025-10-14 07:15:55.784513 | TASK [bindep : Look for bindep.txt] 2025-10-14 07:15:56.369656 | controller | ok 2025-10-14 07:15:56.393737 | 2025-10-14 07:15:56.393856 | TASK [bindep : Define bindep_file fact] 2025-10-14 07:15:56.452212 | controller | ok 2025-10-14 07:15:56.459392 | 2025-10-14 07:15:56.459473 | TASK [bindep : Look for other-requirements.txt] 2025-10-14 07:15:56.492615 | controller | skipping: Conditional result was False 2025-10-14 07:15:56.501149 | 2025-10-14 07:15:56.501260 | TASK [bindep : Define bindep_file fact] 2025-10-14 07:15:56.525408 | controller | skipping: Conditional result was False 2025-10-14 07:15:56.532096 | 2025-10-14 07:15:56.532201 | TASK [bindep : Look for bindep fallback file] 2025-10-14 07:15:56.586797 | controller | skipping: Conditional result was False 2025-10-14 07:15:56.593301 | 2025-10-14 07:15:56.593397 | TASK [bindep : Define bindep_file fact] 2025-10-14 07:15:56.639378 | controller | skipping: Conditional result was False 2025-10-14 07:15:56.647826 | 2025-10-14 07:15:56.647922 | TASK [bindep : Include bindep tasks] 2025-10-14 07:15:56.743517 | controller | ok 2025-10-14 07:15:56.761954 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-14 07:15:56.795629 | 2025-10-14 07:15:56.795737 | TASK [bindep : Look for bindep command] 2025-10-14 07:15:56.853093 | controller | skipping: Conditional result was False 2025-10-14 07:15:56.860701 | 2025-10-14 07:15:56.860789 | TASK [bindep : Check for system bindep] 2025-10-14 07:15:57.417490 | controller | ok: Runtime: 0:00:00.005949 2025-10-14 07:15:57.427438 | 2025-10-14 07:15:57.427562 | TASK [bindep : Define bindep_command fact] 2025-10-14 07:15:57.467367 | controller | skipping: Conditional result was False 2025-10-14 07:15:57.475577 | 2025-10-14 07:15:57.475658 | TASK [bindep : Include install tasks] 2025-10-14 07:15:57.531237 | controller | ok 2025-10-14 07:15:57.542406 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-14 07:15:57.556757 | 2025-10-14 07:15:57.556917 | TASK [bindep : Create temp dir for bindep] 2025-10-14 07:15:58.010234 | controller | changed 2025-10-14 07:15:58.016222 | 2025-10-14 07:15:58.016336 | TASK [Ensure we have pip dependencies] 2025-10-14 07:15:58.061288 | controller | ok 2025-10-14 07:15:58.127210 | 2025-10-14 07:15:58.127318 | TASK [ensure-pip : Check if pip is installed] 2025-10-14 03:15:58.397553 | controller | /usr/bin/pip3 2025-10-14 03:15:58.423682 | controller | /usr/bin/python3: No module named wheel 2025-10-14 07:15:58.686836 | controller | ok: Runtime: 0:00:00.035489 2025-10-14 07:15:58.693152 | 2025-10-14 07:15:58.693246 | LOOP [ensure-pip : Install pip from packages] 2025-10-14 07:15:58.747810 | controller | ok: "/var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-14 07:15:58.762554 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-14 07:15:58.785807 | 2025-10-14 07:15:58.785922 | TASK [ensure-pip : Install Python 3 pip] 2025-10-14 07:16:01.337990 | controller | changed 2025-10-14 07:16:01.350837 | 2025-10-14 07:16:01.350963 | TASK [ensure-pip : Check for EPEL repository] 2025-10-14 07:16:01.426712 | controller | skipping: Conditional result was False 2025-10-14 07:16:01.433693 | 2025-10-14 07:16:01.433784 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-14 07:16:01.541949 | controller | skipping: Conditional result was False 2025-10-14 07:16:01.548918 | 2025-10-14 07:16:01.549002 | TASK [ensure-pip : Install Python 2 pip] 2025-10-14 07:16:01.642044 | controller | skipping: Conditional result was False 2025-10-14 07:16:01.648386 | 2025-10-14 07:16:01.648475 | TASK [ensure-pip : Ensure setuptools] 2025-10-14 07:16:01.684401 | controller | skipping: Conditional result was False 2025-10-14 07:16:01.690552 | 2025-10-14 07:16:01.690636 | TASK [ensure-pip : Check for ensurepip module] 2025-10-14 07:16:02.222710 | controller | skipping: Conditional result was False 2025-10-14 07:16:02.232919 | 2025-10-14 07:16:02.233058 | TASK [ensure-pip : Ensure python3-venv] 2025-10-14 07:16:02.278208 | controller | skipping: Conditional result was False 2025-10-14 07:16:02.285611 | 2025-10-14 07:16:02.285719 | TASK [ensure-pip : Install pip from source] 2025-10-14 07:16:02.342078 | controller | skipping: Conditional result was False 2025-10-14 07:16:02.348601 | 2025-10-14 07:16:02.348719 | TASK [ensure-pip : Probe for venv python full path] 2025-10-14 03:16:02.654403 | controller | /usr/bin/python3 2025-10-14 07:16:02.915954 | controller | ok: Runtime: 0:00:00.004890 2025-10-14 07:16:02.921894 | 2025-10-14 07:16:02.921989 | TASK [ensure-pip : Set host default] 2025-10-14 07:16:02.985509 | controller | ok 2025-10-14 07:16:02.992313 | 2025-10-14 07:16:02.992451 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-14 07:16:03.054471 | controller | ok 2025-10-14 07:16:03.086607 | 2025-10-14 07:16:03.086738 | TASK [bindep : Install bindep into temporary venv] 2025-10-14 07:16:07.203859 | controller | changed 2025-10-14 07:16:07.216130 | 2025-10-14 07:16:07.216279 | TASK [bindep : Define bindep_command] 2025-10-14 07:16:07.260696 | controller | ok 2025-10-14 07:16:07.267702 | 2025-10-14 07:16:07.267796 | LOOP [bindep : Include package tasks] 2025-10-14 07:16:07.316915 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-14 07:16:07.317085 | controller | ok: All items complete 2025-10-14 07:16:07.317113 | 2025-10-14 07:16:07.334386 | controller | included: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-14 07:16:07.349316 | 2025-10-14 07:16:07.349401 | TASK [bindep : Define bindep_run fact] 2025-10-14 07:16:07.371124 | controller | ok 2025-10-14 07:16:07.378657 | 2025-10-14 07:16:07.378742 | TASK [bindep : Get list of packages to install from bindep] 2025-10-14 03:16:08.705638 | controller | podman 2025-10-14 03:16:08.753390 | controller | python3-jmespath 2025-10-14 03:16:08.753459 | controller | python3-libvirt 2025-10-14 03:16:08.753470 | controller | python3-lxml 2025-10-14 03:16:08.753542 | controller | python3-netaddr 2025-10-14 07:16:08.915994 | controller | ok: Runtime: 0:00:01.152330 2025-10-14 07:16:08.922107 | 2025-10-14 07:16:08.922199 | TASK [bindep : Install distro packages from bindep] 2025-10-14 07:17:10.432831 | controller | changed 2025-10-14 07:17:10.443855 | 2025-10-14 07:17:10.444088 | TASK [bindep : Check that packages are installed] 2025-10-14 07:17:11.991821 | controller | ok: Runtime: 0:00:01.191431 2025-10-14 07:17:12.006136 | 2025-10-14 07:17:12.006274 | TASK [bindep : Fail if we cannot install all packages] 2025-10-14 07:17:12.027402 | controller | skipping: Conditional result was False 2025-10-14 07:17:12.051087 | 2025-10-14 07:17:12.051229 | TASK [Run test-setup role] 2025-10-14 07:17:12.074181 | controller | ok 2025-10-14 07:17:12.097985 | 2025-10-14 07:17:12.098144 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-14 07:17:12.348856 | controller | ok 2025-10-14 07:17:12.360695 | 2025-10-14 07:17:12.360832 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-14 07:17:12.904266 | controller | skipping: Conditional result was False 2025-10-14 07:17:12.937128 | 2025-10-14 07:17:12.937291 | TASK [bindep : Remove bindep temp dir] 2025-10-14 07:17:13.345234 | controller | ok 2025-10-14 07:17:13.360738 | 2025-10-14 07:17:13.360834 | PLAY RECAP 2025-10-14 07:17:13.360891 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-14 07:17:13.360921 | 2025-10-14 07:17:13.475200 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-14 07:17:13.476923 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-14 07:17:14.087832 | 2025-10-14 07:17:14.087939 | PLAY [all] 2025-10-14 07:17:14.108123 | 2025-10-14 07:17:14.108205 | TASK [Abort when test_command variable is undefined] 2025-10-14 07:17:14.153606 | controller | skipping: Conditional result was False 2025-10-14 07:17:14.162423 | 2025-10-14 07:17:14.162543 | TASK [Convert test_command to list] 2025-10-14 07:17:14.226997 | controller | skipping: Conditional result was False 2025-10-14 07:17:14.233271 | 2025-10-14 07:17:14.233340 | TASK [Use test_command list] 2025-10-14 07:17:14.313105 | controller | ok 2025-10-14 07:17:14.318857 | 2025-10-14 07:17:14.318945 | LOOP [Run test_command] 2025-10-14 07:17:14.766650 | controller | no check to run 2025-10-14 07:17:14.766941 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007803 2025-10-14 07:17:14.826647 | 2025-10-14 07:17:14.826753 | PLAY RECAP 2025-10-14 07:17:14.826793 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-14 07:17:14.826814 | 2025-10-14 07:17:14.967529 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-14 07:17:14.968436 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-14 07:17:15.572325 | 2025-10-14 07:17:15.572434 | PLAY [all] 2025-10-14 07:17:15.592692 | 2025-10-14 07:17:15.592769 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-14 07:17:16.039189 | controller | changed: non-zero return code 2025-10-14 07:17:16.047404 | 2025-10-14 07:17:16.047504 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-14 07:17:16.072711 | controller | skipping: Conditional result was False 2025-10-14 07:17:16.079167 | 2025-10-14 07:17:16.079245 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-14 07:17:16.110663 | 2025-10-14 07:17:16.110814 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-14 07:17:16.130468 | 2025-10-14 07:17:16.130597 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-14 07:17:16.144159 | controller | skipping: Conditional result was False 2025-10-14 07:17:16.150128 | 2025-10-14 07:17:16.150194 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-14 07:17:16.170655 | 2025-10-14 07:17:16.170781 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-14 07:17:16.184183 | controller | skipping: Conditional result was False 2025-10-14 07:17:16.189715 | 2025-10-14 07:17:16.189778 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-14 07:17:16.203093 | controller | skipping: Conditional result was False 2025-10-14 07:17:16.209366 | 2025-10-14 07:17:16.209433 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-14 07:17:16.223067 | controller | skipping: Conditional result was False 2025-10-14 07:17:16.253066 | 2025-10-14 07:17:16.253159 | PLAY RECAP 2025-10-14 07:17:16.253200 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-14 07:17:16.253222 | 2025-10-14 07:17:16.345256 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-14 07:17:16.346197 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-14 07:17:16.994569 | 2025-10-14 07:17:16.994690 | PLAY [all] 2025-10-14 07:17:17.018004 | 2025-10-14 07:17:17.018171 | TASK [include_role : fetch-output] 2025-10-14 07:17:17.073855 | controller | ok 2025-10-14 07:17:17.094299 | 2025-10-14 07:17:17.094446 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-14 07:17:17.169499 | controller | skipping: Conditional result was False 2025-10-14 07:17:17.175745 | 2025-10-14 07:17:17.175816 | TASK [fetch-output : Set log path for single node] 2025-10-14 07:17:17.215274 | controller | ok 2025-10-14 07:17:17.222337 | 2025-10-14 07:17:17.222472 | LOOP [fetch-output : Ensure local output dirs] 2025-10-14 07:17:17.630935 | controller -> localhost | ok: "/var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/logs" 2025-10-14 07:17:17.846087 | controller -> localhost | changed: "/var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/artifacts" 2025-10-14 07:17:18.126538 | controller -> localhost | changed: "/var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/docs" 2025-10-14 07:17:18.143515 | 2025-10-14 07:17:18.143658 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-14 07:17:18.869933 | controller | changed: .d..t...... ./ 2025-10-14 07:17:18.870259 | controller | changed: All items complete 2025-10-14 07:17:18.870301 | 2025-10-14 07:17:19.368061 | controller | changed: .d..t...... ./ 2025-10-14 07:17:19.938119 | controller | changed: .d..t...... ./ 2025-10-14 07:17:19.956916 | 2025-10-14 07:17:19.957062 | TASK [include_role : fetch-output-openshift] 2025-10-14 07:17:19.971538 | controller | skipping: Conditional result was False 2025-10-14 07:17:19.980437 | 2025-10-14 07:17:19.980570 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-14 07:17:20.421988 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.015409 2025-10-14 07:17:20.646612 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.011399 2025-10-14 07:17:20.702621 | 2025-10-14 07:17:20.702772 | PLAY [all] 2025-10-14 07:17:20.723749 | 2025-10-14 07:17:20.723875 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-14 07:17:21.152479 | controller | changed 2025-10-14 07:17:21.176905 | 2025-10-14 07:17:21.176989 | PLAY RECAP 2025-10-14 07:17:21.177046 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-14 07:17:21.177071 | 2025-10-14 07:17:21.284668 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-14 07:17:21.285523 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-14 07:17:21.903795 | 2025-10-14 07:17:21.903919 | PLAY [localhost] 2025-10-14 07:17:21.926302 | 2025-10-14 07:17:21.926434 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-14 07:17:22.306593 | localhost | changed 2025-10-14 07:17:22.317364 | 2025-10-14 07:17:22.317539 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-14 07:17:22.353910 | localhost | ok 2025-10-14 07:17:22.372617 | 2025-10-14 07:17:22.372761 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-14 07:17:22.762184 | localhost | changed 2025-10-14 07:17:22.768203 | 2025-10-14 07:17:22.768311 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-14 07:17:23.486819 | localhost | changed 2025-10-14 07:17:23.495305 | 2025-10-14 07:17:23.495397 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-14 07:17:23.911505 | localhost | Identity added: /var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/tmp/ansible.x78uiz0x (/var/lib/zuul/builds/c2e4abbbece34ff799455390a87739ce/work/tmp/ansible.x78uiz0x) 2025-10-14 07:17:23.911673 | localhost | ok: Runtime: 0:00:00.007339 2025-10-14 07:17:23.916477 | 2025-10-14 07:17:23.916543 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-14 07:17:24.179914 | localhost | ok: Runtime: 0:00:00.006954 2025-10-14 07:17:24.188102 | 2025-10-14 07:17:24.188186 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-14 07:17:24.279218 | localhost | changed 2025-10-14 07:17:24.283641 | 2025-10-14 07:17:24.283704 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-14 07:17:24.647995 | localhost | changed 2025-10-14 07:17:24.671127 | 2025-10-14 07:17:24.671197 | PLAY [localhost] 2025-10-14 07:17:24.684985 | 2025-10-14 07:17:24.685080 | TASK [Generate bulk log download script] 2025-10-14 07:17:24.703970 | localhost | ok 2025-10-14 07:17:24.715742 | 2025-10-14 07:17:24.715809 | TASK [local-log-download : Check API endpoint is defined] 2025-10-14 07:17:24.753880 | localhost | ok: All assertions passed 2025-10-14 07:17:24.758559 | 2025-10-14 07:17:24.758619 | TASK [local-log-download : Create download script] 2025-10-14 07:17:25.208998 | localhost -> localhost | changed 2025-10-14 07:17:25.230093 | 2025-10-14 07:17:25.230246 | TASK [Register quick-download link] 2025-10-14 07:17:25.263251 | localhost | ok 2025-10-14 07:17:25.308860 | 2025-10-14 07:17:25.308963 | PLAY [logserver.rdoproject.org] 2025-10-14 07:17:25.318545 | 2025-10-14 07:17:25.318605 | TASK [Set zuul-log-path fact] 2025-10-14 07:17:25.334932 | logserver.rdoproject.org | ok 2025-10-14 07:17:25.344474 | 2025-10-14 07:17:25.344547 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-14 07:17:25.381207 | logserver.rdoproject.org | ok 2025-10-14 07:17:25.386884 | 2025-10-14 07:17:25.386948 | TASK [upload-logs : Create log directories] 2025-10-14 07:17:26.032983 | logserver.rdoproject.org | changed 2025-10-14 07:17:26.036480 | 2025-10-14 07:17:26.036549 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-14 07:17:26.334599 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005754 2025-10-14 07:17:26.339617 | 2025-10-14 07:17:26.339683 | TASK [upload-logs : Upload logs to log server] 2025-10-14 07:17:27.022660 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-14 07:17:27.028888 | 2025-10-14 07:17:27.028981 | LOOP [upload-logs : Compress console log and json output] 2025-10-14 07:17:27.080517 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 07:17:27.091207 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 07:17:27.099329 | 2025-10-14 07:17:27.099449 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-14 07:17:27.164449 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 07:17:27.164707 | 2025-10-14 07:17:27.169499 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-14 07:17:27.178827 | 2025-10-14 07:17:27.178948 | LOOP [upload-logs : Upload console log and json output]