2025-10-08 12:09:54.173860 | Job console starting... 2025-10-08 12:09:54.183268 | Updating repositories 2025-10-08 12:09:54.290914 | Preparing job workspace 2025-10-08 12:09:58.129317 | Running Ansible setup... 2025-10-08 12:10:03.035102 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 12:10:03.653572 | 2025-10-08 12:10:03.653736 | PLAY [localhost] 2025-10-08 12:10:03.666069 | 2025-10-08 12:10:03.666149 | TASK [Gathering Facts] 2025-10-08 12:10:04.728044 | localhost | ok 2025-10-08 12:10:04.742160 | 2025-10-08 12:10:04.742285 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 12:10:05.246352 | localhost -> localhost | changed 2025-10-08 12:10:05.253288 | 2025-10-08 12:10:05.253364 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 12:10:06.162257 | localhost -> localhost | changed 2025-10-08 12:10:06.174622 | 2025-10-08 12:10:06.174806 | TASK [Setup log path fact] 2025-10-08 12:10:06.194751 | localhost | ok 2025-10-08 12:10:06.206995 | 2025-10-08 12:10:06.207106 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 12:10:06.237524 | localhost | ok 2025-10-08 12:10:06.245894 | 2025-10-08 12:10:06.246001 | TASK [emit-job-header : Print job information] 2025-10-08 12:10:06.286241 | # Job Information 2025-10-08 12:10:06.286435 | Ansible Version: 2.15.12 2025-10-08 12:10:06.286461 | Job: cifmw-molecule-polarion 2025-10-08 12:10:06.286481 | Pipeline: github-check 2025-10-08 12:10:06.286499 | Executor: ze02.softwarefactory-project.io 2025-10-08 12:10:06.286517 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-08 12:10:06.286535 | Log URL (when completed): https://logserver.rdoproject.org/25b/rdoproject.org/25be145bb67642f9a910a803185fb807/ 2025-10-08 12:10:06.286554 | Event ID: 809f8c00-a43f-11f0-9dc5-9cf6e8dba5cd 2025-10-08 12:10:06.290725 | 2025-10-08 12:10:06.290795 | LOOP [emit-job-header : Print node information] 2025-10-08 12:10:06.393933 | localhost | ok: 2025-10-08 12:10:06.394209 | localhost | # Node Information 2025-10-08 12:10:06.394237 | localhost | Inventory Hostname: controller 2025-10-08 12:10:06.394259 | localhost | Hostname: np0005476069 2025-10-08 12:10:06.394278 | localhost | Username: zuul 2025-10-08 12:10:06.394298 | localhost | Distro: CentOS 9 2025-10-08 12:10:06.394316 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 12:10:06.394332 | localhost | Region: RegionOne 2025-10-08 12:10:06.394349 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 12:10:06.394442 | localhost | Product Name: OpenStack Nova 2025-10-08 12:10:06.394462 | localhost | Interface IP: 38.129.56.104 2025-10-08 12:10:06.420716 | 2025-10-08 12:10:06.420988 | PLAY [all] 2025-10-08 12:10:06.428816 | 2025-10-08 12:10:06.428922 | TASK [Gather network facts] 2025-10-08 12:10:06.940330 | controller | ok 2025-10-08 12:10:06.966888 | 2025-10-08 12:10:06.967049 | TASK [include_role : start-zuul-console] 2025-10-08 12:10:06.989040 | controller | ok 2025-10-08 12:10:07.004987 | 2025-10-08 12:10:07.005072 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 12:10:07.469647 | controller | ok 2025-10-08 12:10:07.484220 | 2025-10-08 12:10:07.484356 | TASK [include_role : add-build-sshkey] 2025-10-08 12:10:07.506533 | controller | ok 2025-10-08 12:10:07.525123 | 2025-10-08 12:10:07.525261 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 12:10:07.765514 | controller -> localhost | ok 2025-10-08 12:10:07.773259 | 2025-10-08 12:10:07.773408 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 12:10:07.806286 | controller | ok 2025-10-08 12:10:07.820038 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 12:10:07.827106 | 2025-10-08 12:10:07.827195 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 12:10:08.587206 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 12:10:08.587507 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/25be145bb67642f9a910a803185fb807_id_rsa. 2025-10-08 12:10:08.587540 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/25be145bb67642f9a910a803185fb807_id_rsa.pub. 2025-10-08 12:10:08.587562 | controller -> localhost | The key fingerprint is: 2025-10-08 12:10:08.587582 | controller -> localhost | SHA256:cvhEH7XttJOw/PCmZuLPT7I08wb8r0zdyhBQZfVizfg zuul-build-sshkey 2025-10-08 12:10:08.587601 | controller -> localhost | The key's randomart image is: 2025-10-08 12:10:08.587620 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 12:10:08.587638 | controller -> localhost | | o.o..| 2025-10-08 12:10:08.587656 | controller -> localhost | | o + +.| 2025-10-08 12:10:08.587696 | controller -> localhost | | . o o * +| 2025-10-08 12:10:08.587716 | controller -> localhost | | o . + * = | 2025-10-08 12:10:08.587735 | controller -> localhost | | o S ..= = E| 2025-10-08 12:10:08.587752 | controller -> localhost | | = o= o.| 2025-10-08 12:10:08.587769 | controller -> localhost | | . *o* o| 2025-10-08 12:10:08.587790 | controller -> localhost | | .oo#o. | 2025-10-08 12:10:08.587807 | controller -> localhost | | ..==oBo.| 2025-10-08 12:10:08.587824 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 12:10:08.587874 | controller -> localhost | ok: Runtime: 0:00:00.259787 2025-10-08 12:10:08.594232 | 2025-10-08 12:10:08.594322 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 12:10:08.634505 | controller | ok 2025-10-08 12:10:08.649450 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 12:10:08.658693 | 2025-10-08 12:10:08.658807 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 12:10:08.683396 | controller | skipping: Conditional result was False 2025-10-08 12:10:08.690576 | 2025-10-08 12:10:08.690644 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 12:10:09.216060 | controller | changed 2025-10-08 12:10:09.227268 | 2025-10-08 12:10:09.227433 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 12:10:09.518402 | controller | ok 2025-10-08 12:10:09.529856 | 2025-10-08 12:10:09.529994 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 12:10:10.377411 | controller | changed 2025-10-08 12:10:10.382815 | 2025-10-08 12:10:10.382884 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 12:10:11.273581 | controller | changed 2025-10-08 12:10:11.278698 | 2025-10-08 12:10:11.278761 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 12:10:11.330378 | controller | skipping: Conditional result was False 2025-10-08 12:10:11.339007 | 2025-10-08 12:10:11.339198 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 12:10:11.803387 | controller -> localhost | changed 2025-10-08 12:10:11.814425 | 2025-10-08 12:10:11.814495 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 12:10:12.145905 | controller -> localhost | Identity added: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/25be145bb67642f9a910a803185fb807_id_rsa (zuul-build-sshkey) 2025-10-08 12:10:12.146326 | controller -> localhost | ok: Runtime: 0:00:00.009019 2025-10-08 12:10:12.153642 | 2025-10-08 12:10:12.153733 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 12:10:12.561035 | controller | ok 2025-10-08 12:10:12.566439 | 2025-10-08 12:10:12.566508 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 12:10:12.603445 | controller | skipping: Conditional result was False 2025-10-08 12:10:12.613521 | 2025-10-08 12:10:12.613589 | TASK [include_role : validate-host] 2025-10-08 12:10:12.645355 | controller | ok 2025-10-08 12:10:12.665763 | 2025-10-08 12:10:12.665842 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 12:10:12.702337 | controller | ok 2025-10-08 12:10:12.724892 | 2025-10-08 12:10:12.725093 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 12:10:13.091768 | controller -> localhost | ok 2025-10-08 12:10:13.099228 | 2025-10-08 12:10:13.099298 | TASK [validate-host : Collect information about the host] 2025-10-08 12:10:13.901154 | controller | ok 2025-10-08 12:10:13.916632 | 2025-10-08 12:10:13.916846 | TASK [validate-host : Sanitize hostname] 2025-10-08 12:10:13.967587 | controller | ok 2025-10-08 12:10:13.973597 | 2025-10-08 12:10:13.973711 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 12:10:14.677237 | controller -> localhost | changed 2025-10-08 12:10:14.683473 | 2025-10-08 12:10:14.683544 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 12:10:15.166724 | controller | ok 2025-10-08 12:10:15.178331 | 2025-10-08 12:10:15.178484 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 12:10:15.803558 | controller -> localhost | changed 2025-10-08 12:10:15.829322 | 2025-10-08 12:10:15.829601 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 12:10:15.866631 | controller | skipping: Conditional result was False 2025-10-08 12:10:15.874422 | 2025-10-08 12:10:15.874529 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 12:10:15.921869 | controller | skipping: Conditional result was False 2025-10-08 12:10:15.930830 | 2025-10-08 12:10:15.930931 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 12:10:16.208310 | controller | ok: "logs" 2025-10-08 12:10:16.213812 | controller | ok: All items complete 2025-10-08 12:10:16.214000 | 2025-10-08 12:10:16.762291 | controller | ok: "artifacts" 2025-10-08 12:10:17.185172 | controller | ok: "docs" 2025-10-08 12:10:17.205860 | 2025-10-08 12:10:17.206039 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 12:10:17.558175 | controller | changed: "logs" 2025-10-08 12:10:17.827584 | controller | changed: "artifacts" 2025-10-08 12:10:18.068549 | controller | changed: "docs" 2025-10-08 12:10:18.111503 | 2025-10-08 12:10:18.111748 | PLAY RECAP 2025-10-08 12:10:18.111807 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 12:10:18.111833 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 12:10:18.111851 | 2025-10-08 12:10:18.271926 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 12:10:18.272907 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 12:10:18.876213 | 2025-10-08 12:10:18.876322 | PLAY [localhost] 2025-10-08 12:10:18.892588 | 2025-10-08 12:10:18.892694 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 12:10:19.322155 | localhost | ok 2025-10-08 12:10:19.328415 | 2025-10-08 12:10:19.328512 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 12:10:20.069340 | localhost | changed 2025-10-08 12:10:20.118536 | 2025-10-08 12:10:20.118724 | PLAY [all] 2025-10-08 12:10:20.141819 | 2025-10-08 12:10:20.142064 | TASK [include_role : prepare-workspace] 2025-10-08 12:10:20.181786 | controller | ok 2025-10-08 12:10:20.197734 | 2025-10-08 12:10:20.197853 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 12:10:20.594722 | controller | ok 2025-10-08 12:10:20.609540 | 2025-10-08 12:10:20.609813 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 12:10:22.656908 | controller | Output suppressed because no_log was given 2025-10-08 12:10:22.676969 | 2025-10-08 12:10:22.677066 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 12:10:22.961441 | controller | changed: "logs" 2025-10-08 12:10:23.175621 | controller | changed: "artifacts" 2025-10-08 12:10:23.422726 | controller | changed: "docs" 2025-10-08 12:10:23.441039 | 2025-10-08 12:10:23.441285 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 12:10:23.776458 | controller | changed: "logs" 2025-10-08 12:10:23.777737 | controller | changed: All items complete 2025-10-08 12:10:23.777946 | 2025-10-08 12:10:24.015491 | controller | changed: "artifacts" 2025-10-08 12:10:24.243207 | controller | changed: "docs" 2025-10-08 12:10:24.276535 | 2025-10-08 12:10:24.276780 | TASK [Check if worker can sudo] 2025-10-08 12:10:25.314211 | controller | ok: Runtime: 0:00:00.095879 2025-10-08 12:10:25.328364 | 2025-10-08 12:10:25.328525 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 12:10:25.408934 | controller | skipping: Conditional result was False 2025-10-08 12:10:25.423191 | 2025-10-08 12:10:25.423380 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 12:10:25.532706 | controller | ok 2025-10-08 12:10:25.544893 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 12:10:25.553515 | 2025-10-08 12:10:25.553603 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 12:10:25.900321 | controller | ok 2025-10-08 12:10:25.908541 | 2025-10-08 12:10:25.908645 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 12:10:26.006947 | controller | ok: "/var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 12:10:26.023501 | 2025-10-08 12:10:26.023756 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 12:10:26.993363 | controller | changed 2025-10-08 12:10:27.001300 | 2025-10-08 12:10:27.001403 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 12:10:27.107358 | controller | ok: "/var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 12:10:27.107618 | controller | ok: All items complete 2025-10-08 12:10:27.107655 | 2025-10-08 12:10:27.165801 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 12:10:27.173354 | 2025-10-08 12:10:27.173418 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 12:10:28.156925 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 12:10:29.084387 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 12:10:29.101116 | 2025-10-08 12:10:29.101288 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 12:10:29.551130 | controller | changed: section and option added 2025-10-08 12:10:29.590097 | 2025-10-08 12:10:29.590244 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 12:10:30.751772 | controller | 29 files removed 2025-10-08 12:10:30.752225 | controller | ok: Item: dnf clean all Runtime: 0:00:00.824993 2025-10-08 12:10:30.752328 | controller | changed: All items complete 2025-10-08 12:10:30.752397 | 2025-10-08 12:10:43.897394 | 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-08 12:10:43.897555 | controller | DNF version: 4.14.0 2025-10-08 12:10:43.897587 | controller | cachedir: /var/cache/dnf 2025-10-08 12:10:43.897612 | controller | Making cache files for all metadata files. 2025-10-08 12:10:43.897637 | controller | baseos: has expired and will be refreshed. 2025-10-08 12:10:43.897659 | controller | appstream: has expired and will be refreshed. 2025-10-08 12:10:43.897701 | controller | crb: has expired and will be refreshed. 2025-10-08 12:10:43.897831 | controller | extras-common: has expired and will be refreshed. 2025-10-08 12:10:43.897864 | controller | repo: downloading from remote: baseos 2025-10-08 12:10:43.897886 | controller | CentOS Stream 9 - BaseOS 17 MB/s | 8.8 MB 00:00 2025-10-08 12:10:43.897911 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 12:10:43.897937 | controller | repo: downloading from remote: appstream 2025-10-08 12:10:43.897956 | controller | CentOS Stream 9 - AppStream 13 MB/s | 25 MB 00:01 2025-10-08 12:10:43.897972 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 12:10:43.897988 | controller | repo: downloading from remote: crb 2025-10-08 12:10:43.898004 | controller | CentOS Stream 9 - CRB 61 MB/s | 7.1 MB 00:00 2025-10-08 12:10:43.898020 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 12:10:43.898036 | controller | repo: downloading from remote: extras-common 2025-10-08 12:10:43.898052 | controller | CentOS Stream 9 - Extras packages 949 kB/s | 20 kB 00:00 2025-10-08 12:10:43.898068 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 12:10:43.898083 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 12:10:43.898099 | controller | Completion plugin: Generating completion cache... 2025-10-08 12:10:43.898114 | controller | Metadata cache created. 2025-10-08 12:10:43.898141 | controller | ok: Item: dnf makecache -v Runtime: 0:00:12.891000 2025-10-08 12:10:43.948492 | 2025-10-08 12:10:43.948626 | PLAY RECAP 2025-10-08 12:10:43.948721 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 12:10:43.948761 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 12:10:43.948780 | 2025-10-08 12:10:44.059214 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 12:10:44.060140 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 12:10:44.700878 | 2025-10-08 12:10:44.701052 | PLAY [all] 2025-10-08 12:10:44.722849 | 2025-10-08 12:10:44.722988 | TASK [Install binary dependencies] 2025-10-08 12:10:44.773830 | controller | ok 2025-10-08 12:10:44.795158 | 2025-10-08 12:10:44.795306 | TASK [bindep : Include find tasks] 2025-10-08 12:10:44.828199 | controller | ok 2025-10-08 12:10:44.837616 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 12:10:44.845160 | 2025-10-08 12:10:44.845257 | TASK [bindep : Look for bindep.txt] 2025-10-08 12:10:45.269143 | controller | ok 2025-10-08 12:10:45.277441 | 2025-10-08 12:10:45.277513 | TASK [bindep : Define bindep_file fact] 2025-10-08 12:10:45.353211 | controller | ok 2025-10-08 12:10:45.360303 | 2025-10-08 12:10:45.360377 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 12:10:45.392496 | controller | skipping: Conditional result was False 2025-10-08 12:10:45.399568 | 2025-10-08 12:10:45.399643 | TASK [bindep : Define bindep_file fact] 2025-10-08 12:10:45.438913 | controller | skipping: Conditional result was False 2025-10-08 12:10:45.446274 | 2025-10-08 12:10:45.446350 | TASK [bindep : Look for bindep fallback file] 2025-10-08 12:10:45.478401 | controller | skipping: Conditional result was False 2025-10-08 12:10:45.485974 | 2025-10-08 12:10:45.486048 | TASK [bindep : Define bindep_file fact] 2025-10-08 12:10:45.511564 | controller | skipping: Conditional result was False 2025-10-08 12:10:45.519012 | 2025-10-08 12:10:45.519087 | TASK [bindep : Include bindep tasks] 2025-10-08 12:10:45.551780 | controller | ok 2025-10-08 12:10:45.563534 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 12:10:45.572410 | 2025-10-08 12:10:45.572487 | TASK [bindep : Look for bindep command] 2025-10-08 12:10:45.597743 | controller | skipping: Conditional result was False 2025-10-08 12:10:45.605050 | 2025-10-08 12:10:45.605123 | TASK [bindep : Check for system bindep] 2025-10-08 12:10:46.137234 | controller | ok: Runtime: 0:00:00.007189 2025-10-08 12:10:46.145590 | 2025-10-08 12:10:46.146105 | TASK [bindep : Define bindep_command fact] 2025-10-08 12:10:46.183619 | controller | skipping: Conditional result was False 2025-10-08 12:10:46.193276 | 2025-10-08 12:10:46.193371 | TASK [bindep : Include install tasks] 2025-10-08 12:10:46.238212 | controller | ok 2025-10-08 12:10:46.250159 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 12:10:46.263242 | 2025-10-08 12:10:46.263326 | TASK [bindep : Create temp dir for bindep] 2025-10-08 12:10:46.678111 | controller | changed 2025-10-08 12:10:46.692295 | 2025-10-08 12:10:46.692430 | TASK [Ensure we have pip dependencies] 2025-10-08 12:10:46.719638 | controller | ok 2025-10-08 12:10:46.754360 | 2025-10-08 12:10:46.754498 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 08:10:47.048197 | controller | /usr/bin/pip3 2025-10-08 08:10:47.072196 | controller | /usr/bin/python3: No module named wheel 2025-10-08 12:10:47.295767 | controller | ok: Runtime: 0:00:00.037467 2025-10-08 12:10:47.302700 | 2025-10-08 12:10:47.302786 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 12:10:47.381102 | controller | ok: "/var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 12:10:47.399792 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 12:10:47.432502 | 2025-10-08 12:10:47.432630 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 12:10:52.159002 | controller | changed 2025-10-08 12:10:52.167022 | 2025-10-08 12:10:52.167128 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 12:10:52.242904 | controller | skipping: Conditional result was False 2025-10-08 12:10:52.253863 | 2025-10-08 12:10:52.254153 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 12:10:52.304475 | controller | skipping: Conditional result was False 2025-10-08 12:10:52.321138 | 2025-10-08 12:10:52.321293 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 12:10:52.371386 | controller | skipping: Conditional result was False 2025-10-08 12:10:52.388405 | 2025-10-08 12:10:52.388578 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 12:10:52.417878 | controller | skipping: Conditional result was False 2025-10-08 12:10:52.433205 | 2025-10-08 12:10:52.433383 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 12:10:53.379585 | controller | skipping: Conditional result was False 2025-10-08 12:10:53.389328 | 2025-10-08 12:10:53.389443 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 12:10:53.425889 | controller | skipping: Conditional result was False 2025-10-08 12:10:53.434759 | 2025-10-08 12:10:53.434856 | TASK [ensure-pip : Install pip from source] 2025-10-08 12:10:53.461561 | controller | skipping: Conditional result was False 2025-10-08 12:10:53.471777 | 2025-10-08 12:10:53.471898 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 08:10:53.840829 | controller | /usr/bin/python3 2025-10-08 12:10:54.015747 | controller | ok: Runtime: 0:00:00.006171 2025-10-08 12:10:54.030006 | 2025-10-08 12:10:54.030148 | TASK [ensure-pip : Set host default] 2025-10-08 12:10:54.091589 | controller | ok 2025-10-08 12:10:54.103890 | 2025-10-08 12:10:54.104026 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 12:10:54.179751 | controller | ok 2025-10-08 12:10:54.202888 | 2025-10-08 12:10:54.202998 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 12:10:59.745298 | controller | changed 2025-10-08 12:10:59.758367 | 2025-10-08 12:10:59.758701 | TASK [bindep : Define bindep_command] 2025-10-08 12:10:59.812223 | controller | ok 2025-10-08 12:10:59.825095 | 2025-10-08 12:10:59.825234 | LOOP [bindep : Include package tasks] 2025-10-08 12:10:59.911799 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 12:10:59.912144 | controller | ok: All items complete 2025-10-08 12:10:59.912200 | 2025-10-08 12:10:59.938903 | controller | included: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 12:10:59.961471 | 2025-10-08 12:10:59.961558 | TASK [bindep : Define bindep_run fact] 2025-10-08 12:11:00.007948 | controller | ok 2025-10-08 12:11:00.019046 | 2025-10-08 12:11:00.019180 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 08:11:01.742794 | controller | podman 2025-10-08 08:11:01.779822 | controller | python3-jmespath 2025-10-08 08:11:01.780051 | controller | python3-libvirt 2025-10-08 08:11:01.780065 | controller | python3-lxml 2025-10-08 08:11:01.780072 | controller | python3-netaddr 2025-10-08 12:11:02.084895 | controller | ok: Runtime: 0:00:01.462005 2025-10-08 12:11:02.098049 | 2025-10-08 12:11:02.098215 | TASK [bindep : Install distro packages from bindep] 2025-10-08 12:12:12.947174 | controller | changed 2025-10-08 12:12:12.956719 | 2025-10-08 12:12:12.956860 | TASK [bindep : Check that packages are installed] 2025-10-08 12:12:14.490763 | controller | ok: Runtime: 0:00:01.100581 2025-10-08 12:12:14.496780 | 2025-10-08 12:12:14.496851 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 12:12:14.554904 | controller | skipping: Conditional result was False 2025-10-08 12:12:14.566608 | 2025-10-08 12:12:14.566706 | TASK [Run test-setup role] 2025-10-08 12:12:14.587388 | controller | ok 2025-10-08 12:12:14.610064 | 2025-10-08 12:12:14.610230 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 12:12:14.866413 | controller | ok 2025-10-08 12:12:14.873249 | 2025-10-08 12:12:14.873384 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 12:12:15.405377 | controller | skipping: Conditional result was False 2025-10-08 12:12:15.429829 | 2025-10-08 12:12:15.429979 | TASK [bindep : Remove bindep temp dir] 2025-10-08 12:12:15.797158 | controller | ok 2025-10-08 12:12:15.808061 | 2025-10-08 12:12:15.808109 | PLAY RECAP 2025-10-08 12:12:15.808164 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 12:12:15.808186 | 2025-10-08 12:12:15.959886 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 12:12:15.960871 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 12:12:16.621463 | 2025-10-08 12:12:16.621591 | PLAY [all] 2025-10-08 12:12:16.641847 | 2025-10-08 12:12:16.641928 | TASK [Abort when test_command variable is undefined] 2025-10-08 12:12:16.677519 | controller | skipping: Conditional result was False 2025-10-08 12:12:16.684306 | 2025-10-08 12:12:16.684392 | TASK [Convert test_command to list] 2025-10-08 12:12:16.729053 | controller | skipping: Conditional result was False 2025-10-08 12:12:16.736763 | 2025-10-08 12:12:16.736832 | TASK [Use test_command list] 2025-10-08 12:12:16.802038 | controller | ok 2025-10-08 12:12:16.807999 | 2025-10-08 12:12:16.808069 | LOOP [Run test_command] 2025-10-08 12:12:17.253254 | controller | no check to run 2025-10-08 12:12:17.253510 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005649 2025-10-08 12:12:17.284737 | 2025-10-08 12:12:17.284939 | PLAY RECAP 2025-10-08 12:12:17.284992 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 12:12:17.285013 | 2025-10-08 12:12:17.445404 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 12:12:17.447295 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 12:12:18.095051 | 2025-10-08 12:12:18.095208 | PLAY [all] 2025-10-08 12:12:18.116941 | 2025-10-08 12:12:18.117094 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 12:12:18.502705 | controller | changed: non-zero return code 2025-10-08 12:12:18.518004 | 2025-10-08 12:12:18.518199 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 12:12:18.543745 | controller | skipping: Conditional result was False 2025-10-08 12:12:18.549813 | 2025-10-08 12:12:18.549889 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 12:12:18.571699 | 2025-10-08 12:12:18.571968 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 12:12:18.596063 | 2025-10-08 12:12:18.596333 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 12:12:18.614475 | controller | skipping: Conditional result was False 2025-10-08 12:12:18.621933 | 2025-10-08 12:12:18.622028 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 12:12:18.656075 | 2025-10-08 12:12:18.656222 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 12:12:18.681727 | controller | skipping: Conditional result was False 2025-10-08 12:12:18.687267 | 2025-10-08 12:12:18.687333 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 12:12:18.701487 | controller | skipping: Conditional result was False 2025-10-08 12:12:18.707615 | 2025-10-08 12:12:18.707701 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 12:12:18.722040 | controller | skipping: Conditional result was False 2025-10-08 12:12:18.746810 | 2025-10-08 12:12:18.746875 | PLAY RECAP 2025-10-08 12:12:18.746932 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 12:12:18.746954 | 2025-10-08 12:12:18.872562 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 12:12:18.873534 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 12:12:19.480460 | 2025-10-08 12:12:19.480620 | PLAY [all] 2025-10-08 12:12:19.500865 | 2025-10-08 12:12:19.500976 | TASK [include_role : fetch-output] 2025-10-08 12:12:19.542459 | controller | ok 2025-10-08 12:12:19.563238 | 2025-10-08 12:12:19.563417 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 12:12:19.608961 | controller | skipping: Conditional result was False 2025-10-08 12:12:19.616787 | 2025-10-08 12:12:19.616879 | TASK [fetch-output : Set log path for single node] 2025-10-08 12:12:19.657017 | controller | ok 2025-10-08 12:12:19.662186 | 2025-10-08 12:12:19.662254 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 12:12:20.059736 | controller -> localhost | ok: "/var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/logs" 2025-10-08 12:12:20.347166 | controller -> localhost | changed: "/var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/artifacts" 2025-10-08 12:12:20.643642 | controller -> localhost | changed: "/var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/docs" 2025-10-08 12:12:20.660713 | 2025-10-08 12:12:20.660824 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 12:12:21.332279 | controller | changed: .d..t...... ./ 2025-10-08 12:12:21.332522 | controller | changed: All items complete 2025-10-08 12:12:21.332549 | 2025-10-08 12:12:21.798209 | controller | changed: .d..t...... ./ 2025-10-08 12:12:22.262214 | controller | changed: .d..t...... ./ 2025-10-08 12:12:22.282269 | 2025-10-08 12:12:22.282389 | TASK [include_role : fetch-output-openshift] 2025-10-08 12:12:22.307993 | controller | skipping: Conditional result was False 2025-10-08 12:12:22.314299 | 2025-10-08 12:12:22.314369 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 12:12:22.813898 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.011388 2025-10-08 12:12:23.079346 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.029850 2025-10-08 12:12:23.111548 | 2025-10-08 12:12:23.111703 | PLAY [all] 2025-10-08 12:12:23.126797 | 2025-10-08 12:12:23.126952 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 12:12:23.639810 | controller | changed 2025-10-08 12:12:23.668875 | 2025-10-08 12:12:23.668953 | PLAY RECAP 2025-10-08 12:12:23.668996 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 12:12:23.669015 | 2025-10-08 12:12:23.821170 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 12:12:23.825625 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 12:12:24.495527 | 2025-10-08 12:12:24.495738 | PLAY [localhost] 2025-10-08 12:12:24.515542 | 2025-10-08 12:12:24.515649 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 12:12:24.976730 | localhost | changed 2025-10-08 12:12:24.982004 | 2025-10-08 12:12:24.982084 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 12:12:25.024099 | localhost | ok 2025-10-08 12:12:25.032550 | 2025-10-08 12:12:25.032619 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 12:12:25.476206 | localhost | changed 2025-10-08 12:12:25.490937 | 2025-10-08 12:12:25.491134 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 12:12:26.285979 | localhost | changed 2025-10-08 12:12:26.298302 | 2025-10-08 12:12:26.298399 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 12:12:26.752975 | localhost | Identity added: /var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/tmp/ansible.knyqpj2x (/var/lib/zuul/builds/25be145bb67642f9a910a803185fb807/work/tmp/ansible.knyqpj2x) 2025-10-08 12:12:26.753431 | localhost | ok: Runtime: 0:00:00.009510 2025-10-08 12:12:26.764506 | 2025-10-08 12:12:26.764769 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 12:12:27.052540 | localhost | ok: Runtime: 0:00:00.007681 2025-10-08 12:12:27.058141 | 2025-10-08 12:12:27.058209 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 12:12:27.166247 | localhost | changed 2025-10-08 12:12:27.170796 | 2025-10-08 12:12:27.170862 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 12:12:27.654207 | localhost | changed 2025-10-08 12:12:27.689044 | 2025-10-08 12:12:27.689148 | PLAY [localhost] 2025-10-08 12:12:27.707976 | 2025-10-08 12:12:27.708072 | TASK [Generate bulk log download script] 2025-10-08 12:12:27.732892 | localhost | ok 2025-10-08 12:12:27.751470 | 2025-10-08 12:12:27.751582 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 12:12:27.802867 | localhost | ok: All assertions passed 2025-10-08 12:12:27.807769 | 2025-10-08 12:12:27.807841 | TASK [local-log-download : Create download script] 2025-10-08 12:12:28.274453 | localhost -> localhost | changed 2025-10-08 12:12:28.295713 | 2025-10-08 12:12:28.295947 | TASK [Register quick-download link] 2025-10-08 12:12:28.335932 | localhost | ok 2025-10-08 12:12:28.406030 | 2025-10-08 12:12:28.406160 | PLAY [logserver.rdoproject.org] 2025-10-08 12:12:28.417860 | 2025-10-08 12:12:28.417955 | TASK [Set zuul-log-path fact] 2025-10-08 12:12:28.436450 | logserver.rdoproject.org | ok 2025-10-08 12:12:28.447046 | 2025-10-08 12:12:28.447142 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 12:12:28.485923 | logserver.rdoproject.org | ok 2025-10-08 12:12:28.491425 | 2025-10-08 12:12:28.491500 | TASK [upload-logs : Create log directories] 2025-10-08 12:12:29.176599 | logserver.rdoproject.org | changed 2025-10-08 12:12:29.184700 | 2025-10-08 12:12:29.184839 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 12:12:29.580009 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009901 2025-10-08 12:12:29.586856 | 2025-10-08 12:12:29.586949 | TASK [upload-logs : Upload logs to log server] 2025-10-08 12:12:30.383136 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 12:12:30.387397 | 2025-10-08 12:12:30.387483 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 12:12:30.440824 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:30.451307 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:30.468255 | 2025-10-08 12:12:30.468440 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 12:12:30.551858 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:30.552181 | 2025-10-08 12:12:30.552807 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:30.560511 | 2025-10-08 12:12:30.560651 | LOOP [upload-logs : Upload console log and json output]