2025-10-13 14:52:59.196416 | Job console starting... 2025-10-13 14:52:59.207419 | Updating repositories 2025-10-13 14:52:59.234120 | Preparing job workspace 2025-10-13 14:53:03.859404 | Running Ansible setup... 2025-10-13 14:53:09.848142 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:53:10.940113 | 2025-10-13 14:53:10.940246 | PLAY [localhost] 2025-10-13 14:53:10.953402 | 2025-10-13 14:53:10.953492 | TASK [Gathering Facts] 2025-10-13 14:53:12.905480 | localhost | ok 2025-10-13 14:53:12.967136 | 2025-10-13 14:53:12.967291 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 14:53:13.782357 | localhost -> localhost | changed 2025-10-13 14:53:13.794766 | 2025-10-13 14:53:13.794893 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 14:53:15.062276 | localhost -> localhost | changed 2025-10-13 14:53:15.073332 | 2025-10-13 14:53:15.073407 | TASK [Setup log path fact] 2025-10-13 14:53:15.092751 | localhost | ok 2025-10-13 14:53:15.108499 | 2025-10-13 14:53:15.108602 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:53:15.148005 | localhost | ok 2025-10-13 14:53:15.157231 | 2025-10-13 14:53:15.157304 | TASK [emit-job-header : Print job information] 2025-10-13 14:53:15.228218 | # Job Information 2025-10-13 14:53:15.228358 | Ansible Version: 2.15.12 2025-10-13 14:53:15.228384 | Job: cifmw-molecule-cleanup_openstack 2025-10-13 14:53:15.228404 | Pipeline: github-check 2025-10-13 14:53:15.228422 | Executor: ze04.softwarefactory-project.io 2025-10-13 14:53:15.228439 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402 2025-10-13 14:53:15.228458 | Log URL (when completed): https://logserver.rdoproject.org/3c8/rdoproject.org/3c87909c2c7747f8a1d73a8905fb162c/ 2025-10-13 14:53:15.228477 | Event ID: 03ccc7c0-a844-11f0-9fcd-d5792746e07c 2025-10-13 14:53:15.232150 | 2025-10-13 14:53:15.232216 | LOOP [emit-job-header : Print node information] 2025-10-13 14:53:15.530991 | localhost | ok: 2025-10-13 14:53:15.531155 | localhost | # Node Information 2025-10-13 14:53:15.531180 | localhost | Inventory Hostname: controller 2025-10-13 14:53:15.531204 | localhost | Hostname: np0005485324 2025-10-13 14:53:15.531224 | localhost | Username: zuul 2025-10-13 14:53:15.531245 | localhost | Distro: CentOS 9 2025-10-13 14:53:15.531263 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 14:53:15.531280 | localhost | Region: RegionOne 2025-10-13 14:53:15.531297 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 14:53:15.531314 | localhost | Product Name: OpenStack Nova 2025-10-13 14:53:15.531330 | localhost | Interface IP: 38.129.56.109 2025-10-13 14:53:15.587285 | 2025-10-13 14:53:15.587401 | PLAY [all] 2025-10-13 14:53:15.605548 | 2025-10-13 14:53:15.605640 | TASK [Gather network facts] 2025-10-13 14:53:16.129738 | controller | ok 2025-10-13 14:53:16.166463 | 2025-10-13 14:53:16.166552 | TASK [include_role : start-zuul-console] 2025-10-13 14:53:16.215077 | controller | ok 2025-10-13 14:53:16.247408 | 2025-10-13 14:53:16.247516 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 14:53:16.930099 | controller | ok 2025-10-13 14:53:16.947290 | 2025-10-13 14:53:16.947397 | TASK [include_role : add-build-sshkey] 2025-10-13 14:53:16.999131 | controller | ok 2025-10-13 14:53:17.018228 | 2025-10-13 14:53:17.018361 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 14:53:17.330599 | controller -> localhost | ok 2025-10-13 14:53:17.340324 | 2025-10-13 14:53:17.340416 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 14:53:17.402067 | controller | ok 2025-10-13 14:53:17.450023 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 14:53:17.470641 | 2025-10-13 14:53:17.470771 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 14:53:18.533839 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 14:53:18.534015 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/3c87909c2c7747f8a1d73a8905fb162c_id_rsa. 2025-10-13 14:53:18.534046 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/3c87909c2c7747f8a1d73a8905fb162c_id_rsa.pub. 2025-10-13 14:53:18.534068 | controller -> localhost | The key fingerprint is: 2025-10-13 14:53:18.534088 | controller -> localhost | SHA256:1RN7mIvv1HA9VIolpWIIZQXvmDlzUyPzfq3FijVkj98 zuul-build-sshkey 2025-10-13 14:53:18.534107 | controller -> localhost | The key's randomart image is: 2025-10-13 14:53:18.534125 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 14:53:18.534142 | controller -> localhost | | ..+o. o.o .| 2025-10-13 14:53:18.534161 | controller -> localhost | | o o . X ..| 2025-10-13 14:53:18.534178 | controller -> localhost | | . B @ o. | 2025-10-13 14:53:18.534196 | controller -> localhost | | B B =.. | 2025-10-13 14:53:18.534214 | controller -> localhost | | S = + +..| 2025-10-13 14:53:18.534231 | controller -> localhost | | + + * =.| 2025-10-13 14:53:18.534248 | controller -> localhost | | + * =| 2025-10-13 14:53:18.534268 | controller -> localhost | | o + *.| 2025-10-13 14:53:18.534286 | controller -> localhost | | o o E| 2025-10-13 14:53:18.534303 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 14:53:18.534350 | controller -> localhost | ok: Runtime: 0:00:00.326861 2025-10-13 14:53:18.540103 | 2025-10-13 14:53:18.540189 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 14:53:18.566189 | controller | ok 2025-10-13 14:53:18.576319 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 14:53:18.584382 | 2025-10-13 14:53:18.584446 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 14:53:18.598152 | controller | skipping: Conditional result was False 2025-10-13 14:53:18.603830 | 2025-10-13 14:53:18.603897 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 14:53:19.132528 | controller | changed 2025-10-13 14:53:19.138834 | 2025-10-13 14:53:19.138902 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 14:53:19.442544 | controller | ok 2025-10-13 14:53:19.449963 | 2025-10-13 14:53:19.450042 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 14:53:20.339960 | controller | changed 2025-10-13 14:53:20.345190 | 2025-10-13 14:53:20.345252 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 14:53:21.240263 | controller | changed 2025-10-13 14:53:21.249247 | 2025-10-13 14:53:21.249386 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 14:53:21.279331 | controller | skipping: Conditional result was False 2025-10-13 14:53:21.286160 | 2025-10-13 14:53:21.286229 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 14:53:21.770154 | controller -> localhost | changed 2025-10-13 14:53:21.785871 | 2025-10-13 14:53:21.786002 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 14:53:22.332018 | controller -> localhost | Identity added: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/3c87909c2c7747f8a1d73a8905fb162c_id_rsa (zuul-build-sshkey) 2025-10-13 14:53:22.332219 | controller -> localhost | ok: Runtime: 0:00:00.016822 2025-10-13 14:53:22.337842 | 2025-10-13 14:53:22.337910 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 14:53:22.871779 | controller | ok 2025-10-13 14:53:22.880165 | 2025-10-13 14:53:22.880238 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 14:53:22.954612 | controller | skipping: Conditional result was False 2025-10-13 14:53:22.964319 | 2025-10-13 14:53:22.964390 | TASK [include_role : validate-host] 2025-10-13 14:53:23.018041 | controller | ok 2025-10-13 14:53:23.087574 | 2025-10-13 14:53:23.087696 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 14:53:23.119701 | controller | ok 2025-10-13 14:53:23.124822 | 2025-10-13 14:53:23.124893 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 14:53:23.526004 | controller -> localhost | ok 2025-10-13 14:53:23.531998 | 2025-10-13 14:53:23.532065 | TASK [validate-host : Collect information about the host] 2025-10-13 14:53:24.325157 | controller | ok 2025-10-13 14:53:24.351415 | 2025-10-13 14:53:24.351537 | TASK [validate-host : Sanitize hostname] 2025-10-13 14:53:24.453734 | controller | ok 2025-10-13 14:53:24.463200 | 2025-10-13 14:53:24.463279 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 14:53:25.335422 | controller -> localhost | changed 2025-10-13 14:53:25.341134 | 2025-10-13 14:53:25.341213 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 14:53:25.746312 | controller | ok 2025-10-13 14:53:25.757282 | 2025-10-13 14:53:25.757365 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 14:53:26.459344 | controller -> localhost | changed 2025-10-13 14:53:26.470448 | 2025-10-13 14:53:26.470574 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 14:53:26.506845 | controller | skipping: Conditional result was False 2025-10-13 14:53:26.512215 | 2025-10-13 14:53:26.512277 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 14:53:26.535960 | controller | skipping: Conditional result was False 2025-10-13 14:53:26.541527 | 2025-10-13 14:53:26.541591 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:53:26.794287 | controller | ok: "logs" 2025-10-13 14:53:26.794523 | controller | ok: All items complete 2025-10-13 14:53:26.794553 | 2025-10-13 14:53:27.028605 | controller | ok: "artifacts" 2025-10-13 14:53:27.254445 | controller | ok: "docs" 2025-10-13 14:53:27.272114 | 2025-10-13 14:53:27.272239 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:53:27.584437 | controller | changed: "logs" 2025-10-13 14:53:27.803725 | controller | changed: "artifacts" 2025-10-13 14:53:28.016384 | controller | changed: "docs" 2025-10-13 14:53:28.075994 | 2025-10-13 14:53:28.076099 | PLAY RECAP 2025-10-13 14:53:28.076140 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 14:53:28.076167 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:53:28.076185 | 2025-10-13 14:53:28.219962 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:53:28.223884 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:53:29.176361 | 2025-10-13 14:53:29.176473 | PLAY [localhost] 2025-10-13 14:53:29.193010 | 2025-10-13 14:53:29.193097 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 14:53:29.708851 | localhost | ok 2025-10-13 14:53:29.720787 | 2025-10-13 14:53:29.720905 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 14:53:30.491886 | localhost | changed 2025-10-13 14:53:30.517825 | 2025-10-13 14:53:30.517927 | PLAY [all] 2025-10-13 14:53:30.569577 | 2025-10-13 14:53:30.569736 | TASK [include_role : prepare-workspace] 2025-10-13 14:53:30.613638 | controller | ok 2025-10-13 14:53:30.635946 | 2025-10-13 14:53:30.636098 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 14:53:31.034132 | controller | ok 2025-10-13 14:53:31.041259 | 2025-10-13 14:53:31.041328 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 14:53:32.901427 | controller | Output suppressed because no_log was given 2025-10-13 14:53:32.912576 | 2025-10-13 14:53:32.912650 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:53:33.155845 | controller | changed: "logs" 2025-10-13 14:53:33.369934 | controller | changed: "artifacts" 2025-10-13 14:53:33.610823 | controller | changed: "docs" 2025-10-13 14:53:33.621659 | 2025-10-13 14:53:33.621827 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:53:33.893972 | controller | changed: "logs" 2025-10-13 14:53:33.894188 | controller | changed: All items complete 2025-10-13 14:53:33.894215 | 2025-10-13 14:53:34.121575 | controller | changed: "artifacts" 2025-10-13 14:53:34.339996 | controller | changed: "docs" 2025-10-13 14:53:34.386674 | 2025-10-13 14:53:34.386806 | TASK [Check if worker can sudo] 2025-10-13 14:53:34.967158 | controller | ok: Runtime: 0:00:00.060813 2025-10-13 14:53:34.973391 | 2025-10-13 14:53:34.973456 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 14:53:35.078730 | controller | skipping: Conditional result was False 2025-10-13 14:53:35.085158 | 2025-10-13 14:53:35.085236 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 14:53:35.189234 | controller | ok 2025-10-13 14:53:35.205019 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 14:53:35.275605 | 2025-10-13 14:53:35.275742 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 14:53:35.600315 | controller | ok 2025-10-13 14:53:35.629446 | 2025-10-13 14:53:35.629575 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 14:53:35.733029 | controller | ok: "/var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 14:53:35.790713 | 2025-10-13 14:53:35.790841 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 14:53:37.055758 | controller | changed 2025-10-13 14:53:37.065903 | 2025-10-13 14:53:37.066009 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 14:53:37.158071 | controller | ok: "/var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 14:53:37.158268 | controller | ok: All items complete 2025-10-13 14:53:37.158302 | 2025-10-13 14:53:37.250935 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 14:53:37.264840 | 2025-10-13 14:53:37.265116 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 14:53:38.262249 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 14:53:39.110383 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 14:53:39.128712 | 2025-10-13 14:53:39.128860 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 14:53:39.690179 | controller | changed: section and option added 2025-10-13 14:53:39.730803 | 2025-10-13 14:53:39.730940 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 14:53:40.525736 | controller | 29 files removed 2025-10-13 14:53:40.526611 | controller | ok: Item: dnf clean all Runtime: 0:00:00.470536 2025-10-13 14:53:40.526959 | controller | changed: All items complete 2025-10-13 14:53:40.527114 | 2025-10-13 14:53:51.819899 | 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:53:51.820020 | controller | DNF version: 4.14.0 2025-10-13 14:53:51.820055 | controller | cachedir: /var/cache/dnf 2025-10-13 14:53:51.820083 | controller | Making cache files for all metadata files. 2025-10-13 14:53:51.820109 | controller | baseos: has expired and will be refreshed. 2025-10-13 14:53:51.820134 | controller | appstream: has expired and will be refreshed. 2025-10-13 14:53:51.820158 | controller | crb: has expired and will be refreshed. 2025-10-13 14:53:51.820194 | controller | extras-common: has expired and will be refreshed. 2025-10-13 14:53:51.820218 | controller | repo: downloading from remote: baseos 2025-10-13 14:53:51.820242 | controller | CentOS Stream 9 - BaseOS 36 MB/s | 8.8 MB 00:00 2025-10-13 14:53:51.820266 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 14:53:51.820290 | controller | repo: downloading from remote: appstream 2025-10-13 14:53:51.820313 | controller | CentOS Stream 9 - AppStream 81 MB/s | 25 MB 00:00 2025-10-13 14:53:51.820336 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 14:53:51.820359 | controller | repo: downloading from remote: crb 2025-10-13 14:53:51.820382 | controller | CentOS Stream 9 - CRB 19 MB/s | 7.2 MB 00:00 2025-10-13 14:53:51.820405 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 14:53:51.820428 | controller | repo: downloading from remote: extras-common 2025-10-13 14:53:51.820452 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-10-13 14:53:51.820475 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 14:53:51.820498 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 14:53:51.820521 | controller | Completion plugin: Generating completion cache... 2025-10-13 14:53:51.820544 | controller | Metadata cache created. 2025-10-13 14:53:51.820580 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.004643 2025-10-13 14:53:51.856608 | 2025-10-13 14:53:51.856767 | PLAY RECAP 2025-10-13 14:53:51.856828 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 14:53:51.856864 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:53:51.856888 | 2025-10-13 14:53:51.992171 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:53:51.993856 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:53:52.602242 | 2025-10-13 14:53:52.602357 | PLAY [all] 2025-10-13 14:53:52.629167 | 2025-10-13 14:53:52.629284 | TASK [Install binary dependencies] 2025-10-13 14:53:52.681364 | controller | ok 2025-10-13 14:53:52.708973 | 2025-10-13 14:53:52.709131 | TASK [bindep : Include find tasks] 2025-10-13 14:53:52.738539 | controller | ok 2025-10-13 14:53:52.746305 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 14:53:52.752284 | 2025-10-13 14:53:52.752348 | TASK [bindep : Look for bindep.txt] 2025-10-13 14:53:53.158831 | controller | ok 2025-10-13 14:53:53.168921 | 2025-10-13 14:53:53.169059 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:53:53.211152 | controller | ok 2025-10-13 14:53:53.216494 | 2025-10-13 14:53:53.216569 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 14:53:53.241152 | controller | skipping: Conditional result was False 2025-10-13 14:53:53.247077 | 2025-10-13 14:53:53.247158 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:53:53.271810 | controller | skipping: Conditional result was False 2025-10-13 14:53:53.277931 | 2025-10-13 14:53:53.278007 | TASK [bindep : Look for bindep fallback file] 2025-10-13 14:53:53.302641 | controller | skipping: Conditional result was False 2025-10-13 14:53:53.309071 | 2025-10-13 14:53:53.309177 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:53:53.334101 | controller | skipping: Conditional result was False 2025-10-13 14:53:53.340217 | 2025-10-13 14:53:53.340289 | TASK [bindep : Include bindep tasks] 2025-10-13 14:53:53.381102 | controller | ok 2025-10-13 14:53:53.387745 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 14:53:53.395420 | 2025-10-13 14:53:53.395481 | TASK [bindep : Look for bindep command] 2025-10-13 14:53:53.419710 | controller | skipping: Conditional result was False 2025-10-13 14:53:53.428914 | 2025-10-13 14:53:53.429010 | TASK [bindep : Check for system bindep] 2025-10-13 14:53:53.984297 | controller | ok: Runtime: 0:00:00.005397 2025-10-13 14:53:53.996603 | 2025-10-13 14:53:53.996774 | TASK [bindep : Define bindep_command fact] 2025-10-13 14:53:54.023894 | controller | skipping: Conditional result was False 2025-10-13 14:53:54.036363 | 2025-10-13 14:53:54.036512 | TASK [bindep : Include install tasks] 2025-10-13 14:53:54.075758 | controller | ok 2025-10-13 14:53:54.093245 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 14:53:54.111948 | 2025-10-13 14:53:54.112106 | TASK [bindep : Create temp dir for bindep] 2025-10-13 14:53:54.495431 | controller | changed 2025-10-13 14:53:54.508815 | 2025-10-13 14:53:54.508969 | TASK [Ensure we have pip dependencies] 2025-10-13 14:53:54.539449 | controller | ok 2025-10-13 14:53:54.565078 | 2025-10-13 14:53:54.565159 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 10:53:54.827798 | controller | /usr/bin/pip3 2025-10-13 10:53:54.854699 | controller | /usr/bin/python3: No module named wheel 2025-10-13 14:53:55.096041 | controller | ok: Runtime: 0:00:00.039388 2025-10-13 14:53:55.102087 | 2025-10-13 14:53:55.102149 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 14:53:55.129230 | controller | ok: "/var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 14:53:55.146953 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 14:53:55.158550 | 2025-10-13 14:53:55.158616 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 14:53:57.525792 | controller | changed 2025-10-13 14:53:57.535007 | 2025-10-13 14:53:57.535138 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 14:53:57.601330 | controller | skipping: Conditional result was False 2025-10-13 14:53:57.610990 | 2025-10-13 14:53:57.611116 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 14:53:57.670840 | controller | skipping: Conditional result was False 2025-10-13 14:53:57.681322 | 2025-10-13 14:53:57.681460 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 14:53:57.728017 | controller | skipping: Conditional result was False 2025-10-13 14:53:57.738823 | 2025-10-13 14:53:57.739001 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 14:53:57.764701 | controller | skipping: Conditional result was False 2025-10-13 14:53:57.772288 | 2025-10-13 14:53:57.772377 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 14:53:58.304592 | controller | skipping: Conditional result was False 2025-10-13 14:53:58.321899 | 2025-10-13 14:53:58.322102 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 14:53:58.361471 | controller | skipping: Conditional result was False 2025-10-13 14:53:58.384550 | 2025-10-13 14:53:58.384767 | TASK [ensure-pip : Install pip from source] 2025-10-13 14:53:58.410894 | controller | skipping: Conditional result was False 2025-10-13 14:53:58.419458 | 2025-10-13 14:53:58.419580 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 10:53:58.716015 | controller | /usr/bin/python3 2025-10-13 14:53:58.980936 | controller | ok: Runtime: 0:00:00.007530 2025-10-13 14:53:58.989439 | 2025-10-13 14:53:58.989559 | TASK [ensure-pip : Set host default] 2025-10-13 14:53:59.039522 | controller | ok 2025-10-13 14:53:59.053679 | 2025-10-13 14:53:59.053959 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 14:53:59.118844 | controller | ok 2025-10-13 14:53:59.134019 | 2025-10-13 14:53:59.134149 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 14:54:03.320418 | controller | changed 2025-10-13 14:54:03.328585 | 2025-10-13 14:54:03.328705 | TASK [bindep : Define bindep_command] 2025-10-13 14:54:03.361587 | controller | ok 2025-10-13 14:54:03.368859 | 2025-10-13 14:54:03.368960 | LOOP [bindep : Include package tasks] 2025-10-13 14:54:03.451268 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 14:54:03.451510 | controller | ok: All items complete 2025-10-13 14:54:03.451539 | 2025-10-13 14:54:03.469471 | controller | included: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 14:54:03.488275 | 2025-10-13 14:54:03.488377 | TASK [bindep : Define bindep_run fact] 2025-10-13 14:54:03.533781 | controller | ok 2025-10-13 14:54:03.542148 | 2025-10-13 14:54:03.542235 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 10:54:04.833239 | controller | podman 2025-10-13 10:54:04.868638 | controller | python3-jmespath 2025-10-13 10:54:04.868702 | controller | python3-libvirt 2025-10-13 10:54:04.868718 | controller | python3-lxml 2025-10-13 10:54:04.868735 | controller | python3-netaddr 2025-10-13 14:54:05.080529 | controller | ok: Runtime: 0:00:01.042349 2025-10-13 14:54:05.086202 | 2025-10-13 14:54:05.086265 | TASK [bindep : Install distro packages from bindep] 2025-10-13 14:55:08.682249 | controller | changed 2025-10-13 14:55:08.688485 | 2025-10-13 14:55:08.688571 | TASK [bindep : Check that packages are installed] 2025-10-13 14:55:10.263983 | controller | ok: Runtime: 0:00:01.058409 2025-10-13 14:55:10.283500 | 2025-10-13 14:55:10.283864 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 14:55:10.325533 | controller | skipping: Conditional result was False 2025-10-13 14:55:10.348413 | 2025-10-13 14:55:10.351098 | TASK [Run test-setup role] 2025-10-13 14:55:10.375714 | controller | ok 2025-10-13 14:55:10.393091 | 2025-10-13 14:55:10.393190 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 14:55:10.660084 | controller | ok 2025-10-13 14:55:10.676187 | 2025-10-13 14:55:10.676437 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 14:55:11.221081 | controller | skipping: Conditional result was False 2025-10-13 14:55:11.266024 | 2025-10-13 14:55:11.266313 | TASK [bindep : Remove bindep temp dir] 2025-10-13 14:55:11.643742 | controller | ok 2025-10-13 14:55:11.665512 | 2025-10-13 14:55:11.665731 | PLAY RECAP 2025-10-13 14:55:11.665829 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 14:55:11.665894 | 2025-10-13 14:55:11.792291 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:55:11.793578 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:55:12.385732 | 2025-10-13 14:55:12.385855 | PLAY [all] 2025-10-13 14:55:12.404913 | 2025-10-13 14:55:12.405001 | TASK [Abort when test_command variable is undefined] 2025-10-13 14:55:12.429026 | controller | skipping: Conditional result was False 2025-10-13 14:55:12.434664 | 2025-10-13 14:55:12.434756 | TASK [Convert test_command to list] 2025-10-13 14:55:12.479086 | controller | skipping: Conditional result was False 2025-10-13 14:55:12.487704 | 2025-10-13 14:55:12.487793 | TASK [Use test_command list] 2025-10-13 14:55:12.539578 | controller | ok 2025-10-13 14:55:12.547506 | 2025-10-13 14:55:12.547601 | LOOP [Run test_command] 2025-10-13 14:55:12.997998 | controller | no check to run 2025-10-13 14:55:12.998198 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008718 2025-10-13 14:55:13.032053 | 2025-10-13 14:55:13.032208 | PLAY RECAP 2025-10-13 14:55:13.032273 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:55:13.032299 | 2025-10-13 14:55:13.158827 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:55:13.159807 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:55:13.743674 | 2025-10-13 14:55:13.743812 | PLAY [all] 2025-10-13 14:55:13.764777 | 2025-10-13 14:55:13.764900 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 14:55:14.161155 | controller | changed: non-zero return code 2025-10-13 14:55:14.168416 | 2025-10-13 14:55:14.168573 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 14:55:14.183136 | controller | skipping: Conditional result was False 2025-10-13 14:55:14.190284 | 2025-10-13 14:55:14.190351 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 14:55:14.220981 | 2025-10-13 14:55:14.221138 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 14:55:14.241776 | 2025-10-13 14:55:14.241948 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 14:55:14.256448 | controller | skipping: Conditional result was False 2025-10-13 14:55:14.263697 | 2025-10-13 14:55:14.263790 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 14:55:14.285055 | 2025-10-13 14:55:14.285196 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 14:55:14.301273 | controller | skipping: Conditional result was False 2025-10-13 14:55:14.307933 | 2025-10-13 14:55:14.308043 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 14:55:14.331650 | controller | skipping: Conditional result was False 2025-10-13 14:55:14.340299 | 2025-10-13 14:55:14.342857 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 14:55:14.357933 | controller | skipping: Conditional result was False 2025-10-13 14:55:14.383147 | 2025-10-13 14:55:14.383226 | PLAY RECAP 2025-10-13 14:55:14.383265 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 14:55:14.383286 | 2025-10-13 14:55:14.496338 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:55:14.497268 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:55:15.197791 | 2025-10-13 14:55:15.197914 | PLAY [all] 2025-10-13 14:55:15.230345 | 2025-10-13 14:55:15.230742 | TASK [include_role : fetch-output] 2025-10-13 14:55:15.270043 | controller | ok 2025-10-13 14:55:15.290618 | 2025-10-13 14:55:15.290786 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 14:55:15.356276 | controller | skipping: Conditional result was False 2025-10-13 14:55:15.362188 | 2025-10-13 14:55:15.362258 | TASK [fetch-output : Set log path for single node] 2025-10-13 14:55:15.401477 | controller | ok 2025-10-13 14:55:15.407652 | 2025-10-13 14:55:15.407784 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 14:55:15.900964 | controller -> localhost | ok: "/var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/logs" 2025-10-13 14:55:16.155861 | controller -> localhost | changed: "/var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/artifacts" 2025-10-13 14:55:16.378978 | controller -> localhost | changed: "/var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/docs" 2025-10-13 14:55:16.396226 | 2025-10-13 14:55:16.396375 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 14:55:17.096271 | controller | changed: .d..t...... ./ 2025-10-13 14:55:17.096467 | controller | changed: All items complete 2025-10-13 14:55:17.096496 | 2025-10-13 14:55:17.660011 | controller | changed: .d..t...... ./ 2025-10-13 14:55:18.241958 | controller | changed: .d..t...... ./ 2025-10-13 14:55:18.265823 | 2025-10-13 14:55:18.265955 | TASK [include_role : fetch-output-openshift] 2025-10-13 14:55:18.290356 | controller | skipping: Conditional result was False 2025-10-13 14:55:18.296989 | 2025-10-13 14:55:18.297067 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 14:55:18.790469 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013314 2025-10-13 14:55:19.049041 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.024579 2025-10-13 14:55:19.089521 | 2025-10-13 14:55:19.089608 | PLAY [all] 2025-10-13 14:55:19.105489 | 2025-10-13 14:55:19.105605 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 14:55:19.604865 | controller | changed 2025-10-13 14:55:19.647449 | 2025-10-13 14:55:19.647528 | PLAY RECAP 2025-10-13 14:55:19.647602 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:55:19.647632 | 2025-10-13 14:55:19.756675 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:55:19.757543 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 14:55:20.473490 | 2025-10-13 14:55:20.473625 | PLAY [localhost] 2025-10-13 14:55:20.493380 | 2025-10-13 14:55:20.493489 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 14:55:20.922200 | localhost | changed 2025-10-13 14:55:20.927269 | 2025-10-13 14:55:20.927376 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 14:55:20.960095 | localhost | ok 2025-10-13 14:55:20.969378 | 2025-10-13 14:55:20.969503 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 14:55:21.357117 | localhost | changed 2025-10-13 14:55:21.363619 | 2025-10-13 14:55:21.363746 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 14:55:22.100552 | localhost | changed 2025-10-13 14:55:22.105705 | 2025-10-13 14:55:22.105772 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 14:55:22.568119 | localhost | Identity added: /var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/tmp/ansible.x1mpmbgx (/var/lib/zuul/builds/3c87909c2c7747f8a1d73a8905fb162c/work/tmp/ansible.x1mpmbgx) 2025-10-13 14:55:22.568322 | localhost | ok: Runtime: 0:00:00.007080 2025-10-13 14:55:22.572844 | 2025-10-13 14:55:22.572906 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 14:55:22.843488 | localhost | ok: Runtime: 0:00:00.011825 2025-10-13 14:55:22.850536 | 2025-10-13 14:55:22.850655 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 14:55:22.910851 | localhost | changed 2025-10-13 14:55:22.915516 | 2025-10-13 14:55:22.915579 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 14:55:23.408476 | localhost | changed 2025-10-13 14:55:23.431797 | 2025-10-13 14:55:23.431891 | PLAY [localhost] 2025-10-13 14:55:23.444940 | 2025-10-13 14:55:23.445011 | TASK [Generate bulk log download script] 2025-10-13 14:55:23.464565 | localhost | ok 2025-10-13 14:55:23.479401 | 2025-10-13 14:55:23.479485 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 14:55:23.509016 | localhost | ok: All assertions passed 2025-10-13 14:55:23.515060 | 2025-10-13 14:55:23.515130 | TASK [local-log-download : Create download script] 2025-10-13 14:55:23.941095 | localhost -> localhost | changed 2025-10-13 14:55:23.974942 | 2025-10-13 14:55:23.975117 | TASK [Register quick-download link] 2025-10-13 14:55:24.007952 | localhost | ok 2025-10-13 14:55:24.069082 | 2025-10-13 14:55:24.069194 | PLAY [logserver.rdoproject.org] 2025-10-13 14:55:24.084344 | 2025-10-13 14:55:24.084419 | TASK [Set zuul-log-path fact] 2025-10-13 14:55:24.102048 | logserver.rdoproject.org | ok 2025-10-13 14:55:24.113139 | 2025-10-13 14:55:24.113212 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:55:24.141098 | logserver.rdoproject.org | ok 2025-10-13 14:55:24.147980 | 2025-10-13 14:55:24.148086 | TASK [upload-logs : Create log directories] 2025-10-13 14:55:24.871070 | logserver.rdoproject.org | changed 2025-10-13 14:55:24.874333 | 2025-10-13 14:55:24.874397 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 14:55:25.152885 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.023368 2025-10-13 14:55:25.158898 | 2025-10-13 14:55:25.159004 | TASK [upload-logs : Upload logs to log server] 2025-10-13 14:55:26.070639 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 14:55:26.075053 | 2025-10-13 14:55:26.075191 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 14:55:26.155853 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:55:26.156603 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:55:26.170850 | 2025-10-13 14:55:26.170981 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 14:55:26.251249 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:55:26.251508 | 2025-10-13 14:55:26.252110 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:55:26.264395 | 2025-10-13 14:55:26.264528 | LOOP [upload-logs : Upload console log and json output]