2025-10-02 14:12:51.547045 | Job console starting... 2025-10-02 14:12:51.559399 | Updating repositories 2025-10-02 14:12:51.598694 | Preparing job workspace 2025-10-02 14:12:55.939261 | Running Ansible setup... 2025-10-02 14:13:00.614252 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 14:13:01.200239 | 2025-10-02 14:13:01.200363 | PLAY [localhost] 2025-10-02 14:13:01.209679 | 2025-10-02 14:13:01.209783 | TASK [Gathering Facts] 2025-10-02 14:13:02.321594 | localhost | ok 2025-10-02 14:13:02.339375 | 2025-10-02 14:13:02.339523 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 14:13:02.746578 | localhost -> localhost | changed 2025-10-02 14:13:02.752532 | 2025-10-02 14:13:02.752624 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 14:13:03.809181 | localhost -> localhost | changed 2025-10-02 14:13:03.831553 | 2025-10-02 14:13:03.831800 | TASK [Setup log path fact] 2025-10-02 14:13:03.854386 | localhost | ok 2025-10-02 14:13:03.872593 | 2025-10-02 14:13:03.872693 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 14:13:03.913657 | localhost | ok 2025-10-02 14:13:03.938898 | 2025-10-02 14:13:03.939051 | TASK [emit-job-header : Print job information] 2025-10-02 14:13:04.012324 | # Job Information 2025-10-02 14:13:04.012498 | Ansible Version: 2.15.12 2025-10-02 14:13:04.012525 | Job: cifmw-molecule-cifmw_external_dns 2025-10-02 14:13:04.012546 | Pipeline: github-check 2025-10-02 14:13:04.012566 | Executor: ze03.softwarefactory-project.io 2025-10-02 14:13:04.012583 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 14:13:04.012715 | Log URL (when completed): https://logserver.rdoproject.org/820/rdoproject.org/820347adbb66458894dc914694265a35/ 2025-10-02 14:13:04.012774 | Event ID: be9565c0-9f99-11f0-9e8d-1085adf9bc04 2025-10-02 14:13:04.017929 | 2025-10-02 14:13:04.018001 | LOOP [emit-job-header : Print node information] 2025-10-02 14:13:04.171794 | localhost | ok: 2025-10-02 14:13:04.171964 | localhost | # Node Information 2025-10-02 14:13:04.171991 | localhost | Inventory Hostname: controller 2025-10-02 14:13:04.172015 | localhost | Hostname: np0005466311 2025-10-02 14:13:04.172034 | localhost | Username: zuul 2025-10-02 14:13:04.172054 | localhost | Distro: CentOS 9 2025-10-02 14:13:04.172072 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 14:13:04.172089 | localhost | Region: RegionOne 2025-10-02 14:13:04.172106 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 14:13:04.172122 | localhost | Product Name: OpenStack Nova 2025-10-02 14:13:04.172139 | localhost | Interface IP: 38.102.83.59 2025-10-02 14:13:04.230629 | 2025-10-02 14:13:04.230770 | PLAY [all] 2025-10-02 14:13:04.249531 | 2025-10-02 14:13:04.249699 | TASK [Gather network facts] 2025-10-02 14:13:04.766398 | controller | ok 2025-10-02 14:13:04.792526 | 2025-10-02 14:13:04.792815 | TASK [include_role : start-zuul-console] 2025-10-02 14:13:04.823027 | controller | ok 2025-10-02 14:13:04.841213 | 2025-10-02 14:13:04.841367 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 14:13:05.292925 | controller | ok 2025-10-02 14:13:05.313462 | 2025-10-02 14:13:05.313592 | TASK [include_role : add-build-sshkey] 2025-10-02 14:13:05.391829 | controller | ok 2025-10-02 14:13:05.430879 | 2025-10-02 14:13:05.431026 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 14:13:05.813888 | controller -> localhost | ok 2025-10-02 14:13:05.820093 | 2025-10-02 14:13:05.820201 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 14:13:05.875803 | controller | ok 2025-10-02 14:13:05.898624 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 14:13:05.905502 | 2025-10-02 14:13:05.905567 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 14:13:06.636080 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 14:13:06.636275 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/820347adbb66458894dc914694265a35_id_rsa. 2025-10-02 14:13:06.636307 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/820347adbb66458894dc914694265a35_id_rsa.pub. 2025-10-02 14:13:06.636330 | controller -> localhost | The key fingerprint is: 2025-10-02 14:13:06.636350 | controller -> localhost | SHA256:lbWMbXQAC1Oiy4qUpEOMVJ2l3DMGrktHVzxwRaIEidA zuul-build-sshkey 2025-10-02 14:13:06.636381 | controller -> localhost | The key's randomart image is: 2025-10-02 14:13:06.636401 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 14:13:06.636420 | controller -> localhost | | o+.oo=+*==++.. | 2025-10-02 14:13:06.636440 | controller -> localhost | |+ Eo+=.+*.O o | 2025-10-02 14:13:06.636459 | controller -> localhost | |.o. =.B * = | 2025-10-02 14:13:06.636478 | controller -> localhost | |.o .o.o.o. . | 2025-10-02 14:13:06.636496 | controller -> localhost | |o oo .o S | 2025-10-02 14:13:06.636514 | controller -> localhost | | o..o. | 2025-10-02 14:13:06.636533 | controller -> localhost | | ... | 2025-10-02 14:13:06.636553 | controller -> localhost | | | 2025-10-02 14:13:06.636573 | controller -> localhost | | | 2025-10-02 14:13:06.636592 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 14:13:06.636635 | controller -> localhost | ok: Runtime: 0:00:00.169721 2025-10-02 14:13:06.642519 | 2025-10-02 14:13:06.642612 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 14:13:06.661485 | controller | ok 2025-10-02 14:13:06.675395 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 14:13:06.684453 | 2025-10-02 14:13:06.684538 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 14:13:06.698321 | controller | skipping: Conditional result was False 2025-10-02 14:13:06.705135 | 2025-10-02 14:13:06.705225 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 14:13:07.165106 | controller | changed 2025-10-02 14:13:07.170148 | 2025-10-02 14:13:07.170211 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 14:13:07.447752 | controller | ok 2025-10-02 14:13:07.455634 | 2025-10-02 14:13:07.455778 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 14:13:08.321522 | controller | changed 2025-10-02 14:13:08.329537 | 2025-10-02 14:13:08.329642 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 14:13:09.288763 | controller | changed 2025-10-02 14:13:09.294300 | 2025-10-02 14:13:09.294371 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 14:13:09.319498 | controller | skipping: Conditional result was False 2025-10-02 14:13:09.326011 | 2025-10-02 14:13:09.326100 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 14:13:09.825864 | controller -> localhost | changed 2025-10-02 14:13:09.844220 | 2025-10-02 14:13:09.844359 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 14:13:10.136388 | controller -> localhost | Identity added: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/820347adbb66458894dc914694265a35_id_rsa (zuul-build-sshkey) 2025-10-02 14:13:10.136633 | controller -> localhost | ok: Runtime: 0:00:00.011255 2025-10-02 14:13:10.143416 | 2025-10-02 14:13:10.143489 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 14:13:10.580073 | controller | ok 2025-10-02 14:13:10.585717 | 2025-10-02 14:13:10.585834 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 14:13:10.631825 | controller | skipping: Conditional result was False 2025-10-02 14:13:10.651284 | 2025-10-02 14:13:10.651434 | TASK [include_role : validate-host] 2025-10-02 14:13:10.699135 | controller | ok 2025-10-02 14:13:10.750274 | 2025-10-02 14:13:10.750556 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 14:13:10.795660 | controller | ok 2025-10-02 14:13:10.801262 | 2025-10-02 14:13:10.801376 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 14:13:11.364376 | controller -> localhost | ok 2025-10-02 14:13:11.370690 | 2025-10-02 14:13:11.370873 | TASK [validate-host : Collect information about the host] 2025-10-02 14:13:12.231546 | controller | ok 2025-10-02 14:13:12.243079 | 2025-10-02 14:13:12.243241 | TASK [validate-host : Sanitize hostname] 2025-10-02 14:13:12.306946 | controller | ok 2025-10-02 14:13:12.314860 | 2025-10-02 14:13:12.316201 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 14:13:13.162489 | controller -> localhost | changed 2025-10-02 14:13:13.170136 | 2025-10-02 14:13:13.170288 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 14:13:13.717081 | controller | ok 2025-10-02 14:13:13.722267 | 2025-10-02 14:13:13.722337 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 14:13:14.665533 | controller -> localhost | changed 2025-10-02 14:13:14.675230 | 2025-10-02 14:13:14.675319 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 14:13:14.720255 | controller | skipping: Conditional result was False 2025-10-02 14:13:14.726363 | 2025-10-02 14:13:14.726468 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 14:13:14.773036 | controller | skipping: Conditional result was False 2025-10-02 14:13:14.781358 | 2025-10-02 14:13:14.781492 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 14:13:15.163874 | controller | ok: "logs" 2025-10-02 14:13:15.164158 | controller | ok: All items complete 2025-10-02 14:13:15.164190 | 2025-10-02 14:13:15.464548 | controller | ok: "artifacts" 2025-10-02 14:13:15.772339 | controller | ok: "docs" 2025-10-02 14:13:15.784550 | 2025-10-02 14:13:15.784740 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 14:13:16.155253 | controller | changed: "logs" 2025-10-02 14:13:16.431809 | controller | changed: "artifacts" 2025-10-02 14:13:16.711172 | controller | changed: "docs" 2025-10-02 14:13:16.776388 | 2025-10-02 14:13:16.776510 | PLAY RECAP 2025-10-02 14:13:16.776681 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 14:13:16.777179 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 14:13:16.777213 | 2025-10-02 14:13:17.000264 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 14:13:17.001113 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 14:13:17.991988 | 2025-10-02 14:13:17.992204 | PLAY [localhost] 2025-10-02 14:13:18.009876 | 2025-10-02 14:13:18.010287 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 14:13:18.631503 | localhost | ok 2025-10-02 14:13:18.638503 | 2025-10-02 14:13:18.638604 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 14:13:19.601914 | localhost | changed 2025-10-02 14:13:19.634041 | 2025-10-02 14:13:19.634173 | PLAY [all] 2025-10-02 14:13:19.668097 | 2025-10-02 14:13:19.668237 | TASK [include_role : prepare-workspace] 2025-10-02 14:13:19.689251 | controller | ok 2025-10-02 14:13:19.704992 | 2025-10-02 14:13:19.705112 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 14:13:20.172133 | controller | ok 2025-10-02 14:13:20.217071 | 2025-10-02 14:13:20.217227 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 14:13:21.983914 | controller | Output suppressed because no_log was given 2025-10-02 14:13:21.997817 | 2025-10-02 14:13:21.997906 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 14:13:22.273595 | controller | changed: "logs" 2025-10-02 14:13:22.492114 | controller | changed: "artifacts" 2025-10-02 14:13:22.749580 | controller | changed: "docs" 2025-10-02 14:13:22.759515 | 2025-10-02 14:13:22.759646 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 14:13:23.073534 | controller | changed: "logs" 2025-10-02 14:13:23.073823 | controller | changed: All items complete 2025-10-02 14:13:23.073853 | 2025-10-02 14:13:23.289429 | controller | changed: "artifacts" 2025-10-02 14:13:23.575038 | controller | changed: "docs" 2025-10-02 14:13:23.599844 | 2025-10-02 14:13:23.599972 | TASK [Check if worker can sudo] 2025-10-02 14:13:24.151080 | controller | ok: Runtime: 0:00:00.057061 2025-10-02 14:13:24.158352 | 2025-10-02 14:13:24.158456 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 14:13:24.211217 | controller | skipping: Conditional result was False 2025-10-02 14:13:24.222464 | 2025-10-02 14:13:24.222617 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 14:13:24.293323 | controller | ok 2025-10-02 14:13:24.301629 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 14:13:24.308272 | 2025-10-02 14:13:24.308364 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 14:13:24.668745 | controller | ok 2025-10-02 14:13:24.676487 | 2025-10-02 14:13:24.676594 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 14:13:24.812261 | controller | ok: "/var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 14:13:24.830933 | 2025-10-02 14:13:24.831049 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 14:13:26.134713 | controller | changed 2025-10-02 14:13:26.143161 | 2025-10-02 14:13:26.143308 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 14:13:26.539180 | controller | ok: "/var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 14:13:26.539595 | controller | ok: All items complete 2025-10-02 14:13:26.539630 | 2025-10-02 14:13:26.689307 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 14:13:26.698535 | 2025-10-02 14:13:26.698656 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 14:13:27.780869 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 14:13:28.713411 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 14:13:28.732037 | 2025-10-02 14:13:28.732420 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 14:13:29.285856 | controller | changed: section and option added 2025-10-02 14:13:29.314023 | 2025-10-02 14:13:29.314118 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 14:13:31.353077 | controller | 29 files removed 2025-10-02 14:13:31.353285 | controller | ok: Item: dnf clean all Runtime: 0:00:01.645004 2025-10-02 14:13:31.353326 | controller | changed: All items complete 2025-10-02 14:13:31.353348 | 2025-10-02 14:13:43.315917 | 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-02 14:13:43.316021 | controller | DNF version: 4.14.0 2025-10-02 14:13:43.316047 | controller | cachedir: /var/cache/dnf 2025-10-02 14:13:43.316067 | controller | Making cache files for all metadata files. 2025-10-02 14:13:43.316086 | controller | baseos: has expired and will be refreshed. 2025-10-02 14:13:43.316104 | controller | appstream: has expired and will be refreshed. 2025-10-02 14:13:43.316121 | controller | crb: has expired and will be refreshed. 2025-10-02 14:13:43.316148 | controller | extras-common: has expired and will be refreshed. 2025-10-02 14:13:43.316165 | controller | repo: downloading from remote: baseos 2025-10-02 14:13:43.316182 | controller | CentOS Stream 9 - BaseOS 7.0 MB/s | 8.8 MB 00:01 2025-10-02 14:13:43.316199 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 14:13:43.316216 | controller | repo: downloading from remote: appstream 2025-10-02 14:13:43.316232 | controller | CentOS Stream 9 - AppStream 86 MB/s | 25 MB 00:00 2025-10-02 14:13:43.316249 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 14:13:43.316265 | controller | repo: downloading from remote: crb 2025-10-02 14:13:43.316282 | controller | CentOS Stream 9 - CRB 82 MB/s | 7.1 MB 00:00 2025-10-02 14:13:43.316299 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 14:13:43.316315 | controller | repo: downloading from remote: extras-common 2025-10-02 14:13:43.316365 | controller | CentOS Stream 9 - Extras packages 1.7 MB/s | 20 kB 00:00 2025-10-02 14:13:43.316475 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 14:13:43.316496 | controller | Last metadata expiration check: 0:00:01 ago on Thu 02 Oct 2025 10:13:41 AM EDT. 2025-10-02 14:13:43.316513 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 14:13:43.316530 | controller | Completion plugin: Generating completion cache... 2025-10-02 14:13:43.316546 | controller | Metadata cache created. 2025-10-02 14:13:43.316573 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.642785 2025-10-02 14:13:43.404512 | 2025-10-02 14:13:43.404607 | PLAY RECAP 2025-10-02 14:13:43.404648 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 14:13:43.404674 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 14:13:43.404692 | 2025-10-02 14:13:43.716540 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 14:13:43.717781 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 14:13:44.757475 | 2025-10-02 14:13:44.757603 | PLAY [all] 2025-10-02 14:13:44.818695 | 2025-10-02 14:13:44.818869 | TASK [Install binary dependencies] 2025-10-02 14:13:44.971646 | controller | ok 2025-10-02 14:13:45.014477 | 2025-10-02 14:13:45.014607 | TASK [bindep : Include find tasks] 2025-10-02 14:13:45.083360 | controller | ok 2025-10-02 14:13:45.095219 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 14:13:45.109865 | 2025-10-02 14:13:45.109935 | TASK [bindep : Look for bindep.txt] 2025-10-02 14:13:45.781879 | controller | ok 2025-10-02 14:13:45.789003 | 2025-10-02 14:13:45.789073 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:45.838236 | controller | ok 2025-10-02 14:13:45.843340 | 2025-10-02 14:13:45.843403 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 14:13:45.867782 | controller | skipping: Conditional result was False 2025-10-02 14:13:45.874486 | 2025-10-02 14:13:45.874572 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:45.912920 | controller | skipping: Conditional result was False 2025-10-02 14:13:45.919343 | 2025-10-02 14:13:45.919411 | TASK [bindep : Look for bindep fallback file] 2025-10-02 14:13:45.975621 | controller | skipping: Conditional result was False 2025-10-02 14:13:45.982101 | 2025-10-02 14:13:45.982171 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:46.018289 | controller | skipping: Conditional result was False 2025-10-02 14:13:46.025490 | 2025-10-02 14:13:46.025588 | TASK [bindep : Include bindep tasks] 2025-10-02 14:13:46.085844 | controller | ok 2025-10-02 14:13:46.096635 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 14:13:46.119880 | 2025-10-02 14:13:46.120071 | TASK [bindep : Look for bindep command] 2025-10-02 14:13:46.224655 | controller | skipping: Conditional result was False 2025-10-02 14:13:46.231669 | 2025-10-02 14:13:46.231775 | TASK [bindep : Check for system bindep] 2025-10-02 14:13:46.826187 | controller | ok: Runtime: 0:00:00.009048 2025-10-02 14:13:46.847117 | 2025-10-02 14:13:46.847232 | TASK [bindep : Define bindep_command fact] 2025-10-02 14:13:46.910994 | controller | skipping: Conditional result was False 2025-10-02 14:13:46.919118 | 2025-10-02 14:13:46.919228 | TASK [bindep : Include install tasks] 2025-10-02 14:13:46.967268 | controller | ok 2025-10-02 14:13:47.004322 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 14:13:47.052396 | 2025-10-02 14:13:47.052518 | TASK [bindep : Create temp dir for bindep] 2025-10-02 14:13:47.677062 | controller | changed 2025-10-02 14:13:47.690992 | 2025-10-02 14:13:47.691115 | TASK [Ensure we have pip dependencies] 2025-10-02 14:13:47.721674 | controller | ok 2025-10-02 14:13:47.772957 | 2025-10-02 14:13:47.773074 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 10:13:48.119390 | controller | /usr/bin/pip3 2025-10-02 10:13:48.139780 | controller | /usr/bin/python3: No module named wheel 2025-10-02 14:13:48.345583 | controller | ok: Runtime: 0:00:00.031613 2025-10-02 14:13:48.351872 | 2025-10-02 14:13:48.351971 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 14:13:48.411277 | controller | ok: "/var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 14:13:48.427626 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 14:13:48.458837 | 2025-10-02 14:13:48.458958 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 14:13:51.377364 | controller | changed 2025-10-02 14:13:51.383207 | 2025-10-02 14:13:51.383275 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 14:13:51.428461 | controller | skipping: Conditional result was False 2025-10-02 14:13:51.438210 | 2025-10-02 14:13:51.438310 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 14:13:51.489189 | controller | skipping: Conditional result was False 2025-10-02 14:13:51.496485 | 2025-10-02 14:13:51.496558 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 14:13:51.561713 | controller | skipping: Conditional result was False 2025-10-02 14:13:51.571064 | 2025-10-02 14:13:51.571225 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 14:13:51.622247 | controller | skipping: Conditional result was False 2025-10-02 14:13:51.628934 | 2025-10-02 14:13:51.629074 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 14:13:52.201202 | controller | skipping: Conditional result was False 2025-10-02 14:13:52.208410 | 2025-10-02 14:13:52.208540 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 14:13:52.233243 | controller | skipping: Conditional result was False 2025-10-02 14:13:52.239988 | 2025-10-02 14:13:52.240094 | TASK [ensure-pip : Install pip from source] 2025-10-02 14:13:52.299448 | controller | skipping: Conditional result was False 2025-10-02 14:13:52.307577 | 2025-10-02 14:13:52.307749 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 10:13:52.573937 | controller | /usr/bin/python3 2025-10-02 14:13:52.873439 | controller | ok: Runtime: 0:00:00.004602 2025-10-02 14:13:52.879306 | 2025-10-02 14:13:52.879387 | TASK [ensure-pip : Set host default] 2025-10-02 14:13:52.951325 | controller | ok 2025-10-02 14:13:52.957064 | 2025-10-02 14:13:52.957149 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 14:13:53.022304 | controller | ok 2025-10-02 14:13:53.044522 | 2025-10-02 14:13:53.044668 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 14:13:57.151725 | controller | changed 2025-10-02 14:13:57.157486 | 2025-10-02 14:13:57.157549 | TASK [bindep : Define bindep_command] 2025-10-02 14:13:57.203654 | controller | ok 2025-10-02 14:13:57.209321 | 2025-10-02 14:13:57.209394 | LOOP [bindep : Include package tasks] 2025-10-02 14:13:57.285163 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 14:13:57.285338 | controller | ok: All items complete 2025-10-02 14:13:57.285364 | 2025-10-02 14:13:57.295454 | controller | included: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 14:13:57.310291 | 2025-10-02 14:13:57.310415 | TASK [bindep : Define bindep_run fact] 2025-10-02 14:13:57.355828 | controller | ok 2025-10-02 14:13:57.360841 | 2025-10-02 14:13:57.360904 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 10:13:58.784664 | controller | podman 2025-10-02 10:13:58.821127 | controller | python3-jmespath 2025-10-02 10:13:58.821194 | controller | python3-libvirt 2025-10-02 10:13:58.821205 | controller | python3-lxml 2025-10-02 10:13:58.821217 | controller | python3-netaddr 2025-10-02 14:13:58.893431 | controller | ok: Runtime: 0:00:01.154489 2025-10-02 14:13:58.900878 | 2025-10-02 14:13:58.900995 | TASK [bindep : Install distro packages from bindep] 2025-10-02 14:15:12.063300 | controller | changed 2025-10-02 14:15:12.073695 | 2025-10-02 14:15:12.073786 | TASK [bindep : Check that packages are installed] 2025-10-02 14:15:13.628593 | controller | ok: Runtime: 0:00:01.162503 2025-10-02 14:15:13.636070 | 2025-10-02 14:15:13.636196 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 14:15:13.673145 | controller | skipping: Conditional result was False 2025-10-02 14:15:13.687566 | 2025-10-02 14:15:13.687713 | TASK [Run test-setup role] 2025-10-02 14:15:13.712706 | controller | ok 2025-10-02 14:15:13.759694 | 2025-10-02 14:15:13.759806 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 14:15:14.027266 | controller | ok 2025-10-02 14:15:14.035494 | 2025-10-02 14:15:14.037011 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 14:15:14.577061 | controller | skipping: Conditional result was False 2025-10-02 14:15:14.609326 | 2025-10-02 14:15:14.609450 | TASK [bindep : Remove bindep temp dir] 2025-10-02 14:15:15.169786 | controller | ok 2025-10-02 14:15:15.193856 | 2025-10-02 14:15:15.193956 | PLAY RECAP 2025-10-02 14:15:15.194001 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 14:15:15.194021 | 2025-10-02 14:15:15.562514 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 14:15:15.563500 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 14:15:16.358403 | 2025-10-02 14:15:16.358571 | PLAY [all] 2025-10-02 14:15:16.390196 | 2025-10-02 14:15:16.390340 | TASK [Abort when test_command variable is undefined] 2025-10-02 14:15:16.433341 | controller | skipping: Conditional result was False 2025-10-02 14:15:16.446261 | 2025-10-02 14:15:16.446384 | TASK [Convert test_command to list] 2025-10-02 14:15:16.493773 | controller | skipping: Conditional result was False 2025-10-02 14:15:16.500763 | 2025-10-02 14:15:16.500856 | TASK [Use test_command list] 2025-10-02 14:15:16.571578 | controller | ok 2025-10-02 14:15:16.578901 | 2025-10-02 14:15:16.578997 | LOOP [Run test_command] 2025-10-02 14:15:17.213776 | controller | no check to run 2025-10-02 14:15:17.213975 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007079 2025-10-02 14:15:17.253529 | 2025-10-02 14:15:17.253797 | PLAY RECAP 2025-10-02 14:15:17.253844 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 14:15:17.254006 | 2025-10-02 14:15:17.393551 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 14:15:17.394464 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 14:15:18.058872 | 2025-10-02 14:15:18.059015 | PLAY [all] 2025-10-02 14:15:18.081321 | 2025-10-02 14:15:18.081468 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 14:15:18.504986 | controller | changed: non-zero return code 2025-10-02 14:15:18.510935 | 2025-10-02 14:15:18.511016 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 14:15:18.535522 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.541663 | 2025-10-02 14:15:18.541799 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 14:15:18.565833 | 2025-10-02 14:15:18.566128 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 14:15:18.590247 | 2025-10-02 14:15:18.590420 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 14:15:18.605256 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.611705 | 2025-10-02 14:15:18.611810 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 14:15:18.643607 | 2025-10-02 14:15:18.643793 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 14:15:18.658265 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.664611 | 2025-10-02 14:15:18.664688 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 14:15:18.692987 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.700097 | 2025-10-02 14:15:18.700188 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 14:15:18.735989 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.779746 | 2025-10-02 14:15:18.779861 | PLAY RECAP 2025-10-02 14:15:18.779904 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 14:15:18.779925 | 2025-10-02 14:15:18.984972 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 14:15:18.985879 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 14:15:19.635234 | 2025-10-02 14:15:19.635373 | PLAY [all] 2025-10-02 14:15:19.654789 | 2025-10-02 14:15:19.654905 | TASK [include_role : fetch-output] 2025-10-02 14:15:19.685453 | controller | ok 2025-10-02 14:15:19.708773 | 2025-10-02 14:15:19.708906 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 14:15:19.753776 | controller | skipping: Conditional result was False 2025-10-02 14:15:19.759754 | 2025-10-02 14:15:19.759828 | TASK [fetch-output : Set log path for single node] 2025-10-02 14:15:19.812121 | controller | ok 2025-10-02 14:15:19.820603 | 2025-10-02 14:15:19.820712 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 14:15:20.250976 | controller -> localhost | ok: "/var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/logs" 2025-10-02 14:15:20.495658 | controller -> localhost | changed: "/var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/artifacts" 2025-10-02 14:15:20.807000 | controller -> localhost | changed: "/var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/docs" 2025-10-02 14:15:20.820786 | 2025-10-02 14:15:20.820909 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 14:15:21.478594 | controller | changed: .d..t...... ./ 2025-10-02 14:15:21.478838 | controller | changed: All items complete 2025-10-02 14:15:21.478866 | 2025-10-02 14:15:21.972951 | controller | changed: .d..t...... ./ 2025-10-02 14:15:22.477994 | controller | changed: .d..t...... ./ 2025-10-02 14:15:22.498425 | 2025-10-02 14:15:22.498540 | TASK [include_role : fetch-output-openshift] 2025-10-02 14:15:22.512158 | controller | skipping: Conditional result was False 2025-10-02 14:15:22.518812 | 2025-10-02 14:15:22.518926 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 14:15:23.107828 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.046840 2025-10-02 14:15:23.438715 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.023806 2025-10-02 14:15:23.477092 | 2025-10-02 14:15:23.477243 | PLAY [all] 2025-10-02 14:15:23.502904 | 2025-10-02 14:15:23.503033 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 14:15:24.111075 | controller | changed 2025-10-02 14:15:24.191912 | 2025-10-02 14:15:24.192022 | PLAY RECAP 2025-10-02 14:15:24.192066 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 14:15:24.192086 | 2025-10-02 14:15:24.348542 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 14:15:24.349491 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 14:15:25.197612 | 2025-10-02 14:15:25.197857 | PLAY [localhost] 2025-10-02 14:15:25.218715 | 2025-10-02 14:15:25.218879 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 14:15:25.709671 | localhost | changed 2025-10-02 14:15:25.718237 | 2025-10-02 14:15:25.718400 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 14:15:25.770701 | localhost | ok 2025-10-02 14:15:25.785022 | 2025-10-02 14:15:25.785169 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 14:15:26.442192 | localhost | changed 2025-10-02 14:15:26.453694 | 2025-10-02 14:15:26.454029 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 14:15:27.367376 | localhost | changed 2025-10-02 14:15:27.374522 | 2025-10-02 14:15:27.374614 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 14:15:27.950903 | localhost | Identity added: /var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/tmp/ansible.d3clud4m (/var/lib/zuul/builds/820347adbb66458894dc914694265a35/work/tmp/ansible.d3clud4m) 2025-10-02 14:15:27.956431 | localhost | ok: Runtime: 0:00:00.007945 2025-10-02 14:15:27.962868 | 2025-10-02 14:15:27.962935 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 14:15:28.251106 | localhost | ok: Runtime: 0:00:00.010434 2025-10-02 14:15:28.256517 | 2025-10-02 14:15:28.256596 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 14:15:28.305477 | localhost | changed 2025-10-02 14:15:28.310250 | 2025-10-02 14:15:28.310317 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 14:15:28.685972 | localhost | changed 2025-10-02 14:15:28.710046 | 2025-10-02 14:15:28.710141 | PLAY [localhost] 2025-10-02 14:15:28.725786 | 2025-10-02 14:15:28.725889 | TASK [Generate bulk log download script] 2025-10-02 14:15:28.745305 | localhost | ok 2025-10-02 14:15:28.762050 | 2025-10-02 14:15:28.762170 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 14:15:28.793649 | localhost | ok: All assertions passed 2025-10-02 14:15:28.808258 | 2025-10-02 14:15:28.808380 | TASK [local-log-download : Create download script] 2025-10-02 14:15:29.230011 | localhost -> localhost | changed 2025-10-02 14:15:29.240049 | 2025-10-02 14:15:29.240192 | TASK [Register quick-download link] 2025-10-02 14:15:29.295836 | localhost | ok 2025-10-02 14:15:29.321500 | 2025-10-02 14:15:29.321625 | PLAY [logserver.rdoproject.org] 2025-10-02 14:15:29.337427 | 2025-10-02 14:15:29.337643 | TASK [Set zuul-log-path fact] 2025-10-02 14:15:29.356939 | logserver.rdoproject.org | ok 2025-10-02 14:15:29.373697 | 2025-10-02 14:15:29.373848 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 14:15:29.403313 | logserver.rdoproject.org | ok 2025-10-02 14:15:29.411285 | 2025-10-02 14:15:29.411375 | TASK [upload-logs : Create log directories] 2025-10-02 14:15:30.018553 | logserver.rdoproject.org | changed 2025-10-02 14:15:30.029765 | 2025-10-02 14:15:30.029886 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 14:15:30.386877 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.024673 2025-10-02 14:15:30.392047 | 2025-10-02 14:15:30.392131 | TASK [upload-logs : Upload logs to log server] 2025-10-02 14:15:31.081154 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 14:15:31.084626 | 2025-10-02 14:15:31.084712 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 14:15:31.142854 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:31.151893 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:31.165270 | 2025-10-02 14:15:31.165533 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 14:15:31.209867 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:31.210103 | 2025-10-02 14:15:31.214019 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:31.231012 | 2025-10-02 14:15:31.231227 | LOOP [upload-logs : Upload console log and json output]