2025-10-01 10:25:41.305811 | Job console starting... 2025-10-01 10:25:41.317022 | Updating repositories 2025-10-01 10:25:41.340330 | Preparing job workspace 2025-10-01 10:25:44.750179 | Running Ansible setup... 2025-10-01 10:25:48.690388 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-01 10:25:49.293730 | 2025-10-01 10:25:49.293847 | PLAY [localhost] 2025-10-01 10:25:49.302574 | 2025-10-01 10:25:49.302657 | TASK [Gathering Facts] 2025-10-01 10:25:50.347571 | localhost | ok 2025-10-01 10:25:50.364447 | 2025-10-01 10:25:50.364597 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-01 10:25:50.755475 | localhost -> localhost | changed 2025-10-01 10:25:50.760974 | 2025-10-01 10:25:50.761051 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-01 10:25:51.548959 | localhost -> localhost | changed 2025-10-01 10:25:51.557967 | 2025-10-01 10:25:51.558035 | TASK [Setup log path fact] 2025-10-01 10:25:51.580033 | localhost | ok 2025-10-01 10:25:51.604027 | 2025-10-01 10:25:51.604160 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-01 10:25:51.633647 | localhost | ok 2025-10-01 10:25:51.644633 | 2025-10-01 10:25:51.644774 | TASK [emit-job-header : Print job information] 2025-10-01 10:25:51.675529 | # Job Information 2025-10-01 10:25:51.675720 | Ansible Version: 2.15.12 2025-10-01 10:25:51.675758 | Job: cifmw-molecule-polarion 2025-10-01 10:25:51.675785 | Pipeline: github-check 2025-10-01 10:25:51.675810 | Executor: ze02.softwarefactory-project.io 2025-10-01 10:25:51.675834 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-01 10:25:51.675860 | Log URL (when completed): https://logserver.rdoproject.org/566/rdoproject.org/5660be260e074645ae9ae90dd49f263f/ 2025-10-01 10:25:51.675884 | Event ID: ca1127c0-9eb0-11f0-9508-c017e27814eb 2025-10-01 10:25:51.682302 | 2025-10-01 10:25:51.682409 | LOOP [emit-job-header : Print node information] 2025-10-01 10:25:51.788951 | localhost | ok: 2025-10-01 10:25:51.789251 | localhost | # Node Information 2025-10-01 10:25:51.789312 | localhost | Inventory Hostname: controller 2025-10-01 10:25:51.789362 | localhost | Hostname: np0005464228 2025-10-01 10:25:51.789405 | localhost | Username: zuul 2025-10-01 10:25:51.789451 | localhost | Distro: CentOS 9 2025-10-01 10:25:51.789494 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-01 10:25:51.789532 | localhost | Region: RegionOne 2025-10-01 10:25:51.789569 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-01 10:25:51.789606 | localhost | Product Name: OpenStack Nova 2025-10-01 10:25:51.789650 | localhost | Interface IP: 38.102.83.195 2025-10-01 10:25:51.834246 | 2025-10-01 10:25:51.834378 | PLAY [all] 2025-10-01 10:25:51.843180 | 2025-10-01 10:25:51.843266 | TASK [Gather network facts] 2025-10-01 10:25:52.362019 | controller | ok 2025-10-01 10:25:52.396321 | 2025-10-01 10:25:52.396590 | TASK [include_role : start-zuul-console] 2025-10-01 10:25:52.428874 | controller | ok 2025-10-01 10:25:52.447117 | 2025-10-01 10:25:52.447264 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-01 10:25:52.884190 | controller | ok 2025-10-01 10:25:52.905611 | 2025-10-01 10:25:52.905797 | TASK [include_role : add-build-sshkey] 2025-10-01 10:25:52.940495 | controller | ok 2025-10-01 10:25:52.954348 | 2025-10-01 10:25:52.954463 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-01 10:25:53.171396 | controller -> localhost | ok 2025-10-01 10:25:53.177132 | 2025-10-01 10:25:53.177196 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-01 10:25:53.206170 | controller | ok 2025-10-01 10:25:53.223551 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-01 10:25:53.230479 | 2025-10-01 10:25:53.230541 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-01 10:25:53.783689 | controller -> localhost | Generating public/private rsa key pair. 2025-10-01 10:25:53.783915 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/5660be260e074645ae9ae90dd49f263f_id_rsa. 2025-10-01 10:25:53.783958 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/5660be260e074645ae9ae90dd49f263f_id_rsa.pub. 2025-10-01 10:25:53.783989 | controller -> localhost | The key fingerprint is: 2025-10-01 10:25:53.784016 | controller -> localhost | SHA256:iK8NP4JtIkwK6gyyQ6cKTfxNsj/edihl61W24HNehWo zuul-build-sshkey 2025-10-01 10:25:53.784046 | controller -> localhost | The key's randomart image is: 2025-10-01 10:25:53.784073 | controller -> localhost | +---[RSA 3072]----+ 2025-10-01 10:25:53.784099 | controller -> localhost | | | 2025-10-01 10:25:53.784126 | controller -> localhost | | | 2025-10-01 10:25:53.784151 | controller -> localhost | | | 2025-10-01 10:25:53.784177 | controller -> localhost | | . . . . | 2025-10-01 10:25:53.784202 | controller -> localhost | | o o o S . o . .| 2025-10-01 10:25:53.784228 | controller -> localhost | |.= o * o. + o . | 2025-10-01 10:25:53.784252 | controller -> localhost | |@ +o+ oo o+ E . | 2025-10-01 10:25:53.784278 | controller -> localhost | |X+o +*+.+..= . | 2025-10-01 10:25:53.784303 | controller -> localhost | |== o.o=*o. . | 2025-10-01 10:25:53.784328 | controller -> localhost | +----[SHA256]-----+ 2025-10-01 10:25:53.784387 | controller -> localhost | ok: Runtime: 0:00:00.111509 2025-10-01 10:25:53.792347 | 2025-10-01 10:25:53.792436 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-01 10:25:53.828564 | controller | ok 2025-10-01 10:25:53.842256 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-01 10:25:53.850503 | 2025-10-01 10:25:53.850564 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-01 10:25:53.895037 | controller | skipping: Conditional result was False 2025-10-01 10:25:53.900890 | 2025-10-01 10:25:53.901036 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-01 10:25:54.416754 | controller | changed 2025-10-01 10:25:54.429009 | 2025-10-01 10:25:54.429452 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-01 10:25:54.665997 | controller | ok 2025-10-01 10:25:54.675233 | 2025-10-01 10:25:54.675347 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-01 10:25:55.596032 | controller | changed 2025-10-01 10:25:55.607387 | 2025-10-01 10:25:55.607550 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-01 10:25:56.471886 | controller | changed 2025-10-01 10:25:56.476722 | 2025-10-01 10:25:56.476785 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-01 10:25:56.500564 | controller | skipping: Conditional result was False 2025-10-01 10:25:56.506098 | 2025-10-01 10:25:56.506167 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-01 10:25:56.907646 | controller -> localhost | changed 2025-10-01 10:25:56.918354 | 2025-10-01 10:25:56.918468 | TASK [add-build-sshkey : Add back temp key] 2025-10-01 10:25:57.200382 | controller -> localhost | Identity added: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/5660be260e074645ae9ae90dd49f263f_id_rsa (zuul-build-sshkey) 2025-10-01 10:25:57.200613 | controller -> localhost | ok: Runtime: 0:00:00.010800 2025-10-01 10:25:57.211530 | 2025-10-01 10:25:57.211654 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-01 10:25:57.645455 | controller | ok 2025-10-01 10:25:57.650973 | 2025-10-01 10:25:57.651035 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-01 10:25:57.676187 | controller | skipping: Conditional result was False 2025-10-01 10:25:57.685250 | 2025-10-01 10:25:57.685313 | TASK [include_role : validate-host] 2025-10-01 10:25:57.703320 | controller | ok 2025-10-01 10:25:57.721970 | 2025-10-01 10:25:57.722039 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-01 10:25:57.750158 | controller | ok 2025-10-01 10:25:57.754952 | 2025-10-01 10:25:57.755012 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-01 10:25:58.011514 | controller -> localhost | ok 2025-10-01 10:25:58.019994 | 2025-10-01 10:25:58.020081 | TASK [validate-host : Collect information about the host] 2025-10-01 10:25:58.829180 | controller | ok 2025-10-01 10:25:58.837344 | 2025-10-01 10:25:58.837404 | TASK [validate-host : Sanitize hostname] 2025-10-01 10:25:58.886636 | controller | ok 2025-10-01 10:25:58.892295 | 2025-10-01 10:25:58.892359 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-01 10:25:59.293071 | controller -> localhost | changed 2025-10-01 10:25:59.298978 | 2025-10-01 10:25:59.299047 | TASK [validate-host : Collect information about zuul worker] 2025-10-01 10:25:59.716379 | controller | ok 2025-10-01 10:25:59.725471 | 2025-10-01 10:25:59.725553 | TASK [validate-host : Write out all zuul information for each host] 2025-10-01 10:26:00.219246 | controller -> localhost | changed 2025-10-01 10:26:00.233300 | 2025-10-01 10:26:00.233423 | TASK [include_role : prepare-workspace-openshift] 2025-10-01 10:26:00.259138 | controller | skipping: Conditional result was False 2025-10-01 10:26:00.266302 | 2025-10-01 10:26:00.266423 | TASK [include_role : remove-zuul-sshkey] 2025-10-01 10:26:00.281985 | controller | skipping: Conditional result was False 2025-10-01 10:26:00.289014 | 2025-10-01 10:26:00.289124 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-01 10:26:00.551185 | controller | ok: "logs" 2025-10-01 10:26:00.551477 | controller | ok: All items complete 2025-10-01 10:26:00.551516 | 2025-10-01 10:26:00.759607 | controller | ok: "artifacts" 2025-10-01 10:26:00.970891 | controller | ok: "docs" 2025-10-01 10:26:00.980732 | 2025-10-01 10:26:00.980842 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-01 10:26:01.249958 | controller | changed: "logs" 2025-10-01 10:26:01.485756 | controller | changed: "artifacts" 2025-10-01 10:26:01.783533 | controller | changed: "docs" 2025-10-01 10:26:01.811740 | 2025-10-01 10:26:01.811835 | PLAY RECAP 2025-10-01 10:26:01.811884 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-01 10:26:01.811917 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-01 10:26:01.811936 | 2025-10-01 10:26:01.910376 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-01 10:26:01.911255 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-01 10:26:02.501330 | 2025-10-01 10:26:02.501438 | PLAY [localhost] 2025-10-01 10:26:02.517352 | 2025-10-01 10:26:02.517457 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-01 10:26:02.923778 | localhost | ok 2025-10-01 10:26:02.928982 | 2025-10-01 10:26:02.929070 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-01 10:26:03.582358 | localhost | changed 2025-10-01 10:26:03.605386 | 2025-10-01 10:26:03.605510 | PLAY [all] 2025-10-01 10:26:03.620854 | 2025-10-01 10:26:03.620927 | TASK [include_role : prepare-workspace] 2025-10-01 10:26:03.640132 | controller | ok 2025-10-01 10:26:03.654540 | 2025-10-01 10:26:03.654623 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-01 10:26:04.092650 | controller | ok 2025-10-01 10:26:04.101504 | 2025-10-01 10:26:04.101586 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-01 10:26:05.899760 | controller | Output suppressed because no_log was given 2025-10-01 10:26:05.909913 | 2025-10-01 10:26:05.909991 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-01 10:26:06.205021 | controller | changed: "logs" 2025-10-01 10:26:06.462084 | controller | changed: "artifacts" 2025-10-01 10:26:06.687065 | controller | changed: "docs" 2025-10-01 10:26:06.699891 | 2025-10-01 10:26:06.700231 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-01 10:26:06.948771 | controller | changed: "logs" 2025-10-01 10:26:06.950373 | controller | changed: All items complete 2025-10-01 10:26:06.950419 | 2025-10-01 10:26:07.170270 | controller | changed: "artifacts" 2025-10-01 10:26:07.405538 | controller | changed: "docs" 2025-10-01 10:26:07.428017 | 2025-10-01 10:26:07.428104 | TASK [Check if worker can sudo] 2025-10-01 10:26:07.957335 | controller | ok: Runtime: 0:00:00.064184 2025-10-01 10:26:07.964632 | 2025-10-01 10:26:07.964771 | TASK [configure-mirrors : Gather needed facts] 2025-10-01 10:26:08.009174 | controller | skipping: Conditional result was False 2025-10-01 10:26:08.015524 | 2025-10-01 10:26:08.015602 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-01 10:26:08.066254 | controller | ok 2025-10-01 10:26:08.074196 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-01 10:26:08.081760 | 2025-10-01 10:26:08.081838 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-01 10:26:08.413351 | controller | ok 2025-10-01 10:26:08.423495 | 2025-10-01 10:26:08.423597 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-01 10:26:08.488614 | controller | ok: "/var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-01 10:26:08.503514 | 2025-10-01 10:26:08.503701 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-01 10:26:09.376428 | controller | changed 2025-10-01 10:26:09.385618 | 2025-10-01 10:26:09.385819 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-01 10:26:09.448337 | controller | ok: "/var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-01 10:26:09.448498 | controller | ok: All items complete 2025-10-01 10:26:09.448526 | 2025-10-01 10:26:09.497534 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-01 10:26:09.505471 | 2025-10-01 10:26:09.505549 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-01 10:26:10.367204 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-01 10:26:11.311566 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-01 10:26:11.322345 | 2025-10-01 10:26:11.322450 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-01 10:26:11.799297 | controller | changed: section and option added 2025-10-01 10:26:11.818378 | 2025-10-01 10:26:11.818446 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-01 10:26:12.609852 | controller | 29 files removed 2025-10-01 10:26:12.610065 | controller | ok: Item: dnf clean all Runtime: 0:00:00.481508 2025-10-01 10:26:12.610107 | controller | changed: All items complete 2025-10-01 10:26:12.610129 | 2025-10-01 10:26:23.212341 | 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-01 10:26:23.212521 | controller | DNF version: 4.14.0 2025-10-01 10:26:23.212627 | controller | cachedir: /var/cache/dnf 2025-10-01 10:26:23.212726 | controller | Making cache files for all metadata files. 2025-10-01 10:26:23.212776 | controller | baseos: has expired and will be refreshed. 2025-10-01 10:26:23.212816 | controller | appstream: has expired and will be refreshed. 2025-10-01 10:26:23.212855 | controller | crb: has expired and will be refreshed. 2025-10-01 10:26:23.212911 | controller | extras-common: has expired and will be refreshed. 2025-10-01 10:26:23.212951 | controller | repo: downloading from remote: baseos 2025-10-01 10:26:23.212990 | controller | CentOS Stream 9 - BaseOS 75 MB/s | 8.8 MB 00:00 2025-10-01 10:26:23.213029 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-01 10:26:23.213068 | controller | repo: downloading from remote: appstream 2025-10-01 10:26:23.213107 | controller | CentOS Stream 9 - AppStream 104 MB/s | 25 MB 00:00 2025-10-01 10:26:23.213146 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-01 10:26:23.213185 | controller | repo: downloading from remote: crb 2025-10-01 10:26:23.213223 | controller | CentOS Stream 9 - CRB 55 MB/s | 7.1 MB 00:00 2025-10-01 10:26:23.213262 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-01 10:26:23.213300 | controller | repo: downloading from remote: extras-common 2025-10-01 10:26:23.213338 | controller | CentOS Stream 9 - Extras packages 186 kB/s | 20 kB 00:00 2025-10-01 10:26:23.213400 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-01 10:26:23.213440 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-01 10:26:23.213490 | controller | Completion plugin: Generating completion cache... 2025-10-01 10:26:23.213538 | controller | Metadata cache created. 2025-10-01 10:26:23.213604 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.344609 2025-10-01 10:26:23.242611 | 2025-10-01 10:26:23.242940 | PLAY RECAP 2025-10-01 10:26:23.243038 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-01 10:26:23.243097 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-01 10:26:23.243197 | 2025-10-01 10:26:23.362095 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-01 10:26:23.363150 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-01 10:26:23.946545 | 2025-10-01 10:26:23.946679 | PLAY [all] 2025-10-01 10:26:23.968523 | 2025-10-01 10:26:23.968635 | TASK [Install binary dependencies] 2025-10-01 10:26:24.028022 | controller | ok 2025-10-01 10:26:24.049026 | 2025-10-01 10:26:24.049110 | TASK [bindep : Include find tasks] 2025-10-01 10:26:24.078614 | controller | ok 2025-10-01 10:26:24.087077 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-01 10:26:24.093022 | 2025-10-01 10:26:24.093084 | TASK [bindep : Look for bindep.txt] 2025-10-01 10:26:24.520075 | controller | ok 2025-10-01 10:26:24.527455 | 2025-10-01 10:26:24.527541 | TASK [bindep : Define bindep_file fact] 2025-10-01 10:26:24.557697 | controller | ok 2025-10-01 10:26:24.562996 | 2025-10-01 10:26:24.563061 | TASK [bindep : Look for other-requirements.txt] 2025-10-01 10:26:24.577488 | controller | skipping: Conditional result was False 2025-10-01 10:26:24.584079 | 2025-10-01 10:26:24.584185 | TASK [bindep : Define bindep_file fact] 2025-10-01 10:26:24.609443 | controller | skipping: Conditional result was False 2025-10-01 10:26:24.615770 | 2025-10-01 10:26:24.615856 | TASK [bindep : Look for bindep fallback file] 2025-10-01 10:26:24.640291 | controller | skipping: Conditional result was False 2025-10-01 10:26:24.648015 | 2025-10-01 10:26:24.648162 | TASK [bindep : Define bindep_file fact] 2025-10-01 10:26:24.682650 | controller | skipping: Conditional result was False 2025-10-01 10:26:24.689784 | 2025-10-01 10:26:24.689906 | TASK [bindep : Include bindep tasks] 2025-10-01 10:26:24.721280 | controller | ok 2025-10-01 10:26:24.729495 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-01 10:26:24.738987 | 2025-10-01 10:26:24.739113 | TASK [bindep : Look for bindep command] 2025-10-01 10:26:24.763739 | controller | skipping: Conditional result was False 2025-10-01 10:26:24.771202 | 2025-10-01 10:26:24.771306 | TASK [bindep : Check for system bindep] 2025-10-01 10:26:25.302044 | controller | ok: Runtime: 0:00:00.006781 2025-10-01 10:26:25.311131 | 2025-10-01 10:26:25.311254 | TASK [bindep : Define bindep_command fact] 2025-10-01 10:26:25.337633 | controller | skipping: Conditional result was False 2025-10-01 10:26:25.347159 | 2025-10-01 10:26:25.347268 | TASK [bindep : Include install tasks] 2025-10-01 10:26:25.382385 | controller | ok 2025-10-01 10:26:25.394234 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-01 10:26:25.407523 | 2025-10-01 10:26:25.407629 | TASK [bindep : Create temp dir for bindep] 2025-10-01 10:26:25.807011 | controller | changed 2025-10-01 10:26:25.823422 | 2025-10-01 10:26:25.823537 | TASK [Ensure we have pip dependencies] 2025-10-01 10:26:25.842863 | controller | ok 2025-10-01 10:26:25.868312 | 2025-10-01 10:26:25.868404 | TASK [ensure-pip : Check if pip is installed] 2025-10-01 06:26:26.144303 | controller | /usr/bin/pip3 2025-10-01 06:26:26.195899 | controller | /usr/bin/python3: No module named wheel 2025-10-01 10:26:26.404324 | controller | ok: Runtime: 0:00:00.062172 2025-10-01 10:26:26.417878 | 2025-10-01 10:26:26.418020 | LOOP [ensure-pip : Install pip from packages] 2025-10-01 10:26:26.482964 | controller | ok: "/var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-01 10:26:26.505409 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-01 10:26:26.519462 | 2025-10-01 10:26:26.519553 | TASK [ensure-pip : Install Python 3 pip] 2025-10-01 10:26:28.964422 | controller | changed 2025-10-01 10:26:28.970558 | 2025-10-01 10:26:28.970620 | TASK [ensure-pip : Check for EPEL repository] 2025-10-01 10:26:29.033299 | controller | skipping: Conditional result was False 2025-10-01 10:26:29.046856 | 2025-10-01 10:26:29.047119 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-01 10:26:29.114344 | controller | skipping: Conditional result was False 2025-10-01 10:26:29.130947 | 2025-10-01 10:26:29.131068 | TASK [ensure-pip : Install Python 2 pip] 2025-10-01 10:26:29.188141 | controller | skipping: Conditional result was False 2025-10-01 10:26:29.194391 | 2025-10-01 10:26:29.194457 | TASK [ensure-pip : Ensure setuptools] 2025-10-01 10:26:29.208229 | controller | skipping: Conditional result was False 2025-10-01 10:26:29.214817 | 2025-10-01 10:26:29.214892 | TASK [ensure-pip : Check for ensurepip module] 2025-10-01 10:26:29.745925 | controller | skipping: Conditional result was False 2025-10-01 10:26:29.759310 | 2025-10-01 10:26:29.759436 | TASK [ensure-pip : Ensure python3-venv] 2025-10-01 10:26:29.785285 | controller | skipping: Conditional result was False 2025-10-01 10:26:29.793595 | 2025-10-01 10:26:29.793692 | TASK [ensure-pip : Install pip from source] 2025-10-01 10:26:29.817609 | controller | skipping: Conditional result was False 2025-10-01 10:26:29.824292 | 2025-10-01 10:26:29.824381 | TASK [ensure-pip : Probe for venv python full path] 2025-10-01 06:26:30.071490 | controller | /usr/bin/python3 2025-10-01 10:26:30.363587 | controller | ok: Runtime: 0:00:00.004929 2025-10-01 10:26:30.374524 | 2025-10-01 10:26:30.374616 | TASK [ensure-pip : Set host default] 2025-10-01 10:26:30.467406 | controller | ok 2025-10-01 10:26:30.473417 | 2025-10-01 10:26:30.473490 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-01 10:26:30.555590 | controller | ok 2025-10-01 10:26:30.573496 | 2025-10-01 10:26:30.574728 | TASK [bindep : Install bindep into temporary venv] 2025-10-01 10:26:35.106075 | controller | changed 2025-10-01 10:26:35.111605 | 2025-10-01 10:26:35.111686 | TASK [bindep : Define bindep_command] 2025-10-01 10:26:35.140547 | controller | ok 2025-10-01 10:26:35.145554 | 2025-10-01 10:26:35.145615 | LOOP [bindep : Include package tasks] 2025-10-01 10:26:35.198939 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-01 10:26:35.199237 | controller | ok: All items complete 2025-10-01 10:26:35.199276 | 2025-10-01 10:26:35.210048 | controller | included: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-01 10:26:35.223999 | 2025-10-01 10:26:35.224067 | TASK [bindep : Define bindep_run fact] 2025-10-01 10:26:35.252673 | controller | ok 2025-10-01 10:26:35.257651 | 2025-10-01 10:26:35.257733 | TASK [bindep : Get list of packages to install from bindep] 2025-10-01 06:26:36.492695 | controller | podman 2025-10-01 06:26:36.530760 | controller | python3-jmespath 2025-10-01 06:26:36.530939 | controller | python3-libvirt 2025-10-01 06:26:36.530958 | controller | python3-lxml 2025-10-01 06:26:36.530975 | controller | python3-netaddr 2025-10-01 10:26:36.801027 | controller | ok: Runtime: 0:00:01.014799 2025-10-01 10:26:36.810393 | 2025-10-01 10:26:36.810538 | TASK [bindep : Install distro packages from bindep] 2025-10-01 10:27:41.994778 | controller | changed 2025-10-01 10:27:42.006215 | 2025-10-01 10:27:42.006363 | TASK [bindep : Check that packages are installed] 2025-10-01 10:27:43.559112 | controller | ok: Runtime: 0:00:01.198118 2025-10-01 10:27:43.572006 | 2025-10-01 10:27:43.572544 | TASK [bindep : Fail if we cannot install all packages] 2025-10-01 10:27:43.599802 | controller | skipping: Conditional result was False 2025-10-01 10:27:43.624824 | 2025-10-01 10:27:43.624977 | TASK [Run test-setup role] 2025-10-01 10:27:43.649598 | controller | ok 2025-10-01 10:27:43.679389 | 2025-10-01 10:27:43.679540 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-01 10:27:43.909144 | controller | ok 2025-10-01 10:27:43.920647 | 2025-10-01 10:27:43.920814 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-01 10:27:44.470653 | controller | skipping: Conditional result was False 2025-10-01 10:27:44.512591 | 2025-10-01 10:27:44.512803 | TASK [bindep : Remove bindep temp dir] 2025-10-01 10:27:44.961863 | controller | ok 2025-10-01 10:27:45.013560 | 2025-10-01 10:27:45.013744 | PLAY RECAP 2025-10-01 10:27:45.013842 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-01 10:27:45.013891 | 2025-10-01 10:27:45.142229 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-01 10:27:45.144261 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-01 10:27:45.699047 | 2025-10-01 10:27:45.699161 | PLAY [all] 2025-10-01 10:27:45.718107 | 2025-10-01 10:27:45.718196 | TASK [Abort when test_command variable is undefined] 2025-10-01 10:27:45.752703 | controller | skipping: Conditional result was False 2025-10-01 10:27:45.758753 | 2025-10-01 10:27:45.758827 | TASK [Convert test_command to list] 2025-10-01 10:27:45.792695 | controller | skipping: Conditional result was False 2025-10-01 10:27:45.800890 | 2025-10-01 10:27:45.800977 | TASK [Use test_command list] 2025-10-01 10:27:45.842519 | controller | ok 2025-10-01 10:27:45.850013 | 2025-10-01 10:27:45.850094 | LOOP [Run test_command] 2025-10-01 10:27:46.216650 | controller | no check to run 2025-10-01 10:27:46.217076 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006563 2025-10-01 10:27:46.275628 | 2025-10-01 10:27:46.275802 | PLAY RECAP 2025-10-01 10:27:46.275862 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-01 10:27:46.275892 | 2025-10-01 10:27:46.390200 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-01 10:27:46.391281 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-01 10:27:46.982773 | 2025-10-01 10:27:46.982889 | PLAY [all] 2025-10-01 10:27:47.005110 | 2025-10-01 10:27:47.005206 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-01 10:27:47.390959 | controller | changed: non-zero return code 2025-10-01 10:27:47.396462 | 2025-10-01 10:27:47.396535 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-01 10:27:47.420412 | controller | skipping: Conditional result was False 2025-10-01 10:27:47.426427 | 2025-10-01 10:27:47.426500 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-01 10:27:47.463340 | 2025-10-01 10:27:47.463611 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-01 10:27:47.492390 | 2025-10-01 10:27:47.492717 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-01 10:27:47.509192 | controller | skipping: Conditional result was False 2025-10-01 10:27:47.517885 | 2025-10-01 10:27:47.517983 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-01 10:27:47.542048 | 2025-10-01 10:27:47.542247 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-01 10:27:47.567323 | controller | skipping: Conditional result was False 2025-10-01 10:27:47.575772 | 2025-10-01 10:27:47.575868 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-01 10:27:47.591146 | controller | skipping: Conditional result was False 2025-10-01 10:27:47.599479 | 2025-10-01 10:27:47.599575 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-01 10:27:47.613893 | controller | skipping: Conditional result was False 2025-10-01 10:27:47.651720 | 2025-10-01 10:27:47.651818 | PLAY RECAP 2025-10-01 10:27:47.651876 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-01 10:27:47.651905 | 2025-10-01 10:27:47.738292 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-01 10:27:47.739134 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-01 10:27:48.329865 | 2025-10-01 10:27:48.329969 | PLAY [all] 2025-10-01 10:27:48.349516 | 2025-10-01 10:27:48.349598 | TASK [include_role : fetch-output] 2025-10-01 10:27:48.398607 | controller | ok 2025-10-01 10:27:48.416932 | 2025-10-01 10:27:48.417011 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-01 10:27:48.491556 | controller | skipping: Conditional result was False 2025-10-01 10:27:48.497514 | 2025-10-01 10:27:48.497581 | TASK [fetch-output : Set log path for single node] 2025-10-01 10:27:48.536570 | controller | ok 2025-10-01 10:27:48.541579 | 2025-10-01 10:27:48.541641 | LOOP [fetch-output : Ensure local output dirs] 2025-10-01 10:27:48.984563 | controller -> localhost | ok: "/var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/logs" 2025-10-01 10:27:49.255348 | controller -> localhost | changed: "/var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/artifacts" 2025-10-01 10:27:49.468184 | controller -> localhost | changed: "/var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/docs" 2025-10-01 10:27:49.478438 | 2025-10-01 10:27:49.478552 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-01 10:27:50.254396 | controller | changed: .d..t...... ./ 2025-10-01 10:27:50.254763 | controller | changed: All items complete 2025-10-01 10:27:50.254831 | 2025-10-01 10:27:50.789628 | controller | changed: .d..t...... ./ 2025-10-01 10:27:51.330182 | controller | changed: .d..t...... ./ 2025-10-01 10:27:51.345845 | 2025-10-01 10:27:51.345973 | TASK [include_role : fetch-output-openshift] 2025-10-01 10:27:51.370687 | controller | skipping: Conditional result was False 2025-10-01 10:27:51.377315 | 2025-10-01 10:27:51.377455 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-01 10:27:51.911120 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013845 2025-10-01 10:27:52.199199 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014517 2025-10-01 10:27:52.237534 | 2025-10-01 10:27:52.237644 | PLAY [all] 2025-10-01 10:27:52.251922 | 2025-10-01 10:27:52.251988 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-01 10:27:52.713141 | controller | changed 2025-10-01 10:27:52.739739 | 2025-10-01 10:27:52.739844 | PLAY RECAP 2025-10-01 10:27:52.739894 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-01 10:27:52.739918 | 2025-10-01 10:27:52.856199 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-01 10:27:52.857926 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-01 10:27:53.482892 | 2025-10-01 10:27:53.483016 | PLAY [localhost] 2025-10-01 10:27:53.502611 | 2025-10-01 10:27:53.502749 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-01 10:27:53.898129 | localhost | changed 2025-10-01 10:27:53.905543 | 2025-10-01 10:27:53.905647 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-01 10:27:53.957150 | localhost | ok 2025-10-01 10:27:53.972898 | 2025-10-01 10:27:53.973007 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-01 10:27:54.349016 | localhost | changed 2025-10-01 10:27:54.356064 | 2025-10-01 10:27:54.356140 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-01 10:27:55.012201 | localhost | changed 2025-10-01 10:27:55.017546 | 2025-10-01 10:27:55.017612 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-01 10:27:55.475994 | localhost | Identity added: /var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/tmp/ansible.c38eoxol (/var/lib/zuul/builds/5660be260e074645ae9ae90dd49f263f/work/tmp/ansible.c38eoxol) 2025-10-01 10:27:55.476195 | localhost | ok: Runtime: 0:00:00.015163 2025-10-01 10:27:55.480849 | 2025-10-01 10:27:55.480918 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-01 10:27:55.739310 | localhost | ok: Runtime: 0:00:00.005062 2025-10-01 10:27:55.751571 | 2025-10-01 10:27:55.751782 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-01 10:27:55.808037 | localhost | changed 2025-10-01 10:27:55.814280 | 2025-10-01 10:27:55.814456 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-01 10:27:56.249456 | localhost | changed 2025-10-01 10:27:56.293719 | 2025-10-01 10:27:56.293834 | PLAY [localhost] 2025-10-01 10:27:56.312086 | 2025-10-01 10:27:56.312171 | TASK [Generate bulk log download script] 2025-10-01 10:27:56.334232 | localhost | ok 2025-10-01 10:27:56.352535 | 2025-10-01 10:27:56.352632 | TASK [local-log-download : Check API endpoint is defined] 2025-10-01 10:27:56.395768 | localhost | ok: All assertions passed 2025-10-01 10:27:56.402410 | 2025-10-01 10:27:56.402514 | TASK [local-log-download : Create download script] 2025-10-01 10:27:56.848757 | localhost -> localhost | changed 2025-10-01 10:27:56.872328 | 2025-10-01 10:27:56.872476 | TASK [Register quick-download link] 2025-10-01 10:27:56.900578 | localhost | ok 2025-10-01 10:27:56.959286 | 2025-10-01 10:27:56.959384 | PLAY [logserver.rdoproject.org] 2025-10-01 10:27:56.969704 | 2025-10-01 10:27:56.969765 | TASK [Set zuul-log-path fact] 2025-10-01 10:27:56.986423 | logserver.rdoproject.org | ok 2025-10-01 10:27:56.996941 | 2025-10-01 10:27:56.997003 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-01 10:27:57.034166 | logserver.rdoproject.org | ok 2025-10-01 10:27:57.040575 | 2025-10-01 10:27:57.040701 | TASK [upload-logs : Create log directories] 2025-10-01 10:27:57.895812 | logserver.rdoproject.org | changed 2025-10-01 10:27:57.899216 | 2025-10-01 10:27:57.899286 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-01 10:27:58.176465 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004885 2025-10-01 10:27:58.181068 | 2025-10-01 10:27:58.181131 | TASK [upload-logs : Upload logs to log server] 2025-10-01 10:27:58.854480 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-01 10:27:58.861069 | 2025-10-01 10:27:58.861195 | LOOP [upload-logs : Compress console log and json output] 2025-10-01 10:27:58.908181 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-01 10:27:58.929635 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-01 10:27:58.947646 | 2025-10-01 10:27:58.947860 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-01 10:27:59.007865 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-01 10:27:59.008270 | 2025-10-01 10:27:59.011487 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-01 10:27:59.023396 | 2025-10-01 10:27:59.023576 | LOOP [upload-logs : Upload console log and json output]