2025-10-02 19:27:10.137266 | Job console starting... 2025-10-02 19:27:10.147875 | Updating repositories 2025-10-02 19:27:10.185956 | Preparing job workspace 2025-10-02 19:27:13.574872 | Running Ansible setup... 2025-10-02 19:27:17.478311 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 19:27:18.086059 | 2025-10-02 19:27:18.086165 | PLAY [localhost] 2025-10-02 19:27:18.101509 | 2025-10-02 19:27:18.101582 | TASK [Gathering Facts] 2025-10-02 19:27:19.045527 | localhost | ok 2025-10-02 19:27:19.061840 | 2025-10-02 19:27:19.061923 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 19:27:19.573475 | localhost -> localhost | changed 2025-10-02 19:27:19.579020 | 2025-10-02 19:27:19.579088 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 19:27:20.762014 | localhost -> localhost | changed 2025-10-02 19:27:20.780611 | 2025-10-02 19:27:20.780804 | TASK [Setup log path fact] 2025-10-02 19:27:20.808304 | localhost | ok 2025-10-02 19:27:20.834918 | 2025-10-02 19:27:20.835041 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 19:27:20.862762 | localhost | ok 2025-10-02 19:27:20.878762 | 2025-10-02 19:27:20.878918 | TASK [emit-job-header : Print job information] 2025-10-02 19:27:20.919117 | # Job Information 2025-10-02 19:27:20.919293 | Ansible Version: 2.15.12 2025-10-02 19:27:20.919328 | Job: cifmw-molecule-cifmw_external_dns 2025-10-02 19:27:20.919355 | Pipeline: github-check 2025-10-02 19:27:20.919379 | Executor: ze02.softwarefactory-project.io 2025-10-02 19:27:20.919402 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 19:27:20.919427 | Log URL (when completed): https://logserver.rdoproject.org/979/rdoproject.org/97973c9df03d4fbb8b87ff1fae3f2b09/ 2025-10-02 19:27:20.919450 | Event ID: 9ca491d0-9fc5-11f0-8734-f8eb35e200a5 2025-10-02 19:27:20.924452 | 2025-10-02 19:27:20.924534 | LOOP [emit-job-header : Print node information] 2025-10-02 19:27:21.023602 | localhost | ok: 2025-10-02 19:27:21.023801 | localhost | # Node Information 2025-10-02 19:27:21.023829 | localhost | Inventory Hostname: controller 2025-10-02 19:27:21.023851 | localhost | Hostname: np0005467132 2025-10-02 19:27:21.023870 | localhost | Username: zuul 2025-10-02 19:27:21.023890 | localhost | Distro: CentOS 9 2025-10-02 19:27:21.023908 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 19:27:21.023925 | localhost | Region: RegionOne 2025-10-02 19:27:21.023958 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 19:27:21.023975 | localhost | Product Name: OpenStack Nova 2025-10-02 19:27:21.023991 | localhost | Interface IP: 38.102.83.188 2025-10-02 19:27:21.057222 | 2025-10-02 19:27:21.057373 | PLAY [all] 2025-10-02 19:27:21.066018 | 2025-10-02 19:27:21.066102 | TASK [Gather network facts] 2025-10-02 19:27:21.518282 | controller | ok 2025-10-02 19:27:21.562591 | 2025-10-02 19:27:21.562747 | TASK [include_role : start-zuul-console] 2025-10-02 19:27:21.603114 | controller | ok 2025-10-02 19:27:21.614651 | 2025-10-02 19:27:21.614740 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 19:27:22.030414 | controller | ok 2025-10-02 19:27:22.042343 | 2025-10-02 19:27:22.042427 | TASK [include_role : add-build-sshkey] 2025-10-02 19:27:22.073024 | controller | ok 2025-10-02 19:27:22.090144 | 2025-10-02 19:27:22.090209 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 19:27:22.299884 | controller -> localhost | ok 2025-10-02 19:27:22.307161 | 2025-10-02 19:27:22.307227 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 19:27:22.334690 | controller | ok 2025-10-02 19:27:22.347612 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 19:27:22.353247 | 2025-10-02 19:27:22.353305 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 19:27:22.846576 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 19:27:22.846863 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/97973c9df03d4fbb8b87ff1fae3f2b09_id_rsa. 2025-10-02 19:27:22.846897 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/97973c9df03d4fbb8b87ff1fae3f2b09_id_rsa.pub. 2025-10-02 19:27:22.846920 | controller -> localhost | The key fingerprint is: 2025-10-02 19:27:22.846940 | controller -> localhost | SHA256:8eqt2UnUSohUXB7wGe4UTaZssmJpt4FleZZqXKYaZdg zuul-build-sshkey 2025-10-02 19:27:22.846961 | controller -> localhost | The key's randomart image is: 2025-10-02 19:27:22.846980 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 19:27:22.846997 | controller -> localhost | | .oo=oo | 2025-10-02 19:27:22.847015 | controller -> localhost | | +.* O. | 2025-10-02 19:27:22.847033 | controller -> localhost | | o E / | 2025-10-02 19:27:22.847052 | controller -> localhost | | . X ^ . | 2025-10-02 19:27:22.847069 | controller -> localhost | | O S = . | 2025-10-02 19:27:22.847086 | controller -> localhost | | o * * . | 2025-10-02 19:27:22.847104 | controller -> localhost | | . o o | 2025-10-02 19:27:22.847124 | controller -> localhost | | . = . | 2025-10-02 19:27:22.847142 | controller -> localhost | | +.+ | 2025-10-02 19:27:22.847159 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 19:27:22.847208 | controller -> localhost | ok: Runtime: 0:00:00.089944 2025-10-02 19:27:22.853525 | 2025-10-02 19:27:22.853597 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 19:27:22.918875 | controller | ok 2025-10-02 19:27:22.944105 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 19:27:22.963467 | 2025-10-02 19:27:22.963585 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 19:27:22.987715 | controller | skipping: Conditional result was False 2025-10-02 19:27:22.995112 | 2025-10-02 19:27:22.995183 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 19:27:23.459366 | controller | changed 2025-10-02 19:27:23.466725 | 2025-10-02 19:27:23.466796 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 19:27:23.732768 | controller | ok 2025-10-02 19:27:23.739126 | 2025-10-02 19:27:23.739191 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 19:27:24.683609 | controller | changed 2025-10-02 19:27:24.689124 | 2025-10-02 19:27:24.689190 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 19:27:25.696211 | controller | changed 2025-10-02 19:27:25.701163 | 2025-10-02 19:27:25.701222 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 19:27:25.730131 | controller | skipping: Conditional result was False 2025-10-02 19:27:25.736127 | 2025-10-02 19:27:25.736191 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 19:27:26.126489 | controller -> localhost | changed 2025-10-02 19:27:26.136174 | 2025-10-02 19:27:26.136238 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 19:27:26.424949 | controller -> localhost | Identity added: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/97973c9df03d4fbb8b87ff1fae3f2b09_id_rsa (zuul-build-sshkey) 2025-10-02 19:27:26.425129 | controller -> localhost | ok: Runtime: 0:00:00.013265 2025-10-02 19:27:26.430793 | 2025-10-02 19:27:26.430852 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 19:27:26.820789 | controller | ok 2025-10-02 19:27:26.831217 | 2025-10-02 19:27:26.831347 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 19:27:26.868427 | controller | skipping: Conditional result was False 2025-10-02 19:27:26.890260 | 2025-10-02 19:27:26.890389 | TASK [include_role : validate-host] 2025-10-02 19:27:26.934226 | controller | ok 2025-10-02 19:27:26.970155 | 2025-10-02 19:27:26.970264 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 19:27:27.024351 | controller | ok 2025-10-02 19:27:27.036011 | 2025-10-02 19:27:27.036074 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 19:27:27.288565 | controller -> localhost | ok 2025-10-02 19:27:27.297990 | 2025-10-02 19:27:27.298354 | TASK [validate-host : Collect information about the host] 2025-10-02 19:27:28.213192 | controller | ok 2025-10-02 19:27:28.223529 | 2025-10-02 19:27:28.223657 | TASK [validate-host : Sanitize hostname] 2025-10-02 19:27:28.272270 | controller | ok 2025-10-02 19:27:28.277231 | 2025-10-02 19:27:28.277295 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 19:27:28.922788 | controller -> localhost | changed 2025-10-02 19:27:28.928646 | 2025-10-02 19:27:28.928740 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 19:27:29.419602 | controller | ok 2025-10-02 19:27:29.432150 | 2025-10-02 19:27:29.432222 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 19:27:29.959401 | controller -> localhost | changed 2025-10-02 19:27:29.972301 | 2025-10-02 19:27:29.972368 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 19:27:29.986212 | controller | skipping: Conditional result was False 2025-10-02 19:27:29.995617 | 2025-10-02 19:27:29.995753 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 19:27:30.033052 | controller | skipping: Conditional result was False 2025-10-02 19:27:30.038121 | 2025-10-02 19:27:30.038185 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 19:27:30.269287 | controller | ok: "logs" 2025-10-02 19:27:30.269518 | controller | ok: All items complete 2025-10-02 19:27:30.269547 | 2025-10-02 19:27:30.511217 | controller | ok: "artifacts" 2025-10-02 19:27:30.722225 | controller | ok: "docs" 2025-10-02 19:27:30.733749 | 2025-10-02 19:27:30.733877 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 19:27:30.986398 | controller | changed: "logs" 2025-10-02 19:27:31.223761 | controller | changed: "artifacts" 2025-10-02 19:27:31.472181 | controller | changed: "docs" 2025-10-02 19:27:31.507340 | 2025-10-02 19:27:31.507452 | PLAY RECAP 2025-10-02 19:27:31.507507 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 19:27:31.507541 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 19:27:31.507564 | 2025-10-02 19:27:31.616824 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 19:27:31.617602 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 19:27:32.234712 | 2025-10-02 19:27:32.234830 | PLAY [localhost] 2025-10-02 19:27:32.251080 | 2025-10-02 19:27:32.251153 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 19:27:32.655983 | localhost | ok 2025-10-02 19:27:32.663284 | 2025-10-02 19:27:32.663385 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 19:27:33.329311 | localhost | changed 2025-10-02 19:27:33.368713 | 2025-10-02 19:27:33.368786 | PLAY [all] 2025-10-02 19:27:33.389950 | 2025-10-02 19:27:33.390032 | TASK [include_role : prepare-workspace] 2025-10-02 19:27:33.432868 | controller | ok 2025-10-02 19:27:33.450138 | 2025-10-02 19:27:33.450203 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 19:27:33.914272 | controller | ok 2025-10-02 19:27:33.923157 | 2025-10-02 19:27:33.923258 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 19:27:35.923452 | controller | Output suppressed because no_log was given 2025-10-02 19:27:35.937335 | 2025-10-02 19:27:35.937424 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 19:27:36.215232 | controller | changed: "logs" 2025-10-02 19:27:36.430193 | controller | changed: "artifacts" 2025-10-02 19:27:36.690164 | controller | changed: "docs" 2025-10-02 19:27:36.708240 | 2025-10-02 19:27:36.708425 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 19:27:36.984794 | controller | changed: "logs" 2025-10-02 19:27:36.985059 | controller | changed: All items complete 2025-10-02 19:27:36.985093 | 2025-10-02 19:27:37.274913 | controller | changed: "artifacts" 2025-10-02 19:27:37.550867 | controller | changed: "docs" 2025-10-02 19:27:37.571571 | 2025-10-02 19:27:37.571701 | TASK [Check if worker can sudo] 2025-10-02 19:27:38.114980 | controller | ok: Runtime: 0:00:00.062443 2025-10-02 19:27:38.120780 | 2025-10-02 19:27:38.120845 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 19:27:38.175432 | controller | skipping: Conditional result was False 2025-10-02 19:27:38.181372 | 2025-10-02 19:27:38.181437 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 19:27:38.265590 | controller | ok 2025-10-02 19:27:38.274046 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 19:27:38.339102 | 2025-10-02 19:27:38.339221 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 19:27:38.615432 | controller | ok 2025-10-02 19:27:38.622917 | 2025-10-02 19:27:38.623070 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 19:27:38.695291 | controller | ok: "/var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 19:27:38.709352 | 2025-10-02 19:27:38.709470 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 19:27:39.714236 | controller | changed 2025-10-02 19:27:39.733186 | 2025-10-02 19:27:39.733320 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 19:27:39.820154 | controller | ok: "/var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 19:27:39.820443 | controller | ok: All items complete 2025-10-02 19:27:39.820500 | 2025-10-02 19:27:39.890022 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 19:27:39.899881 | 2025-10-02 19:27:39.900006 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 19:27:41.026510 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 19:27:41.954932 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 19:27:41.976869 | 2025-10-02 19:27:41.977034 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 19:27:42.406415 | controller | changed: section and option added 2025-10-02 19:27:42.425256 | 2025-10-02 19:27:42.425328 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 19:27:43.254512 | controller | 29 files removed 2025-10-02 19:27:43.255052 | controller | ok: Item: dnf clean all Runtime: 0:00:00.487193 2025-10-02 19:27:43.255150 | controller | changed: All items complete 2025-10-02 19:27:43.255197 | 2025-10-02 19:27:54.121217 | 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 19:27:54.121524 | controller | DNF version: 4.14.0 2025-10-02 19:27:54.121591 | controller | cachedir: /var/cache/dnf 2025-10-02 19:27:54.121636 | controller | Making cache files for all metadata files. 2025-10-02 19:27:54.121715 | controller | baseos: has expired and will be refreshed. 2025-10-02 19:27:54.121759 | controller | appstream: has expired and will be refreshed. 2025-10-02 19:27:54.121797 | controller | crb: has expired and will be refreshed. 2025-10-02 19:27:54.121851 | controller | extras-common: has expired and will be refreshed. 2025-10-02 19:27:54.121889 | controller | repo: downloading from remote: baseos 2025-10-02 19:27:54.121926 | controller | CentOS Stream 9 - BaseOS 65 MB/s | 8.8 MB 00:00 2025-10-02 19:27:54.121963 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 19:27:54.122000 | controller | repo: downloading from remote: appstream 2025-10-02 19:27:54.122036 | controller | CentOS Stream 9 - AppStream 76 MB/s | 25 MB 00:00 2025-10-02 19:27:54.122072 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 19:27:54.122108 | controller | repo: downloading from remote: crb 2025-10-02 19:27:54.122144 | controller | CentOS Stream 9 - CRB 96 MB/s | 7.1 MB 00:00 2025-10-02 19:27:54.122182 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 19:27:54.122219 | controller | repo: downloading from remote: extras-common 2025-10-02 19:27:54.122256 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-10-02 19:27:54.122292 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 19:27:54.122328 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 19:27:54.122365 | controller | Completion plugin: Generating completion cache... 2025-10-02 19:27:54.122402 | controller | Metadata cache created. 2025-10-02 19:27:54.122457 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.561948 2025-10-02 19:27:54.155091 | 2025-10-02 19:27:54.155255 | PLAY RECAP 2025-10-02 19:27:54.155343 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 19:27:54.155398 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 19:27:54.155437 | 2025-10-02 19:27:54.287034 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 19:27:54.288756 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 19:27:54.863204 | 2025-10-02 19:27:54.863309 | PLAY [all] 2025-10-02 19:27:54.883366 | 2025-10-02 19:27:54.883441 | TASK [Install binary dependencies] 2025-10-02 19:27:54.954774 | controller | ok 2025-10-02 19:27:54.980160 | 2025-10-02 19:27:54.980289 | TASK [bindep : Include find tasks] 2025-10-02 19:27:55.012870 | controller | ok 2025-10-02 19:27:55.023110 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 19:27:55.031464 | 2025-10-02 19:27:55.031553 | TASK [bindep : Look for bindep.txt] 2025-10-02 19:27:55.488998 | controller | ok 2025-10-02 19:27:55.499222 | 2025-10-02 19:27:55.499316 | TASK [bindep : Define bindep_file fact] 2025-10-02 19:27:55.531250 | controller | ok 2025-10-02 19:27:55.538136 | 2025-10-02 19:27:55.538223 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 19:27:55.553487 | controller | skipping: Conditional result was False 2025-10-02 19:27:55.562562 | 2025-10-02 19:27:55.562656 | TASK [bindep : Define bindep_file fact] 2025-10-02 19:27:55.587374 | controller | skipping: Conditional result was False 2025-10-02 19:27:55.595241 | 2025-10-02 19:27:55.595329 | TASK [bindep : Look for bindep fallback file] 2025-10-02 19:27:55.619896 | controller | skipping: Conditional result was False 2025-10-02 19:27:55.627653 | 2025-10-02 19:27:55.627758 | TASK [bindep : Define bindep_file fact] 2025-10-02 19:27:55.653359 | controller | skipping: Conditional result was False 2025-10-02 19:27:55.660754 | 2025-10-02 19:27:55.660842 | TASK [bindep : Include bindep tasks] 2025-10-02 19:27:55.703595 | controller | ok 2025-10-02 19:27:55.717529 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 19:27:55.728642 | 2025-10-02 19:27:55.728755 | TASK [bindep : Look for bindep command] 2025-10-02 19:27:55.762384 | controller | skipping: Conditional result was False 2025-10-02 19:27:55.769096 | 2025-10-02 19:27:55.769158 | TASK [bindep : Check for system bindep] 2025-10-02 19:27:56.305277 | controller | ok: Runtime: 0:00:00.010914 2025-10-02 19:27:56.317257 | 2025-10-02 19:27:56.317392 | TASK [bindep : Define bindep_command fact] 2025-10-02 19:27:56.358203 | controller | skipping: Conditional result was False 2025-10-02 19:27:56.375970 | 2025-10-02 19:27:56.376134 | TASK [bindep : Include install tasks] 2025-10-02 19:27:56.419132 | controller | ok 2025-10-02 19:27:56.429172 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 19:27:56.441175 | 2025-10-02 19:27:56.441258 | TASK [bindep : Create temp dir for bindep] 2025-10-02 19:27:56.787967 | controller | changed 2025-10-02 19:27:56.795915 | 2025-10-02 19:27:56.795997 | TASK [Ensure we have pip dependencies] 2025-10-02 19:27:56.827528 | controller | ok 2025-10-02 19:27:56.863466 | 2025-10-02 19:27:56.863588 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 15:27:57.142890 | controller | /usr/bin/pip3 2025-10-02 15:27:57.171826 | controller | /usr/bin/python3: No module named wheel 2025-10-02 19:27:57.392546 | controller | ok: Runtime: 0:00:00.042068 2025-10-02 19:27:57.398210 | 2025-10-02 19:27:57.398272 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 19:27:57.430605 | controller | ok: "/var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 19:27:57.441295 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 19:27:57.452171 | 2025-10-02 19:27:57.452229 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 19:27:59.845635 | controller | changed 2025-10-02 19:27:59.857983 | 2025-10-02 19:27:59.858069 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 19:27:59.903274 | controller | skipping: Conditional result was False 2025-10-02 19:27:59.914755 | 2025-10-02 19:27:59.915061 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 19:27:59.962630 | controller | skipping: Conditional result was False 2025-10-02 19:27:59.971494 | 2025-10-02 19:27:59.971580 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 19:28:00.007391 | controller | skipping: Conditional result was False 2025-10-02 19:28:00.017347 | 2025-10-02 19:28:00.017441 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 19:28:00.032267 | controller | skipping: Conditional result was False 2025-10-02 19:28:00.041219 | 2025-10-02 19:28:00.041305 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 19:28:00.579836 | controller | skipping: Conditional result was False 2025-10-02 19:28:00.586344 | 2025-10-02 19:28:00.586409 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 19:28:00.610603 | controller | skipping: Conditional result was False 2025-10-02 19:28:00.617739 | 2025-10-02 19:28:00.617808 | TASK [ensure-pip : Install pip from source] 2025-10-02 19:28:00.642380 | controller | skipping: Conditional result was False 2025-10-02 19:28:00.648850 | 2025-10-02 19:28:00.648978 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 15:28:00.928139 | controller | /usr/bin/python3 2025-10-02 19:28:01.186625 | controller | ok: Runtime: 0:00:00.005107 2025-10-02 19:28:01.198995 | 2025-10-02 19:28:01.199126 | TASK [ensure-pip : Set host default] 2025-10-02 19:28:01.248197 | controller | ok 2025-10-02 19:28:01.262330 | 2025-10-02 19:28:01.262462 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 19:28:01.307176 | controller | ok 2025-10-02 19:28:01.321190 | 2025-10-02 19:28:01.321273 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 19:28:05.454430 | controller | changed 2025-10-02 19:28:05.466150 | 2025-10-02 19:28:05.466281 | TASK [bindep : Define bindep_command] 2025-10-02 19:28:05.506048 | controller | ok 2025-10-02 19:28:05.519906 | 2025-10-02 19:28:05.520114 | LOOP [bindep : Include package tasks] 2025-10-02 19:28:05.585386 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 19:28:05.585597 | controller | ok: All items complete 2025-10-02 19:28:05.585632 | 2025-10-02 19:28:05.606195 | controller | included: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 19:28:05.621801 | 2025-10-02 19:28:05.621885 | TASK [bindep : Define bindep_run fact] 2025-10-02 19:28:05.652052 | controller | ok 2025-10-02 19:28:05.657135 | 2025-10-02 19:28:05.657202 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 15:28:07.031106 | controller | podman 2025-10-02 15:28:07.063341 | controller | python3-jmespath 2025-10-02 15:28:07.063407 | controller | python3-libvirt 2025-10-02 15:28:07.063414 | controller | python3-lxml 2025-10-02 15:28:07.063424 | controller | python3-netaddr 2025-10-02 19:28:07.193163 | controller | ok: Runtime: 0:00:01.123830 2025-10-02 19:28:07.204934 | 2025-10-02 19:28:07.205067 | TASK [bindep : Install distro packages from bindep] 2025-10-02 19:29:09.875501 | controller | changed 2025-10-02 19:29:09.887254 | 2025-10-02 19:29:09.887325 | TASK [bindep : Check that packages are installed] 2025-10-02 19:29:11.469807 | controller | ok: Runtime: 0:00:01.029528 2025-10-02 19:29:11.481436 | 2025-10-02 19:29:11.481568 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 19:29:11.509302 | controller | skipping: Conditional result was False 2025-10-02 19:29:11.531849 | 2025-10-02 19:29:11.531941 | TASK [Run test-setup role] 2025-10-02 19:29:11.552922 | controller | ok 2025-10-02 19:29:11.575054 | 2025-10-02 19:29:11.575138 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 19:29:11.804701 | controller | ok 2025-10-02 19:29:11.815534 | 2025-10-02 19:29:11.815698 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 19:29:12.362480 | controller | skipping: Conditional result was False 2025-10-02 19:29:12.404317 | 2025-10-02 19:29:12.404419 | TASK [bindep : Remove bindep temp dir] 2025-10-02 19:29:12.769253 | controller | ok 2025-10-02 19:29:12.793464 | 2025-10-02 19:29:12.793542 | PLAY RECAP 2025-10-02 19:29:12.793601 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 19:29:12.793637 | 2025-10-02 19:29:12.902236 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 19:29:12.903961 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 19:29:13.513568 | 2025-10-02 19:29:13.513700 | PLAY [all] 2025-10-02 19:29:13.532817 | 2025-10-02 19:29:13.532931 | TASK [Abort when test_command variable is undefined] 2025-10-02 19:29:13.577350 | controller | skipping: Conditional result was False 2025-10-02 19:29:13.582935 | 2025-10-02 19:29:13.583006 | TASK [Convert test_command to list] 2025-10-02 19:29:13.616797 | controller | skipping: Conditional result was False 2025-10-02 19:29:13.625465 | 2025-10-02 19:29:13.625564 | TASK [Use test_command list] 2025-10-02 19:29:13.677751 | controller | ok 2025-10-02 19:29:13.687697 | 2025-10-02 19:29:13.687785 | LOOP [Run test_command] 2025-10-02 19:29:14.103229 | controller | no check to run 2025-10-02 19:29:14.103535 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008322 2025-10-02 19:29:14.139923 | 2025-10-02 19:29:14.140058 | PLAY RECAP 2025-10-02 19:29:14.140114 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 19:29:14.140143 | 2025-10-02 19:29:14.248272 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 19:29:14.250009 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 19:29:14.837757 | 2025-10-02 19:29:14.837868 | PLAY [all] 2025-10-02 19:29:14.857880 | 2025-10-02 19:29:14.857958 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 19:29:15.276030 | controller | changed: non-zero return code 2025-10-02 19:29:15.287776 | 2025-10-02 19:29:15.287930 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 19:29:15.315968 | controller | skipping: Conditional result was False 2025-10-02 19:29:15.327882 | 2025-10-02 19:29:15.328027 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 19:29:15.369434 | 2025-10-02 19:29:15.369725 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 19:29:15.408908 | 2025-10-02 19:29:15.409178 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 19:29:15.436885 | controller | skipping: Conditional result was False 2025-10-02 19:29:15.449776 | 2025-10-02 19:29:15.449937 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 19:29:15.491250 | 2025-10-02 19:29:15.491493 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 19:29:15.518559 | controller | skipping: Conditional result was False 2025-10-02 19:29:15.530727 | 2025-10-02 19:29:15.530871 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 19:29:15.567856 | controller | skipping: Conditional result was False 2025-10-02 19:29:15.580588 | 2025-10-02 19:29:15.580797 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 19:29:15.607524 | controller | skipping: Conditional result was False 2025-10-02 19:29:15.643353 | 2025-10-02 19:29:15.643437 | PLAY RECAP 2025-10-02 19:29:15.643493 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 19:29:15.643520 | 2025-10-02 19:29:15.730182 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 19:29:15.731000 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 19:29:16.279214 | 2025-10-02 19:29:16.279316 | PLAY [all] 2025-10-02 19:29:16.312856 | 2025-10-02 19:29:16.312928 | TASK [include_role : fetch-output] 2025-10-02 19:29:16.341559 | controller | ok 2025-10-02 19:29:16.359830 | 2025-10-02 19:29:16.359914 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 19:29:16.424372 | controller | skipping: Conditional result was False 2025-10-02 19:29:16.430383 | 2025-10-02 19:29:16.430451 | TASK [fetch-output : Set log path for single node] 2025-10-02 19:29:16.464748 | controller | ok 2025-10-02 19:29:16.470557 | 2025-10-02 19:29:16.470625 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 19:29:16.833976 | controller -> localhost | ok: "/var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/logs" 2025-10-02 19:29:17.033975 | controller -> localhost | changed: "/var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/artifacts" 2025-10-02 19:29:17.235329 | controller -> localhost | changed: "/var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/docs" 2025-10-02 19:29:17.244849 | 2025-10-02 19:29:17.245052 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 19:29:17.861921 | controller | changed: .d..t...... ./ 2025-10-02 19:29:17.862123 | controller | changed: All items complete 2025-10-02 19:29:17.862225 | 2025-10-02 19:29:18.300527 | controller | changed: .d..t...... ./ 2025-10-02 19:29:18.710233 | controller | changed: .d..t...... ./ 2025-10-02 19:29:18.724362 | 2025-10-02 19:29:18.724499 | TASK [include_role : fetch-output-openshift] 2025-10-02 19:29:18.769180 | controller | skipping: Conditional result was False 2025-10-02 19:29:18.775491 | 2025-10-02 19:29:18.775559 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 19:29:19.356364 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.029844 2025-10-02 19:29:19.649622 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.025505 2025-10-02 19:29:19.696707 | 2025-10-02 19:29:19.696819 | PLAY [all] 2025-10-02 19:29:19.715944 | 2025-10-02 19:29:19.716033 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 19:29:20.192218 | controller | changed 2025-10-02 19:29:20.232401 | 2025-10-02 19:29:20.232479 | PLAY RECAP 2025-10-02 19:29:20.232521 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 19:29:20.232541 | 2025-10-02 19:29:20.417024 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 19:29:20.417878 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 19:29:21.100551 | 2025-10-02 19:29:21.100656 | PLAY [localhost] 2025-10-02 19:29:21.118597 | 2025-10-02 19:29:21.118693 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 19:29:21.461418 | localhost | changed 2025-10-02 19:29:21.466139 | 2025-10-02 19:29:21.466213 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 19:29:21.495850 | localhost | ok 2025-10-02 19:29:21.506089 | 2025-10-02 19:29:21.506154 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 19:29:21.929421 | localhost | changed 2025-10-02 19:29:21.935473 | 2025-10-02 19:29:21.935552 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 19:29:22.639971 | localhost | changed 2025-10-02 19:29:22.645030 | 2025-10-02 19:29:22.645093 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 19:29:23.012685 | localhost | Identity added: /var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/tmp/ansible._9qfs_pv (/var/lib/zuul/builds/97973c9df03d4fbb8b87ff1fae3f2b09/work/tmp/ansible._9qfs_pv) 2025-10-02 19:29:23.012884 | localhost | ok: Runtime: 0:00:00.007507 2025-10-02 19:29:23.017176 | 2025-10-02 19:29:23.017242 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 19:29:23.269053 | localhost | ok: Runtime: 0:00:00.008883 2025-10-02 19:29:23.275722 | 2025-10-02 19:29:23.276067 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 19:29:23.345023 | localhost | changed 2025-10-02 19:29:23.365972 | 2025-10-02 19:29:23.366125 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 19:29:23.774287 | localhost | changed 2025-10-02 19:29:23.797945 | 2025-10-02 19:29:23.798017 | PLAY [localhost] 2025-10-02 19:29:23.810360 | 2025-10-02 19:29:23.810419 | TASK [Generate bulk log download script] 2025-10-02 19:29:23.829462 | localhost | ok 2025-10-02 19:29:23.840831 | 2025-10-02 19:29:23.840892 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 19:29:23.869005 | localhost | ok: All assertions passed 2025-10-02 19:29:23.873725 | 2025-10-02 19:29:23.873792 | TASK [local-log-download : Create download script] 2025-10-02 19:29:24.292229 | localhost -> localhost | changed 2025-10-02 19:29:24.313479 | 2025-10-02 19:29:24.313618 | TASK [Register quick-download link] 2025-10-02 19:29:24.335234 | localhost | ok 2025-10-02 19:29:24.386727 | 2025-10-02 19:29:24.386829 | PLAY [logserver.rdoproject.org] 2025-10-02 19:29:24.396231 | 2025-10-02 19:29:24.396290 | TASK [Set zuul-log-path fact] 2025-10-02 19:29:24.412353 | logserver.rdoproject.org | ok 2025-10-02 19:29:24.421040 | 2025-10-02 19:29:24.421129 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 19:29:24.457300 | logserver.rdoproject.org | ok 2025-10-02 19:29:24.462990 | 2025-10-02 19:29:24.463048 | TASK [upload-logs : Create log directories] 2025-10-02 19:29:25.212529 | logserver.rdoproject.org | changed 2025-10-02 19:29:25.215894 | 2025-10-02 19:29:25.215956 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 19:29:25.538697 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006873 2025-10-02 19:29:25.543702 | 2025-10-02 19:29:25.543764 | TASK [upload-logs : Upload logs to log server] 2025-10-02 19:29:26.140771 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 19:29:26.143648 | 2025-10-02 19:29:26.143731 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 19:29:26.192780 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:29:26.193519 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:29:26.201316 | 2025-10-02 19:29:26.201435 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 19:29:26.241326 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:29:26.241554 | 2025-10-02 19:29:26.242112 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 19:29:26.248317 | 2025-10-02 19:29:26.248503 | LOOP [upload-logs : Upload console log and json output]