2025-10-02 15:27:54.681438 | Job console starting... 2025-10-02 15:27:54.697827 | Updating repositories 2025-10-02 15:27:54.739604 | Preparing job workspace 2025-10-02 15:27:58.058167 | Running Ansible setup... 2025-10-02 15:28:02.013482 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 15:28:02.612574 | 2025-10-02 15:28:02.612706 | PLAY [localhost] 2025-10-02 15:28:02.622298 | 2025-10-02 15:28:02.622390 | TASK [Gathering Facts] 2025-10-02 15:28:03.600259 | localhost | ok 2025-10-02 15:28:03.621717 | 2025-10-02 15:28:03.621957 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 15:28:03.993051 | localhost -> localhost | changed 2025-10-02 15:28:03.998393 | 2025-10-02 15:28:03.998460 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 15:28:04.866142 | localhost -> localhost | changed 2025-10-02 15:28:04.876977 | 2025-10-02 15:28:04.877133 | TASK [Setup log path fact] 2025-10-02 15:28:04.900269 | localhost | ok 2025-10-02 15:28:04.919806 | 2025-10-02 15:28:04.919929 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 15:28:04.948653 | localhost | ok 2025-10-02 15:28:04.961240 | 2025-10-02 15:28:04.961356 | TASK [emit-job-header : Print job information] 2025-10-02 15:28:05.012363 | # Job Information 2025-10-02 15:28:05.012785 | Ansible Version: 2.15.12 2025-10-02 15:28:05.012854 | Job: cifmw-molecule-cifmw_external_dns 2025-10-02 15:28:05.012886 | Pipeline: github-check 2025-10-02 15:28:05.012942 | Executor: ze01.softwarefactory-project.io 2025-10-02 15:28:05.012969 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 15:28:05.013031 | Log URL (when completed): https://logserver.rdoproject.org/019/rdoproject.org/0197c3d29a7a4c6eb918c59c3803f9a0/ 2025-10-02 15:28:05.013120 | Event ID: 31e612e0-9fa4-11f0-8bb8-66cf2469bdc9 2025-10-02 15:28:05.019234 | 2025-10-02 15:28:05.019370 | LOOP [emit-job-header : Print node information] 2025-10-02 15:28:05.137887 | localhost | ok: 2025-10-02 15:28:05.138048 | localhost | # Node Information 2025-10-02 15:28:05.138085 | localhost | Inventory Hostname: controller 2025-10-02 15:28:05.138110 | localhost | Hostname: np0005466605 2025-10-02 15:28:05.138131 | localhost | Username: zuul 2025-10-02 15:28:05.138152 | localhost | Distro: CentOS 9 2025-10-02 15:28:05.138170 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 15:28:05.138189 | localhost | Region: RegionOne 2025-10-02 15:28:05.138207 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 15:28:05.138224 | localhost | Product Name: OpenStack Nova 2025-10-02 15:28:05.138241 | localhost | Interface IP: 38.129.56.106 2025-10-02 15:28:05.165068 | 2025-10-02 15:28:05.165166 | PLAY [all] 2025-10-02 15:28:05.172293 | 2025-10-02 15:28:05.172384 | TASK [Gather network facts] 2025-10-02 15:28:05.654691 | controller | ok 2025-10-02 15:28:05.677778 | 2025-10-02 15:28:05.677893 | TASK [include_role : start-zuul-console] 2025-10-02 15:28:05.699570 | controller | ok 2025-10-02 15:28:05.719562 | 2025-10-02 15:28:05.719705 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 15:28:06.133260 | controller | ok 2025-10-02 15:28:06.146442 | 2025-10-02 15:28:06.146599 | TASK [include_role : add-build-sshkey] 2025-10-02 15:28:06.180490 | controller | ok 2025-10-02 15:28:06.206238 | 2025-10-02 15:28:06.206365 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 15:28:06.465621 | controller -> localhost | ok 2025-10-02 15:28:06.471429 | 2025-10-02 15:28:06.471529 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 15:28:06.500811 | controller | ok 2025-10-02 15:28:06.519117 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 15:28:06.528806 | 2025-10-02 15:28:06.528941 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 15:28:07.722182 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 15:28:07.722412 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/0197c3d29a7a4c6eb918c59c3803f9a0_id_rsa. 2025-10-02 15:28:07.722450 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/0197c3d29a7a4c6eb918c59c3803f9a0_id_rsa.pub. 2025-10-02 15:28:07.722475 | controller -> localhost | The key fingerprint is: 2025-10-02 15:28:07.722496 | controller -> localhost | SHA256:Ai1mpQvVeQ9Z10itF4+foT8PB69+C0DXTGLJDIwJdYU zuul-build-sshkey 2025-10-02 15:28:07.722515 | controller -> localhost | The key's randomart image is: 2025-10-02 15:28:07.722535 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 15:28:07.722601 | controller -> localhost | | ...oo+=+OB.. | 2025-10-02 15:28:07.722631 | controller -> localhost | | . +o +o.Eo+O | 2025-10-02 15:28:07.722661 | controller -> localhost | | . * .. o . o * | 2025-10-02 15:28:07.722692 | controller -> localhost | | + + o o o..| 2025-10-02 15:28:07.722722 | controller -> localhost | | . . S . .o.o| 2025-10-02 15:28:07.722752 | controller -> localhost | | . .. +.| 2025-10-02 15:28:07.722782 | controller -> localhost | | .o o| 2025-10-02 15:28:07.722812 | controller -> localhost | | .*.| 2025-10-02 15:28:07.722837 | controller -> localhost | | .oo=| 2025-10-02 15:28:07.722860 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 15:28:07.722915 | controller -> localhost | ok: Runtime: 0:00:00.723634 2025-10-02 15:28:07.729541 | 2025-10-02 15:28:07.729669 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 15:28:07.759446 | controller | ok 2025-10-02 15:28:07.769894 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 15:28:07.780588 | 2025-10-02 15:28:07.780716 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 15:28:07.805378 | controller | skipping: Conditional result was False 2025-10-02 15:28:07.812286 | 2025-10-02 15:28:07.812403 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 15:28:08.321214 | controller | changed 2025-10-02 15:28:08.332115 | 2025-10-02 15:28:08.332227 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 15:28:08.686857 | controller | ok 2025-10-02 15:28:08.692124 | 2025-10-02 15:28:08.692196 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 15:28:09.650660 | controller | changed 2025-10-02 15:28:09.665534 | 2025-10-02 15:28:09.665684 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 15:28:10.604210 | controller | changed 2025-10-02 15:28:10.609574 | 2025-10-02 15:28:10.609643 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 15:28:10.633439 | controller | skipping: Conditional result was False 2025-10-02 15:28:10.639100 | 2025-10-02 15:28:10.639168 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 15:28:11.021090 | controller -> localhost | changed 2025-10-02 15:28:11.031354 | 2025-10-02 15:28:11.031429 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 15:28:11.282110 | controller -> localhost | Identity added: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/0197c3d29a7a4c6eb918c59c3803f9a0_id_rsa (zuul-build-sshkey) 2025-10-02 15:28:11.282336 | controller -> localhost | ok: Runtime: 0:00:00.012860 2025-10-02 15:28:11.288114 | 2025-10-02 15:28:11.288178 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 15:28:11.671975 | controller | ok 2025-10-02 15:28:11.689201 | 2025-10-02 15:28:11.689330 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 15:28:11.714350 | controller | skipping: Conditional result was False 2025-10-02 15:28:11.725539 | 2025-10-02 15:28:11.725657 | TASK [include_role : validate-host] 2025-10-02 15:28:11.746575 | controller | ok 2025-10-02 15:28:11.770102 | 2025-10-02 15:28:11.770234 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 15:28:11.798759 | controller | ok 2025-10-02 15:28:11.803705 | 2025-10-02 15:28:11.803783 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 15:28:12.062742 | controller -> localhost | ok 2025-10-02 15:28:12.087742 | 2025-10-02 15:28:12.087875 | TASK [validate-host : Collect information about the host] 2025-10-02 15:28:12.992389 | controller | ok 2025-10-02 15:28:13.008943 | 2025-10-02 15:28:13.009058 | TASK [validate-host : Sanitize hostname] 2025-10-02 15:28:13.088632 | controller | ok 2025-10-02 15:28:13.099217 | 2025-10-02 15:28:13.099332 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 15:28:13.977254 | controller -> localhost | changed 2025-10-02 15:28:13.983197 | 2025-10-02 15:28:13.983321 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 15:28:14.400358 | controller | ok 2025-10-02 15:28:14.410975 | 2025-10-02 15:28:14.411101 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 15:28:14.858788 | controller -> localhost | changed 2025-10-02 15:28:14.869350 | 2025-10-02 15:28:14.869465 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 15:28:14.883482 | controller | skipping: Conditional result was False 2025-10-02 15:28:14.889711 | 2025-10-02 15:28:14.889830 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 15:28:14.906454 | controller | skipping: Conditional result was False 2025-10-02 15:28:14.916207 | 2025-10-02 15:28:14.916281 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 15:28:15.198640 | controller | ok: "logs" 2025-10-02 15:28:15.198933 | controller | ok: All items complete 2025-10-02 15:28:15.198971 | 2025-10-02 15:28:15.409116 | controller | ok: "artifacts" 2025-10-02 15:28:15.626602 | controller | ok: "docs" 2025-10-02 15:28:15.633371 | 2025-10-02 15:28:15.633486 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 15:28:15.907581 | controller | changed: "logs" 2025-10-02 15:28:16.134087 | controller | changed: "artifacts" 2025-10-02 15:28:16.375077 | controller | changed: "docs" 2025-10-02 15:28:16.403243 | 2025-10-02 15:28:16.403371 | PLAY RECAP 2025-10-02 15:28:16.403415 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 15:28:16.403441 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 15:28:16.403461 | 2025-10-02 15:28:16.537300 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 15:28:16.538205 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 15:28:17.140193 | 2025-10-02 15:28:17.140307 | PLAY [localhost] 2025-10-02 15:28:17.156341 | 2025-10-02 15:28:17.156420 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 15:28:17.535945 | localhost | ok 2025-10-02 15:28:17.543612 | 2025-10-02 15:28:17.543961 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 15:28:18.352119 | localhost | changed 2025-10-02 15:28:18.380669 | 2025-10-02 15:28:18.380778 | PLAY [all] 2025-10-02 15:28:18.403572 | 2025-10-02 15:28:18.403699 | TASK [include_role : prepare-workspace] 2025-10-02 15:28:18.434519 | controller | ok 2025-10-02 15:28:18.452674 | 2025-10-02 15:28:18.452805 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 15:28:18.875674 | controller | ok 2025-10-02 15:28:18.882461 | 2025-10-02 15:28:18.882543 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 15:28:20.703822 | controller | Output suppressed because no_log was given 2025-10-02 15:28:20.721555 | 2025-10-02 15:28:20.721704 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 15:28:20.960492 | controller | changed: "logs" 2025-10-02 15:28:21.233319 | controller | changed: "artifacts" 2025-10-02 15:28:21.457217 | controller | changed: "docs" 2025-10-02 15:28:21.478064 | 2025-10-02 15:28:21.478233 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 15:28:21.747368 | controller | changed: "logs" 2025-10-02 15:28:21.747734 | controller | changed: All items complete 2025-10-02 15:28:21.747771 | 2025-10-02 15:28:21.975747 | controller | changed: "artifacts" 2025-10-02 15:28:22.213317 | controller | changed: "docs" 2025-10-02 15:28:22.236350 | 2025-10-02 15:28:22.236472 | TASK [Check if worker can sudo] 2025-10-02 15:28:22.794271 | controller | ok: Runtime: 0:00:00.050683 2025-10-02 15:28:22.800803 | 2025-10-02 15:28:22.800871 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 15:28:22.875661 | controller | skipping: Conditional result was False 2025-10-02 15:28:22.881767 | 2025-10-02 15:28:22.881838 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 15:28:22.944792 | controller | ok 2025-10-02 15:28:22.956103 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 15:28:22.964563 | 2025-10-02 15:28:22.964701 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 15:28:23.345149 | controller | ok 2025-10-02 15:28:23.357339 | 2025-10-02 15:28:23.357468 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 15:28:23.443193 | controller | ok: "/var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 15:28:23.464766 | 2025-10-02 15:28:23.464981 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 15:28:24.333408 | controller | changed 2025-10-02 15:28:24.340136 | 2025-10-02 15:28:24.340207 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 15:28:24.441833 | controller | ok: "/var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 15:28:24.442055 | controller | ok: All items complete 2025-10-02 15:28:24.442085 | 2025-10-02 15:28:24.508259 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 15:28:24.514985 | 2025-10-02 15:28:24.515111 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 15:28:25.416966 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 15:28:26.220488 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 15:28:26.235671 | 2025-10-02 15:28:26.235802 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 15:28:26.699840 | controller | changed: section and option added 2025-10-02 15:28:26.727300 | 2025-10-02 15:28:26.727397 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 15:28:27.556633 | controller | 29 files removed 2025-10-02 15:28:27.557424 | controller | ok: Item: dnf clean all Runtime: 0:00:00.506302 2025-10-02 15:28:27.557544 | controller | changed: All items complete 2025-10-02 15:28:27.557782 | 2025-10-02 15:28:38.733887 | 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 15:28:38.734081 | controller | DNF version: 4.14.0 2025-10-02 15:28:38.734149 | controller | cachedir: /var/cache/dnf 2025-10-02 15:28:38.734204 | controller | Making cache files for all metadata files. 2025-10-02 15:28:38.734256 | controller | baseos: has expired and will be refreshed. 2025-10-02 15:28:38.734304 | controller | appstream: has expired and will be refreshed. 2025-10-02 15:28:38.734353 | controller | crb: has expired and will be refreshed. 2025-10-02 15:28:38.734613 | controller | extras-common: has expired and will be refreshed. 2025-10-02 15:28:38.734675 | controller | repo: downloading from remote: baseos 2025-10-02 15:28:38.734718 | controller | CentOS Stream 9 - BaseOS 56 MB/s | 8.8 MB 00:00 2025-10-02 15:28:38.734761 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 15:28:38.734800 | controller | repo: downloading from remote: appstream 2025-10-02 15:28:38.734837 | controller | CentOS Stream 9 - AppStream 68 MB/s | 25 MB 00:00 2025-10-02 15:28:38.734874 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 15:28:38.734911 | controller | repo: downloading from remote: crb 2025-10-02 15:28:38.734948 | controller | CentOS Stream 9 - CRB 35 MB/s | 7.1 MB 00:00 2025-10-02 15:28:38.734987 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 15:28:38.735067 | controller | repo: downloading from remote: extras-common 2025-10-02 15:28:38.735110 | controller | CentOS Stream 9 - Extras packages 1.8 MB/s | 20 kB 00:00 2025-10-02 15:28:38.735148 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 15:28:38.735183 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 15:28:38.735219 | controller | Completion plugin: Generating completion cache... 2025-10-02 15:28:38.735254 | controller | Metadata cache created. 2025-10-02 15:28:38.735309 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.903231 2025-10-02 15:28:38.770493 | 2025-10-02 15:28:38.770668 | PLAY RECAP 2025-10-02 15:28:38.770782 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 15:28:38.770878 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 15:28:38.770951 | 2025-10-02 15:28:38.887211 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 15:28:38.890507 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 15:28:39.506380 | 2025-10-02 15:28:39.506505 | PLAY [all] 2025-10-02 15:28:39.527661 | 2025-10-02 15:28:39.527759 | TASK [Install binary dependencies] 2025-10-02 15:28:39.597623 | controller | ok 2025-10-02 15:28:39.619847 | 2025-10-02 15:28:39.620008 | TASK [bindep : Include find tasks] 2025-10-02 15:28:39.662342 | controller | ok 2025-10-02 15:28:39.674326 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 15:28:39.683283 | 2025-10-02 15:28:39.683381 | TASK [bindep : Look for bindep.txt] 2025-10-02 15:28:40.094187 | controller | ok 2025-10-02 15:28:40.103612 | 2025-10-02 15:28:40.103707 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:40.147960 | controller | ok 2025-10-02 15:28:40.155985 | 2025-10-02 15:28:40.156091 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 15:28:40.181741 | controller | skipping: Conditional result was False 2025-10-02 15:28:40.190514 | 2025-10-02 15:28:40.190624 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:40.230277 | controller | skipping: Conditional result was False 2025-10-02 15:28:40.238838 | 2025-10-02 15:28:40.238937 | TASK [bindep : Look for bindep fallback file] 2025-10-02 15:28:40.264683 | controller | skipping: Conditional result was False 2025-10-02 15:28:40.273324 | 2025-10-02 15:28:40.273451 | TASK [bindep : Define bindep_file fact] 2025-10-02 15:28:40.299693 | controller | skipping: Conditional result was False 2025-10-02 15:28:40.308455 | 2025-10-02 15:28:40.308583 | TASK [bindep : Include bindep tasks] 2025-10-02 15:28:40.352929 | controller | ok 2025-10-02 15:28:40.362676 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 15:28:40.372860 | 2025-10-02 15:28:40.372964 | TASK [bindep : Look for bindep command] 2025-10-02 15:28:40.411940 | controller | skipping: Conditional result was False 2025-10-02 15:28:40.421519 | 2025-10-02 15:28:40.421646 | TASK [bindep : Check for system bindep] 2025-10-02 15:28:40.951421 | controller | ok: Runtime: 0:00:00.006285 2025-10-02 15:28:40.957121 | 2025-10-02 15:28:40.957185 | TASK [bindep : Define bindep_command fact] 2025-10-02 15:28:40.981144 | controller | skipping: Conditional result was False 2025-10-02 15:28:40.986723 | 2025-10-02 15:28:40.986786 | TASK [bindep : Include install tasks] 2025-10-02 15:28:41.015028 | controller | ok 2025-10-02 15:28:41.023269 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 15:28:41.031914 | 2025-10-02 15:28:41.031984 | TASK [bindep : Create temp dir for bindep] 2025-10-02 15:28:41.434905 | controller | changed 2025-10-02 15:28:41.446613 | 2025-10-02 15:28:41.446752 | TASK [Ensure we have pip dependencies] 2025-10-02 15:28:41.484339 | controller | ok 2025-10-02 15:28:41.540817 | 2025-10-02 15:28:41.540980 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 11:28:41.841693 | controller | /usr/bin/pip3 2025-10-02 11:28:41.886374 | controller | /usr/bin/python3: No module named wheel 2025-10-02 15:28:42.071059 | controller | ok: Runtime: 0:00:00.057775 2025-10-02 15:28:42.077470 | 2025-10-02 15:28:42.077553 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 15:28:42.104951 | controller | ok: "/var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 15:28:42.129183 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 15:28:42.141444 | 2025-10-02 15:28:42.141665 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 15:28:44.519096 | controller | changed 2025-10-02 15:28:44.527609 | 2025-10-02 15:28:44.527753 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 15:28:44.575918 | controller | skipping: Conditional result was False 2025-10-02 15:28:44.592343 | 2025-10-02 15:28:44.592520 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 15:28:44.651613 | controller | skipping: Conditional result was False 2025-10-02 15:28:44.665886 | 2025-10-02 15:28:44.666097 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 15:28:44.734365 | controller | skipping: Conditional result was False 2025-10-02 15:28:44.748379 | 2025-10-02 15:28:44.748543 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 15:28:44.764870 | controller | skipping: Conditional result was False 2025-10-02 15:28:44.776881 | 2025-10-02 15:28:44.777011 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 15:28:45.321839 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.328129 | 2025-10-02 15:28:45.328197 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 15:28:45.355468 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.368789 | 2025-10-02 15:28:45.368975 | TASK [ensure-pip : Install pip from source] 2025-10-02 15:28:45.397110 | controller | skipping: Conditional result was False 2025-10-02 15:28:45.406349 | 2025-10-02 15:28:45.406478 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 11:28:45.691018 | controller | /usr/bin/python3 2025-10-02 15:28:45.950740 | controller | ok: Runtime: 0:00:00.007679 2025-10-02 15:28:45.962825 | 2025-10-02 15:28:45.962957 | TASK [ensure-pip : Set host default] 2025-10-02 15:28:46.037585 | controller | ok 2025-10-02 15:28:46.045381 | 2025-10-02 15:28:46.045513 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 15:28:46.104687 | controller | ok 2025-10-02 15:28:46.129767 | 2025-10-02 15:28:46.129878 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 15:28:51.122870 | controller | changed 2025-10-02 15:28:51.135122 | 2025-10-02 15:28:51.135298 | TASK [bindep : Define bindep_command] 2025-10-02 15:28:51.172648 | controller | ok 2025-10-02 15:28:51.184107 | 2025-10-02 15:28:51.184286 | LOOP [bindep : Include package tasks] 2025-10-02 15:28:51.231740 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 15:28:51.231936 | controller | ok: All items complete 2025-10-02 15:28:51.231970 | 2025-10-02 15:28:51.244163 | controller | included: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 15:28:51.259942 | 2025-10-02 15:28:51.260069 | TASK [bindep : Define bindep_run fact] 2025-10-02 15:28:51.293792 | controller | ok 2025-10-02 15:28:51.301066 | 2025-10-02 15:28:51.301156 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 11:28:52.804660 | controller | podman 2025-10-02 11:28:52.846245 | controller | python3-jmespath 2025-10-02 11:28:52.846311 | controller | python3-libvirt 2025-10-02 11:28:52.846322 | controller | python3-lxml 2025-10-02 11:28:52.846334 | controller | python3-netaddr 2025-10-02 15:28:53.342487 | controller | ok: Runtime: 0:00:01.260334 2025-10-02 15:28:53.348832 | 2025-10-02 15:28:53.348922 | TASK [bindep : Install distro packages from bindep] 2025-10-02 15:30:03.753429 | controller | changed 2025-10-02 15:30:03.761801 | 2025-10-02 15:30:03.761941 | TASK [bindep : Check that packages are installed] 2025-10-02 15:30:05.309661 | controller | ok: Runtime: 0:00:01.221097 2025-10-02 15:30:05.319717 | 2025-10-02 15:30:05.319859 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 15:30:05.344880 | controller | skipping: Conditional result was False 2025-10-02 15:30:05.359452 | 2025-10-02 15:30:05.359582 | TASK [Run test-setup role] 2025-10-02 15:30:05.378127 | controller | ok 2025-10-02 15:30:05.395667 | 2025-10-02 15:30:05.395793 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 15:30:05.629318 | controller | ok 2025-10-02 15:30:05.642314 | 2025-10-02 15:30:05.643380 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 15:30:06.183880 | controller | skipping: Conditional result was False 2025-10-02 15:30:06.203816 | 2025-10-02 15:30:06.203933 | TASK [bindep : Remove bindep temp dir] 2025-10-02 15:30:06.646326 | controller | ok 2025-10-02 15:30:06.669161 | 2025-10-02 15:30:06.669278 | PLAY RECAP 2025-10-02 15:30:06.669363 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 15:30:06.669408 | 2025-10-02 15:30:06.793157 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 15:30:06.794913 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 15:30:07.415799 | 2025-10-02 15:30:07.415930 | PLAY [all] 2025-10-02 15:30:07.437705 | 2025-10-02 15:30:07.437825 | TASK [Abort when test_command variable is undefined] 2025-10-02 15:30:07.473042 | controller | skipping: Conditional result was False 2025-10-02 15:30:07.478724 | 2025-10-02 15:30:07.478802 | TASK [Convert test_command to list] 2025-10-02 15:30:07.523364 | controller | skipping: Conditional result was False 2025-10-02 15:30:07.529613 | 2025-10-02 15:30:07.529684 | TASK [Use test_command list] 2025-10-02 15:30:07.582279 | controller | ok 2025-10-02 15:30:07.591630 | 2025-10-02 15:30:07.591769 | LOOP [Run test_command] 2025-10-02 15:30:08.005538 | controller | no check to run 2025-10-02 15:30:08.005732 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008639 2025-10-02 15:30:08.048667 | 2025-10-02 15:30:08.048830 | PLAY RECAP 2025-10-02 15:30:08.048917 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 15:30:08.048963 | 2025-10-02 15:30:08.159531 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 15:30:08.160418 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 15:30:08.815305 | 2025-10-02 15:30:08.815434 | PLAY [all] 2025-10-02 15:30:08.845746 | 2025-10-02 15:30:08.845884 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 15:30:09.242717 | controller | changed: non-zero return code 2025-10-02 15:30:09.257893 | 2025-10-02 15:30:09.258188 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 15:30:09.275116 | controller | skipping: Conditional result was False 2025-10-02 15:30:09.283458 | 2025-10-02 15:30:09.283555 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 15:30:09.316595 | 2025-10-02 15:30:09.316753 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 15:30:09.337953 | 2025-10-02 15:30:09.338158 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 15:30:09.352508 | controller | skipping: Conditional result was False 2025-10-02 15:30:09.361147 | 2025-10-02 15:30:09.361294 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 15:30:09.393375 | 2025-10-02 15:30:09.393564 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 15:30:09.430134 | controller | skipping: Conditional result was False 2025-10-02 15:30:09.437519 | 2025-10-02 15:30:09.437670 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 15:30:09.455186 | controller | skipping: Conditional result was False 2025-10-02 15:30:09.465572 | 2025-10-02 15:30:09.465731 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 15:30:09.491117 | controller | skipping: Conditional result was False 2025-10-02 15:30:09.526146 | 2025-10-02 15:30:09.526256 | PLAY RECAP 2025-10-02 15:30:09.526301 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 15:30:09.526321 | 2025-10-02 15:30:09.635685 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 15:30:09.636846 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 15:30:10.231522 | 2025-10-02 15:30:10.231641 | PLAY [all] 2025-10-02 15:30:10.255862 | 2025-10-02 15:30:10.255997 | TASK [include_role : fetch-output] 2025-10-02 15:30:10.286816 | controller | ok 2025-10-02 15:30:10.305193 | 2025-10-02 15:30:10.305305 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 15:30:10.349835 | controller | skipping: Conditional result was False 2025-10-02 15:30:10.356103 | 2025-10-02 15:30:10.356191 | TASK [fetch-output : Set log path for single node] 2025-10-02 15:30:10.385877 | controller | ok 2025-10-02 15:30:10.391452 | 2025-10-02 15:30:10.391563 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 15:30:10.781470 | controller -> localhost | ok: "/var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/logs" 2025-10-02 15:30:11.068638 | controller -> localhost | changed: "/var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/artifacts" 2025-10-02 15:30:11.380097 | controller -> localhost | changed: "/var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/docs" 2025-10-02 15:30:11.402033 | 2025-10-02 15:30:11.402187 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 15:30:12.068506 | controller | changed: .d..t...... ./ 2025-10-02 15:30:12.068708 | controller | changed: All items complete 2025-10-02 15:30:12.068754 | 2025-10-02 15:30:12.540747 | controller | changed: .d..t...... ./ 2025-10-02 15:30:13.070220 | controller | changed: .d..t...... ./ 2025-10-02 15:30:13.093728 | 2025-10-02 15:30:13.093822 | TASK [include_role : fetch-output-openshift] 2025-10-02 15:30:13.108140 | controller | skipping: Conditional result was False 2025-10-02 15:30:13.114959 | 2025-10-02 15:30:13.115061 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 15:30:13.608798 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010236 2025-10-02 15:30:13.880343 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.010180 2025-10-02 15:30:13.916893 | 2025-10-02 15:30:13.916999 | PLAY [all] 2025-10-02 15:30:13.933603 | 2025-10-02 15:30:13.933712 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 15:30:14.642613 | controller | changed 2025-10-02 15:30:14.668531 | 2025-10-02 15:30:14.668641 | PLAY RECAP 2025-10-02 15:30:14.668683 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 15:30:14.668704 | 2025-10-02 15:30:14.801720 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 15:30:14.803456 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 15:30:15.465538 | 2025-10-02 15:30:15.465711 | PLAY [localhost] 2025-10-02 15:30:15.492720 | 2025-10-02 15:30:15.492898 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 15:30:15.880456 | localhost | changed 2025-10-02 15:30:15.891166 | 2025-10-02 15:30:15.891445 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 15:30:15.923196 | localhost | ok 2025-10-02 15:30:15.936950 | 2025-10-02 15:30:15.937134 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 15:30:16.318668 | localhost | changed 2025-10-02 15:30:16.330643 | 2025-10-02 15:30:16.330797 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 15:30:17.017988 | localhost | changed 2025-10-02 15:30:17.023957 | 2025-10-02 15:30:17.024039 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 15:30:17.505570 | localhost | Identity added: /var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/tmp/ansible.vsp2o60h (/var/lib/zuul/builds/0197c3d29a7a4c6eb918c59c3803f9a0/work/tmp/ansible.vsp2o60h) 2025-10-02 15:30:17.505815 | localhost | ok: Runtime: 0:00:00.008872 2025-10-02 15:30:17.512843 | 2025-10-02 15:30:17.512923 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 15:30:17.797698 | localhost | ok: Runtime: 0:00:00.013065 2025-10-02 15:30:17.804602 | 2025-10-02 15:30:17.804756 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 15:30:17.871197 | localhost | changed 2025-10-02 15:30:17.878193 | 2025-10-02 15:30:17.878317 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 15:30:18.316785 | localhost | changed 2025-10-02 15:30:18.338551 | 2025-10-02 15:30:18.338660 | PLAY [localhost] 2025-10-02 15:30:18.353159 | 2025-10-02 15:30:18.353276 | TASK [Generate bulk log download script] 2025-10-02 15:30:18.371992 | localhost | ok 2025-10-02 15:30:18.385470 | 2025-10-02 15:30:18.385621 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 15:30:18.426753 | localhost | ok: All assertions passed 2025-10-02 15:30:18.433752 | 2025-10-02 15:30:18.433886 | TASK [local-log-download : Create download script] 2025-10-02 15:30:18.910212 | localhost -> localhost | changed 2025-10-02 15:30:18.920612 | 2025-10-02 15:30:18.920741 | TASK [Register quick-download link] 2025-10-02 15:30:18.952776 | localhost | ok 2025-10-02 15:30:19.012592 | 2025-10-02 15:30:19.012727 | PLAY [logserver.rdoproject.org] 2025-10-02 15:30:19.024566 | 2025-10-02 15:30:19.024686 | TASK [Set zuul-log-path fact] 2025-10-02 15:30:19.042846 | logserver.rdoproject.org | ok 2025-10-02 15:30:19.055312 | 2025-10-02 15:30:19.055428 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 15:30:19.092879 | logserver.rdoproject.org | ok 2025-10-02 15:30:19.099225 | 2025-10-02 15:30:19.099336 | TASK [upload-logs : Create log directories] 2025-10-02 15:30:19.840460 | logserver.rdoproject.org | changed 2025-10-02 15:30:19.845509 | 2025-10-02 15:30:19.845607 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 15:30:20.158804 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.014901 2025-10-02 15:30:20.163963 | 2025-10-02 15:30:20.164062 | TASK [upload-logs : Upload logs to log server] 2025-10-02 15:30:20.883072 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 15:30:20.886700 | 2025-10-02 15:30:20.886810 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 15:30:20.944044 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:20.944853 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:20.956933 | 2025-10-02 15:30:20.957091 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 15:30:21.015222 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:21.015472 | 2025-10-02 15:30:21.016269 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 15:30:21.028647 | 2025-10-02 15:30:21.028790 | LOOP [upload-logs : Upload console log and json output]