2025-10-08 14:56:56.658160 | Job console starting... 2025-10-08 14:56:56.672210 | Updating repositories 2025-10-08 14:56:56.698391 | Preparing job workspace 2025-10-08 14:57:00.204391 | Running Ansible setup... 2025-10-08 14:57:03.798710 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 14:57:04.364960 | 2025-10-08 14:57:04.365078 | PLAY [localhost] 2025-10-08 14:57:04.377183 | 2025-10-08 14:57:04.377259 | TASK [Gathering Facts] 2025-10-08 14:57:05.370008 | localhost | ok 2025-10-08 14:57:05.386813 | 2025-10-08 14:57:05.386893 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 14:57:05.736486 | localhost -> localhost | changed 2025-10-08 14:57:05.742346 | 2025-10-08 14:57:05.742418 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 14:57:06.496145 | localhost -> localhost | changed 2025-10-08 14:57:06.504574 | 2025-10-08 14:57:06.504639 | TASK [Setup log path fact] 2025-10-08 14:57:06.522303 | localhost | ok 2025-10-08 14:57:06.533525 | 2025-10-08 14:57:06.533593 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 14:57:06.551374 | localhost | ok 2025-10-08 14:57:06.566243 | 2025-10-08 14:57:06.566309 | TASK [emit-job-header : Print job information] 2025-10-08 14:57:06.604300 | # Job Information 2025-10-08 14:57:06.604535 | Ansible Version: 2.15.12 2025-10-08 14:57:06.604561 | Job: cifmw-molecule-cifmw_external_dns 2025-10-08 14:57:06.604581 | Pipeline: github-check 2025-10-08 14:57:06.604599 | Executor: ze04.softwarefactory-project.io 2025-10-08 14:57:06.604617 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368 2025-10-08 14:57:06.604636 | Log URL (when completed): https://logserver.rdoproject.org/ee6/rdoproject.org/ee61370053624d538692465cce8cefef/ 2025-10-08 14:57:06.604653 | Event ID: dc080060-a456-11f0-897c-380a1fc1fefa 2025-10-08 14:57:06.608651 | 2025-10-08 14:57:06.608750 | LOOP [emit-job-header : Print node information] 2025-10-08 14:57:06.707278 | localhost | ok: 2025-10-08 14:57:06.707509 | localhost | # Node Information 2025-10-08 14:57:06.707541 | localhost | Inventory Hostname: controller 2025-10-08 14:57:06.707564 | localhost | Hostname: np0005476882 2025-10-08 14:57:06.707583 | localhost | Username: zuul 2025-10-08 14:57:06.707603 | localhost | Distro: CentOS 9 2025-10-08 14:57:06.707621 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 14:57:06.707638 | localhost | Region: RegionOne 2025-10-08 14:57:06.707655 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 14:57:06.707671 | localhost | Product Name: OpenStack Nova 2025-10-08 14:57:06.707720 | localhost | Interface IP: 38.129.56.193 2025-10-08 14:57:06.734341 | 2025-10-08 14:57:06.734464 | PLAY [all] 2025-10-08 14:57:06.740991 | 2025-10-08 14:57:06.741051 | TASK [Gather network facts] 2025-10-08 14:57:07.216619 | controller | ok 2025-10-08 14:57:07.230808 | 2025-10-08 14:57:07.230867 | TASK [include_role : start-zuul-console] 2025-10-08 14:57:07.248630 | controller | ok 2025-10-08 14:57:07.261002 | 2025-10-08 14:57:07.261066 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 14:57:07.663374 | controller | ok 2025-10-08 14:57:07.673736 | 2025-10-08 14:57:07.673796 | TASK [include_role : add-build-sshkey] 2025-10-08 14:57:07.702752 | controller | ok 2025-10-08 14:57:07.715407 | 2025-10-08 14:57:07.715471 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 14:57:07.932995 | controller -> localhost | ok 2025-10-08 14:57:07.938790 | 2025-10-08 14:57:07.938859 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 14:57:07.987728 | controller | ok 2025-10-08 14:57:08.001311 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 14:57:08.007025 | 2025-10-08 14:57:08.007086 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 14:57:08.630402 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 14:57:08.630738 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/ee61370053624d538692465cce8cefef_id_rsa. 2025-10-08 14:57:08.630802 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/ee61370053624d538692465cce8cefef_id_rsa.pub. 2025-10-08 14:57:08.630842 | controller -> localhost | The key fingerprint is: 2025-10-08 14:57:08.630876 | controller -> localhost | SHA256:2Qm8V3afUot6sXtDsUQUFJkya2tkqZd2fHCM3bvYZ6w zuul-build-sshkey 2025-10-08 14:57:08.630909 | controller -> localhost | The key's randomart image is: 2025-10-08 14:57:08.630941 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 14:57:08.630968 | controller -> localhost | | o==| 2025-10-08 14:57:08.630994 | controller -> localhost | | . o + | 2025-10-08 14:57:08.631019 | controller -> localhost | | o o B=.| 2025-10-08 14:57:08.631044 | controller -> localhost | | = + B=+B| 2025-10-08 14:57:08.631068 | controller -> localhost | | S + =+===| 2025-10-08 14:57:08.631092 | controller -> localhost | | . ..*+*.| 2025-10-08 14:57:08.631115 | controller -> localhost | | .+o=.o| 2025-10-08 14:57:08.631141 | controller -> localhost | | ...=+| 2025-10-08 14:57:08.631165 | controller -> localhost | | .Eoo| 2025-10-08 14:57:08.631189 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 14:57:08.631245 | controller -> localhost | ok: Runtime: 0:00:00.112793 2025-10-08 14:57:08.642355 | 2025-10-08 14:57:08.642473 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 14:57:08.664156 | controller | ok 2025-10-08 14:57:08.675866 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 14:57:08.685423 | 2025-10-08 14:57:08.685491 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 14:57:08.709792 | controller | skipping: Conditional result was False 2025-10-08 14:57:08.716827 | 2025-10-08 14:57:08.716916 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 14:57:09.192196 | controller | changed 2025-10-08 14:57:09.204164 | 2025-10-08 14:57:09.204306 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 14:57:09.480816 | controller | ok 2025-10-08 14:57:09.485782 | 2025-10-08 14:57:09.485845 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 14:57:10.224008 | controller | changed 2025-10-08 14:57:10.229137 | 2025-10-08 14:57:10.229201 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 14:57:10.967292 | controller | changed 2025-10-08 14:57:10.978414 | 2025-10-08 14:57:10.978552 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 14:57:11.005924 | controller | skipping: Conditional result was False 2025-10-08 14:57:11.018292 | 2025-10-08 14:57:11.018427 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 14:57:11.466870 | controller -> localhost | changed 2025-10-08 14:57:11.488858 | 2025-10-08 14:57:11.488992 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 14:57:11.791031 | controller -> localhost | Identity added: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/ee61370053624d538692465cce8cefef_id_rsa (zuul-build-sshkey) 2025-10-08 14:57:11.791416 | controller -> localhost | ok: Runtime: 0:00:00.015785 2025-10-08 14:57:11.803901 | 2025-10-08 14:57:11.804032 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 14:57:12.188458 | controller | ok 2025-10-08 14:57:12.198800 | 2025-10-08 14:57:12.198934 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 14:57:12.236991 | controller | skipping: Conditional result was False 2025-10-08 14:57:12.266475 | 2025-10-08 14:57:12.266725 | TASK [include_role : validate-host] 2025-10-08 14:57:12.303539 | controller | ok 2025-10-08 14:57:12.337951 | 2025-10-08 14:57:12.338094 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 14:57:12.379760 | controller | ok 2025-10-08 14:57:12.386136 | 2025-10-08 14:57:12.386219 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 14:57:12.616012 | controller -> localhost | ok 2025-10-08 14:57:12.628859 | 2025-10-08 14:57:12.629008 | TASK [validate-host : Collect information about the host] 2025-10-08 14:57:13.373586 | controller | ok 2025-10-08 14:57:13.420469 | 2025-10-08 14:57:13.420605 | TASK [validate-host : Sanitize hostname] 2025-10-08 14:57:13.493089 | controller | ok 2025-10-08 14:57:13.499610 | 2025-10-08 14:57:13.499735 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 14:57:13.967966 | controller -> localhost | changed 2025-10-08 14:57:13.980245 | 2025-10-08 14:57:13.980383 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 14:57:14.398993 | controller | ok 2025-10-08 14:57:14.409882 | 2025-10-08 14:57:14.410024 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 14:57:14.979604 | controller -> localhost | changed 2025-10-08 14:57:15.002777 | 2025-10-08 14:57:15.002878 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 14:57:15.026305 | controller | skipping: Conditional result was False 2025-10-08 14:57:15.034479 | 2025-10-08 14:57:15.034580 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 14:57:15.052066 | controller | skipping: Conditional result was False 2025-10-08 14:57:15.060029 | 2025-10-08 14:57:15.060115 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 14:57:15.377514 | controller | ok: "logs" 2025-10-08 14:57:15.378022 | controller | ok: All items complete 2025-10-08 14:57:15.378086 | 2025-10-08 14:57:15.602588 | controller | ok: "artifacts" 2025-10-08 14:57:15.869661 | controller | ok: "docs" 2025-10-08 14:57:15.883789 | 2025-10-08 14:57:15.883996 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 14:57:16.239276 | controller | changed: "logs" 2025-10-08 14:57:16.527187 | controller | changed: "artifacts" 2025-10-08 14:57:16.769364 | controller | changed: "docs" 2025-10-08 14:57:16.812886 | 2025-10-08 14:57:16.813018 | PLAY RECAP 2025-10-08 14:57:16.813075 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 14:57:16.813111 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 14:57:16.813137 | 2025-10-08 14:57:16.935158 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 14:57:16.937268 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 14:57:17.562238 | 2025-10-08 14:57:17.562356 | PLAY [localhost] 2025-10-08 14:57:17.578949 | 2025-10-08 14:57:17.579026 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 14:57:17.989431 | localhost | ok 2025-10-08 14:57:17.994477 | 2025-10-08 14:57:17.994550 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 14:57:18.642891 | localhost | changed 2025-10-08 14:57:18.663394 | 2025-10-08 14:57:18.663468 | PLAY [all] 2025-10-08 14:57:18.679808 | 2025-10-08 14:57:18.679872 | TASK [include_role : prepare-workspace] 2025-10-08 14:57:18.712141 | controller | ok 2025-10-08 14:57:18.727190 | 2025-10-08 14:57:18.727259 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 14:57:19.325928 | controller | ok 2025-10-08 14:57:19.340342 | 2025-10-08 14:57:19.340472 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 14:57:23.772882 | controller | Output suppressed because no_log was given 2025-10-08 14:57:23.784136 | 2025-10-08 14:57:23.784202 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 14:57:24.443435 | controller | changed: "logs" 2025-10-08 14:57:24.880395 | controller | changed: "artifacts" 2025-10-08 14:57:25.095315 | controller | changed: "docs" 2025-10-08 14:57:25.106596 | 2025-10-08 14:57:25.106746 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 14:57:25.368959 | controller | changed: "logs" 2025-10-08 14:57:25.369194 | controller | changed: All items complete 2025-10-08 14:57:25.369222 | 2025-10-08 14:57:25.596463 | controller | changed: "artifacts" 2025-10-08 14:57:25.821448 | controller | changed: "docs" 2025-10-08 14:57:25.842277 | 2025-10-08 14:57:25.842405 | TASK [Check if worker can sudo] 2025-10-08 14:57:26.888731 | controller | ok: Runtime: 0:00:00.047954 2025-10-08 14:57:26.894348 | 2025-10-08 14:57:26.894416 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 14:57:26.969109 | controller | skipping: Conditional result was False 2025-10-08 14:57:26.981607 | 2025-10-08 14:57:26.981792 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 14:57:27.050178 | controller | ok 2025-10-08 14:57:27.067089 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 14:57:27.076480 | 2025-10-08 14:57:27.076562 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 14:57:27.410868 | controller | ok 2025-10-08 14:57:27.416635 | 2025-10-08 14:57:27.416712 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 14:57:27.487384 | controller | ok: "/var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 14:57:27.499368 | 2025-10-08 14:57:27.499493 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 14:57:28.823300 | controller | changed 2025-10-08 14:57:28.835855 | 2025-10-08 14:57:28.835993 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 14:57:28.915658 | controller | ok: "/var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 14:57:28.915967 | controller | ok: All items complete 2025-10-08 14:57:28.916004 | 2025-10-08 14:57:28.992687 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 14:57:29.000987 | 2025-10-08 14:57:29.001053 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 14:57:29.980824 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 14:57:30.874057 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 14:57:30.888502 | 2025-10-08 14:57:30.888657 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 14:57:31.334532 | controller | changed: section and option added 2025-10-08 14:57:31.354365 | 2025-10-08 14:57:31.354434 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 14:57:32.131655 | controller | 29 files removed 2025-10-08 14:57:32.132162 | controller | ok: Item: dnf clean all Runtime: 0:00:00.457322 2025-10-08 14:57:32.132247 | controller | changed: All items complete 2025-10-08 14:57:32.132293 | 2025-10-08 14:57:43.589451 | 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 14:57:43.589578 | controller | DNF version: 4.14.0 2025-10-08 14:57:43.589611 | controller | cachedir: /var/cache/dnf 2025-10-08 14:57:43.589638 | controller | Making cache files for all metadata files. 2025-10-08 14:57:43.589662 | controller | baseos: has expired and will be refreshed. 2025-10-08 14:57:43.589711 | controller | appstream: has expired and will be refreshed. 2025-10-08 14:57:43.589737 | controller | crb: has expired and will be refreshed. 2025-10-08 14:57:43.589782 | controller | extras-common: has expired and will be refreshed. 2025-10-08 14:57:43.589807 | controller | repo: downloading from remote: baseos 2025-10-08 14:57:43.589829 | controller | CentOS Stream 9 - BaseOS 57 MB/s | 8.8 MB 00:00 2025-10-08 14:57:43.589852 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 14:57:43.589873 | controller | repo: downloading from remote: appstream 2025-10-08 14:57:43.589895 | controller | CentOS Stream 9 - AppStream 72 MB/s | 25 MB 00:00 2025-10-08 14:57:43.589916 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 14:57:43.589937 | controller | repo: downloading from remote: crb 2025-10-08 14:57:43.589958 | controller | CentOS Stream 9 - CRB 73 MB/s | 7.1 MB 00:00 2025-10-08 14:57:43.589981 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 14:57:43.590003 | controller | repo: downloading from remote: extras-common 2025-10-08 14:57:43.590026 | controller | CentOS Stream 9 - Extras packages 92 kB/s | 20 kB 00:00 2025-10-08 14:57:43.590048 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 14:57:43.590070 | controller | Last metadata expiration check: 0:00:01 ago on Wed 08 Oct 2025 10:57:41 AM EDT. 2025-10-08 14:57:43.590091 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 14:57:43.590114 | controller | Completion plugin: Generating completion cache... 2025-10-08 14:57:43.590137 | controller | Metadata cache created. 2025-10-08 14:57:43.590169 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.200117 2025-10-08 14:57:43.618559 | 2025-10-08 14:57:43.618765 | PLAY RECAP 2025-10-08 14:57:43.618949 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 14:57:43.619069 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 14:57:43.619170 | 2025-10-08 14:57:43.738599 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 14:57:43.739582 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 14:57:44.341852 | 2025-10-08 14:57:44.341964 | PLAY [all] 2025-10-08 14:57:44.363036 | 2025-10-08 14:57:44.363133 | TASK [Install binary dependencies] 2025-10-08 14:57:44.414810 | controller | ok 2025-10-08 14:57:44.442373 | 2025-10-08 14:57:44.442460 | TASK [bindep : Include find tasks] 2025-10-08 14:57:44.491885 | controller | ok 2025-10-08 14:57:44.499318 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 14:57:44.505288 | 2025-10-08 14:57:44.505353 | TASK [bindep : Look for bindep.txt] 2025-10-08 14:57:44.937876 | controller | ok 2025-10-08 14:57:44.952041 | 2025-10-08 14:57:44.952190 | TASK [bindep : Define bindep_file fact] 2025-10-08 14:57:44.999441 | controller | ok 2025-10-08 14:57:45.010648 | 2025-10-08 14:57:45.010813 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 14:57:45.036393 | controller | skipping: Conditional result was False 2025-10-08 14:57:45.048292 | 2025-10-08 14:57:45.048438 | TASK [bindep : Define bindep_file fact] 2025-10-08 14:57:45.085922 | controller | skipping: Conditional result was False 2025-10-08 14:57:45.095065 | 2025-10-08 14:57:45.095155 | TASK [bindep : Look for bindep fallback file] 2025-10-08 14:57:45.120256 | controller | skipping: Conditional result was False 2025-10-08 14:57:45.128332 | 2025-10-08 14:57:45.128424 | TASK [bindep : Define bindep_file fact] 2025-10-08 14:57:45.163383 | controller | skipping: Conditional result was False 2025-10-08 14:57:45.171043 | 2025-10-08 14:57:45.171130 | TASK [bindep : Include bindep tasks] 2025-10-08 14:57:45.219188 | controller | ok 2025-10-08 14:57:45.228124 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 14:57:45.238468 | 2025-10-08 14:57:45.238550 | TASK [bindep : Look for bindep command] 2025-10-08 14:57:45.273183 | controller | skipping: Conditional result was False 2025-10-08 14:57:45.281795 | 2025-10-08 14:57:45.281883 | TASK [bindep : Check for system bindep] 2025-10-08 14:57:45.821881 | controller | ok: Runtime: 0:00:00.005655 2025-10-08 14:57:45.829927 | 2025-10-08 14:57:45.830019 | TASK [bindep : Define bindep_command fact] 2025-10-08 14:57:45.854670 | controller | skipping: Conditional result was False 2025-10-08 14:57:45.862847 | 2025-10-08 14:57:45.862933 | TASK [bindep : Include install tasks] 2025-10-08 14:57:45.905563 | controller | ok 2025-10-08 14:57:45.916666 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 14:57:45.929097 | 2025-10-08 14:57:45.929185 | TASK [bindep : Create temp dir for bindep] 2025-10-08 14:57:46.815177 | controller | changed 2025-10-08 14:57:46.829874 | 2025-10-08 14:57:46.829962 | TASK [Ensure we have pip dependencies] 2025-10-08 14:57:46.881898 | controller | ok 2025-10-08 14:57:46.921959 | 2025-10-08 14:57:46.922078 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 10:57:47.201142 | controller | /usr/bin/pip3 2025-10-08 10:57:47.223944 | controller | /usr/bin/python3: No module named wheel 2025-10-08 14:57:47.465013 | controller | ok: Runtime: 0:00:00.032906 2025-10-08 14:57:47.471957 | 2025-10-08 14:57:47.472028 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 14:57:47.522536 | controller | ok: "/var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 14:57:47.538618 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 14:57:47.549122 | 2025-10-08 14:57:47.549196 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 14:57:51.789197 | controller | changed 2025-10-08 14:57:51.801060 | 2025-10-08 14:57:51.801190 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 14:57:51.860248 | controller | skipping: Conditional result was False 2025-10-08 14:57:51.874255 | 2025-10-08 14:57:51.874396 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 14:57:51.922164 | controller | skipping: Conditional result was False 2025-10-08 14:57:51.936115 | 2025-10-08 14:57:51.936257 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 14:57:51.983929 | controller | skipping: Conditional result was False 2025-10-08 14:57:51.996523 | 2025-10-08 14:57:51.996662 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 14:57:52.013515 | controller | skipping: Conditional result was False 2025-10-08 14:57:52.026410 | 2025-10-08 14:57:52.026544 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 14:57:52.574404 | controller | skipping: Conditional result was False 2025-10-08 14:57:52.587457 | 2025-10-08 14:57:52.587593 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 14:57:52.604462 | controller | skipping: Conditional result was False 2025-10-08 14:57:52.617507 | 2025-10-08 14:57:52.617642 | TASK [ensure-pip : Install pip from source] 2025-10-08 14:57:52.634360 | controller | skipping: Conditional result was False 2025-10-08 14:57:52.647553 | 2025-10-08 14:57:52.647717 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 10:57:52.895533 | controller | /usr/bin/python3 2025-10-08 14:57:53.192347 | controller | ok: Runtime: 0:00:00.004876 2025-10-08 14:57:53.205262 | 2025-10-08 14:57:53.205403 | TASK [ensure-pip : Set host default] 2025-10-08 14:57:53.254959 | controller | ok 2025-10-08 14:57:53.266709 | 2025-10-08 14:57:53.266850 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 14:57:53.317620 | controller | ok 2025-10-08 14:57:53.339535 | 2025-10-08 14:57:53.339622 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 14:57:57.968567 | controller | changed 2025-10-08 14:57:57.980271 | 2025-10-08 14:57:57.980400 | TASK [bindep : Define bindep_command] 2025-10-08 14:57:58.012187 | controller | ok 2025-10-08 14:57:58.017719 | 2025-10-08 14:57:58.017784 | LOOP [bindep : Include package tasks] 2025-10-08 14:57:58.090162 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 14:57:58.090469 | controller | ok: All items complete 2025-10-08 14:57:58.090529 | 2025-10-08 14:57:58.105148 | controller | included: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 14:57:58.115585 | 2025-10-08 14:57:58.115647 | TASK [bindep : Define bindep_run fact] 2025-10-08 14:57:58.146218 | controller | ok 2025-10-08 14:57:58.151778 | 2025-10-08 14:57:58.151845 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 10:57:59.544121 | controller | podman 2025-10-08 10:57:59.599366 | controller | python3-jmespath 2025-10-08 10:57:59.599445 | controller | python3-libvirt 2025-10-08 10:57:59.599455 | controller | python3-lxml 2025-10-08 10:57:59.599605 | controller | python3-netaddr 2025-10-08 14:57:59.684897 | controller | ok: Runtime: 0:00:01.205225 2025-10-08 14:57:59.692033 | 2025-10-08 14:57:59.692108 | TASK [bindep : Install distro packages from bindep] 2025-10-08 14:59:06.737285 | controller | changed 2025-10-08 14:59:06.743775 | 2025-10-08 14:59:06.746579 | TASK [bindep : Check that packages are installed] 2025-10-08 14:59:08.332191 | controller | ok: Runtime: 0:00:01.225924 2025-10-08 14:59:08.337625 | 2025-10-08 14:59:08.337708 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 14:59:08.362068 | controller | skipping: Conditional result was False 2025-10-08 14:59:08.376959 | 2025-10-08 14:59:08.377044 | TASK [Run test-setup role] 2025-10-08 14:59:08.395594 | controller | ok 2025-10-08 14:59:08.411967 | 2025-10-08 14:59:08.412028 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 14:59:08.632867 | controller | ok 2025-10-08 14:59:08.645027 | 2025-10-08 14:59:08.645185 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 14:59:09.192662 | controller | skipping: Conditional result was False 2025-10-08 14:59:09.213411 | 2025-10-08 14:59:09.213501 | TASK [bindep : Remove bindep temp dir] 2025-10-08 14:59:09.554266 | controller | ok 2025-10-08 14:59:09.580524 | 2025-10-08 14:59:09.580629 | PLAY RECAP 2025-10-08 14:59:09.580670 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 14:59:09.580718 | 2025-10-08 14:59:09.782854 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 14:59:09.783724 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 14:59:10.438164 | 2025-10-08 14:59:10.438281 | PLAY [all] 2025-10-08 14:59:10.457651 | 2025-10-08 14:59:10.457750 | TASK [Abort when test_command variable is undefined] 2025-10-08 14:59:10.491922 | controller | skipping: Conditional result was False 2025-10-08 14:59:10.497345 | 2025-10-08 14:59:10.497419 | TASK [Convert test_command to list] 2025-10-08 14:59:10.531825 | controller | skipping: Conditional result was False 2025-10-08 14:59:10.539952 | 2025-10-08 14:59:10.540021 | TASK [Use test_command list] 2025-10-08 14:59:10.608446 | controller | ok 2025-10-08 14:59:10.613708 | 2025-10-08 14:59:10.613768 | LOOP [Run test_command] 2025-10-08 14:59:11.023802 | controller | no check to run 2025-10-08 14:59:11.023998 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006467 2025-10-08 14:59:11.068024 | 2025-10-08 14:59:11.068116 | PLAY RECAP 2025-10-08 14:59:11.068155 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 14:59:11.068186 | 2025-10-08 14:59:11.165093 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 14:59:11.165995 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 14:59:11.721027 | 2025-10-08 14:59:11.721145 | PLAY [all] 2025-10-08 14:59:11.748007 | 2025-10-08 14:59:11.748129 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 14:59:12.175315 | controller | changed: non-zero return code 2025-10-08 14:59:12.180870 | 2025-10-08 14:59:12.180941 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 14:59:12.215078 | controller | skipping: Conditional result was False 2025-10-08 14:59:12.221161 | 2025-10-08 14:59:12.221226 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 14:59:12.263948 | 2025-10-08 14:59:12.264197 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 14:59:12.322623 | 2025-10-08 14:59:12.322809 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 14:59:12.367092 | controller | skipping: Conditional result was False 2025-10-08 14:59:12.373152 | 2025-10-08 14:59:12.373218 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 14:59:12.426127 | 2025-10-08 14:59:12.426293 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 14:59:12.485632 | controller | skipping: Conditional result was False 2025-10-08 14:59:12.491326 | 2025-10-08 14:59:12.491393 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 14:59:12.534788 | controller | skipping: Conditional result was False 2025-10-08 14:59:12.542049 | 2025-10-08 14:59:12.542117 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 14:59:12.565655 | controller | skipping: Conditional result was False 2025-10-08 14:59:12.625624 | 2025-10-08 14:59:12.625752 | PLAY RECAP 2025-10-08 14:59:12.625797 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 14:59:12.625819 | 2025-10-08 14:59:12.783411 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 14:59:12.784219 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 14:59:16.234789 | 2025-10-08 14:59:16.234913 | PLAY [all] 2025-10-08 14:59:16.258477 | 2025-10-08 14:59:16.258567 | TASK [include_role : fetch-output] 2025-10-08 14:59:16.297729 | controller | ok 2025-10-08 14:59:16.315264 | 2025-10-08 14:59:16.315358 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 14:59:16.369890 | controller | skipping: Conditional result was False 2025-10-08 14:59:16.375941 | 2025-10-08 14:59:16.376013 | TASK [fetch-output : Set log path for single node] 2025-10-08 14:59:16.416487 | controller | ok 2025-10-08 14:59:16.422039 | 2025-10-08 14:59:16.422108 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 14:59:16.844079 | controller -> localhost | ok: "/var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/logs" 2025-10-08 14:59:17.067335 | controller -> localhost | changed: "/var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/artifacts" 2025-10-08 14:59:17.265514 | controller -> localhost | changed: "/var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/docs" 2025-10-08 14:59:17.279828 | 2025-10-08 14:59:17.280003 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 14:59:17.915275 | controller | changed: .d..t...... ./ 2025-10-08 14:59:17.915623 | controller | changed: All items complete 2025-10-08 14:59:17.915667 | 2025-10-08 14:59:18.376816 | controller | changed: .d..t...... ./ 2025-10-08 14:59:19.431244 | controller | changed: .d..t...... ./ 2025-10-08 14:59:19.458600 | 2025-10-08 14:59:19.458846 | TASK [include_role : fetch-output-openshift] 2025-10-08 14:59:19.486572 | controller | skipping: Conditional result was False 2025-10-08 14:59:19.493715 | 2025-10-08 14:59:19.493797 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 14:59:19.964064 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010572 2025-10-08 14:59:20.184400 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.010780 2025-10-08 14:59:20.233934 | 2025-10-08 14:59:20.234035 | PLAY [all] 2025-10-08 14:59:20.248200 | 2025-10-08 14:59:20.248265 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 14:59:20.675157 | controller | changed 2025-10-08 14:59:20.697115 | 2025-10-08 14:59:20.697165 | PLAY RECAP 2025-10-08 14:59:20.697205 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 14:59:20.697225 | 2025-10-08 14:59:20.791576 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 14:59:20.793354 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 14:59:21.415181 | 2025-10-08 14:59:21.415284 | PLAY [localhost] 2025-10-08 14:59:21.433129 | 2025-10-08 14:59:21.433209 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 14:59:21.789463 | localhost | changed 2025-10-08 14:59:21.794238 | 2025-10-08 14:59:21.794310 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 14:59:21.821638 | localhost | ok 2025-10-08 14:59:21.829440 | 2025-10-08 14:59:21.829505 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 14:59:22.203528 | localhost | changed 2025-10-08 14:59:22.210507 | 2025-10-08 14:59:22.210600 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 14:59:22.875549 | localhost | changed 2025-10-08 14:59:22.880595 | 2025-10-08 14:59:22.880661 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 14:59:23.284453 | localhost | Identity added: /var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/tmp/ansible.fv_1y1zh (/var/lib/zuul/builds/ee61370053624d538692465cce8cefef/work/tmp/ansible.fv_1y1zh) 2025-10-08 14:59:23.284633 | localhost | ok: Runtime: 0:00:00.008049 2025-10-08 14:59:23.288924 | 2025-10-08 14:59:23.288987 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 14:59:23.530306 | localhost | ok: Runtime: 0:00:00.008175 2025-10-08 14:59:23.535062 | 2025-10-08 14:59:23.535127 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 14:59:23.606669 | localhost | changed 2025-10-08 14:59:23.611984 | 2025-10-08 14:59:23.612072 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 14:59:24.059279 | localhost | changed 2025-10-08 14:59:24.092565 | 2025-10-08 14:59:24.092658 | PLAY [localhost] 2025-10-08 14:59:24.104976 | 2025-10-08 14:59:24.105033 | TASK [Generate bulk log download script] 2025-10-08 14:59:24.145536 | localhost | ok 2025-10-08 14:59:24.164781 | 2025-10-08 14:59:24.164879 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 14:59:24.203042 | localhost | ok: All assertions passed 2025-10-08 14:59:24.208035 | 2025-10-08 14:59:24.208094 | TASK [local-log-download : Create download script] 2025-10-08 14:59:24.601160 | localhost -> localhost | changed 2025-10-08 14:59:24.611753 | 2025-10-08 14:59:24.611855 | TASK [Register quick-download link] 2025-10-08 14:59:24.630010 | localhost | ok 2025-10-08 14:59:24.671690 | 2025-10-08 14:59:24.671807 | PLAY [logserver.rdoproject.org] 2025-10-08 14:59:24.681469 | 2025-10-08 14:59:24.681530 | TASK [Set zuul-log-path fact] 2025-10-08 14:59:24.699029 | logserver.rdoproject.org | ok 2025-10-08 14:59:24.708235 | 2025-10-08 14:59:24.708299 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 14:59:24.744886 | logserver.rdoproject.org | ok 2025-10-08 14:59:24.750109 | 2025-10-08 14:59:24.750170 | TASK [upload-logs : Create log directories] 2025-10-08 14:59:25.538541 | logserver.rdoproject.org | changed 2025-10-08 14:59:25.547167 | 2025-10-08 14:59:25.547298 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 14:59:25.852858 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.014374 2025-10-08 14:59:25.857624 | 2025-10-08 14:59:25.857694 | TASK [upload-logs : Upload logs to log server] 2025-10-08 14:59:26.546596 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 14:59:26.549574 | 2025-10-08 14:59:26.549635 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 14:59:26.600864 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 14:59:26.610240 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 14:59:26.617863 | 2025-10-08 14:59:26.617946 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 14:59:26.653248 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 14:59:26.653489 | 2025-10-08 14:59:26.657887 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 14:59:26.664991 | 2025-10-08 14:59:26.665076 | LOOP [upload-logs : Upload console log and json output]