2025-10-03 12:56:20.803154 | Job console starting... 2025-10-03 12:56:20.819344 | Updating repositories 2025-10-03 12:56:20.850009 | Preparing job workspace 2025-10-03 12:56:24.781588 | Running Ansible setup... 2025-10-03 12:56:28.772995 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 12:56:29.426279 | 2025-10-03 12:56:29.426407 | PLAY [localhost] 2025-10-03 12:56:29.435917 | 2025-10-03 12:56:29.436001 | TASK [Gathering Facts] 2025-10-03 12:56:30.459266 | localhost | ok 2025-10-03 12:56:30.486203 | 2025-10-03 12:56:30.486336 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-03 12:56:30.911927 | localhost -> localhost | changed 2025-10-03 12:56:30.924156 | 2025-10-03 12:56:30.924313 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-03 12:56:31.786618 | localhost -> localhost | changed 2025-10-03 12:56:31.817202 | 2025-10-03 12:56:31.817350 | TASK [Setup log path fact] 2025-10-03 12:56:31.834745 | localhost | ok 2025-10-03 12:56:31.858563 | 2025-10-03 12:56:31.858732 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 12:56:31.886225 | localhost | ok 2025-10-03 12:56:31.893952 | 2025-10-03 12:56:31.894020 | TASK [emit-job-header : Print job information] 2025-10-03 12:56:31.921724 | # Job Information 2025-10-03 12:56:31.921966 | Ansible Version: 2.15.12 2025-10-03 12:56:31.921994 | Job: cifmw-molecule-cifmw_external_dns 2025-10-03 12:56:31.922014 | Pipeline: github-check 2025-10-03 12:56:31.922032 | Executor: ze02.softwarefactory-project.io 2025-10-03 12:56:31.922049 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366 2025-10-03 12:56:31.922067 | Log URL (when completed): https://logserver.rdoproject.org/223/rdoproject.org/2239728f6bb649bd9040046ba425b3bf/ 2025-10-03 12:56:31.922085 | Event ID: 2f17a3d0-a058-11f0-9c81-07e47aea193a 2025-10-03 12:56:31.926497 | 2025-10-03 12:56:31.926629 | LOOP [emit-job-header : Print node information] 2025-10-03 12:56:32.035956 | localhost | ok: 2025-10-03 12:56:32.036111 | localhost | # Node Information 2025-10-03 12:56:32.036140 | localhost | Inventory Hostname: controller 2025-10-03 12:56:32.036163 | localhost | Hostname: np0005469089 2025-10-03 12:56:32.036183 | localhost | Username: zuul 2025-10-03 12:56:32.036204 | localhost | Distro: CentOS 9 2025-10-03 12:56:32.036221 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-03 12:56:32.036240 | localhost | Region: RegionOne 2025-10-03 12:56:32.036257 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-03 12:56:32.036274 | localhost | Product Name: OpenStack Nova 2025-10-03 12:56:32.036291 | localhost | Interface IP: 38.102.83.246 2025-10-03 12:56:32.067104 | 2025-10-03 12:56:32.067206 | PLAY [all] 2025-10-03 12:56:32.083927 | 2025-10-03 12:56:32.084020 | TASK [Gather network facts] 2025-10-03 12:56:32.586741 | controller | ok 2025-10-03 12:56:32.608411 | 2025-10-03 12:56:32.608535 | TASK [include_role : start-zuul-console] 2025-10-03 12:56:32.632415 | controller | ok 2025-10-03 12:56:32.650830 | 2025-10-03 12:56:32.650929 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-03 12:56:33.126281 | controller | ok 2025-10-03 12:56:33.135546 | 2025-10-03 12:56:33.135620 | TASK [include_role : add-build-sshkey] 2025-10-03 12:56:33.157509 | controller | ok 2025-10-03 12:56:33.170556 | 2025-10-03 12:56:33.170623 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-03 12:56:33.475982 | controller -> localhost | ok 2025-10-03 12:56:33.483590 | 2025-10-03 12:56:33.483655 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-03 12:56:33.504608 | controller | ok 2025-10-03 12:56:33.523011 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-03 12:56:33.529801 | 2025-10-03 12:56:33.529866 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-03 12:56:34.200369 | controller -> localhost | Generating public/private rsa key pair. 2025-10-03 12:56:34.200568 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/2239728f6bb649bd9040046ba425b3bf_id_rsa. 2025-10-03 12:56:34.200600 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/2239728f6bb649bd9040046ba425b3bf_id_rsa.pub. 2025-10-03 12:56:34.200623 | controller -> localhost | The key fingerprint is: 2025-10-03 12:56:34.200643 | controller -> localhost | SHA256:22a0wUXRQuNf02rW6MG13Owx9eww7gLhJbdNwLfb9mI zuul-build-sshkey 2025-10-03 12:56:34.200682 | controller -> localhost | The key's randomart image is: 2025-10-03 12:56:34.200708 | controller -> localhost | +---[RSA 3072]----+ 2025-10-03 12:56:34.200727 | controller -> localhost | | o=o | 2025-10-03 12:56:34.200745 | controller -> localhost | | o+.o .| 2025-10-03 12:56:34.200763 | controller -> localhost | | o+ o=| 2025-10-03 12:56:34.200780 | controller -> localhost | | .o.oo+O*| 2025-10-03 12:56:34.200797 | controller -> localhost | | S.+= +@B*| 2025-10-03 12:56:34.200814 | controller -> localhost | | +oo.=o*=| 2025-10-03 12:56:34.200831 | controller -> localhost | | . =. o.+| 2025-10-03 12:56:34.200849 | controller -> localhost | | o ..E .| 2025-10-03 12:56:34.200866 | controller -> localhost | | o.. | 2025-10-03 12:56:34.200883 | controller -> localhost | +----[SHA256]-----+ 2025-10-03 12:56:34.200925 | controller -> localhost | ok: Runtime: 0:00:00.297402 2025-10-03 12:56:34.206601 | 2025-10-03 12:56:34.206681 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-03 12:56:34.238332 | controller | ok 2025-10-03 12:56:34.259430 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-03 12:56:34.279136 | 2025-10-03 12:56:34.279247 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-03 12:56:34.309833 | controller | skipping: Conditional result was False 2025-10-03 12:56:34.316430 | 2025-10-03 12:56:34.316497 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-03 12:56:34.839547 | controller | changed 2025-10-03 12:56:34.845904 | 2025-10-03 12:56:34.845970 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-03 12:56:35.122149 | controller | ok 2025-10-03 12:56:35.140082 | 2025-10-03 12:56:35.140179 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-03 12:56:35.992287 | controller | changed 2025-10-03 12:56:35.997550 | 2025-10-03 12:56:35.997613 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-03 12:56:36.868831 | controller | changed 2025-10-03 12:56:36.874140 | 2025-10-03 12:56:36.874202 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-03 12:56:36.898627 | controller | skipping: Conditional result was False 2025-10-03 12:56:36.904324 | 2025-10-03 12:56:36.904388 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-03 12:56:37.264135 | controller -> localhost | changed 2025-10-03 12:56:37.284801 | 2025-10-03 12:56:37.284940 | TASK [add-build-sshkey : Add back temp key] 2025-10-03 12:56:37.597108 | controller -> localhost | Identity added: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/2239728f6bb649bd9040046ba425b3bf_id_rsa (zuul-build-sshkey) 2025-10-03 12:56:37.597530 | controller -> localhost | ok: Runtime: 0:00:00.015751 2025-10-03 12:56:37.609697 | 2025-10-03 12:56:37.609836 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-03 12:56:37.995146 | controller | ok 2025-10-03 12:56:37.999954 | 2025-10-03 12:56:38.000017 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-03 12:56:38.034365 | controller | skipping: Conditional result was False 2025-10-03 12:56:38.043873 | 2025-10-03 12:56:38.043940 | TASK [include_role : validate-host] 2025-10-03 12:56:38.072773 | controller | ok 2025-10-03 12:56:38.092035 | 2025-10-03 12:56:38.092113 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-03 12:56:38.120508 | controller | ok 2025-10-03 12:56:38.125341 | 2025-10-03 12:56:38.125398 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-03 12:56:38.376067 | controller -> localhost | ok 2025-10-03 12:56:38.390985 | 2025-10-03 12:56:38.391119 | TASK [validate-host : Collect information about the host] 2025-10-03 12:56:39.247305 | controller | ok 2025-10-03 12:56:39.267745 | 2025-10-03 12:56:39.267881 | TASK [validate-host : Sanitize hostname] 2025-10-03 12:56:39.360369 | controller | ok 2025-10-03 12:56:39.367251 | 2025-10-03 12:56:39.367342 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-03 12:56:39.780553 | controller -> localhost | changed 2025-10-03 12:56:39.786219 | 2025-10-03 12:56:39.786280 | TASK [validate-host : Collect information about zuul worker] 2025-10-03 12:56:41.867759 | controller | ok 2025-10-03 12:56:41.874590 | 2025-10-03 12:56:41.874652 | TASK [validate-host : Write out all zuul information for each host] 2025-10-03 12:56:42.397271 | controller -> localhost | changed 2025-10-03 12:56:42.407516 | 2025-10-03 12:56:42.407588 | TASK [include_role : prepare-workspace-openshift] 2025-10-03 12:56:42.421528 | controller | skipping: Conditional result was False 2025-10-03 12:56:42.428077 | 2025-10-03 12:56:42.428187 | TASK [include_role : remove-zuul-sshkey] 2025-10-03 12:56:42.455457 | controller | skipping: Conditional result was False 2025-10-03 12:56:42.460994 | 2025-10-03 12:56:42.461066 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 12:56:42.711923 | controller | ok: "logs" 2025-10-03 12:56:42.712194 | controller | ok: All items complete 2025-10-03 12:56:42.712226 | 2025-10-03 12:56:43.193604 | controller | ok: "artifacts" 2025-10-03 12:56:43.500397 | controller | ok: "docs" 2025-10-03 12:56:43.517331 | 2025-10-03 12:56:43.517457 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 12:56:43.926076 | controller | changed: "logs" 2025-10-03 12:56:44.164131 | controller | changed: "artifacts" 2025-10-03 12:56:44.390851 | controller | changed: "docs" 2025-10-03 12:56:44.437567 | 2025-10-03 12:56:44.437656 | PLAY RECAP 2025-10-03 12:56:44.437721 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-03 12:56:44.437748 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 12:56:44.437766 | 2025-10-03 12:56:44.553115 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 12:56:44.554135 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 12:56:45.188775 | 2025-10-03 12:56:45.188948 | PLAY [localhost] 2025-10-03 12:56:45.205534 | 2025-10-03 12:56:45.205611 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-03 12:56:45.592156 | localhost | ok 2025-10-03 12:56:45.598772 | 2025-10-03 12:56:45.598855 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-03 12:56:46.242310 | localhost | changed 2025-10-03 12:56:46.286585 | 2025-10-03 12:56:46.286692 | PLAY [all] 2025-10-03 12:56:46.304551 | 2025-10-03 12:56:46.304631 | TASK [include_role : prepare-workspace] 2025-10-03 12:56:46.334208 | controller | ok 2025-10-03 12:56:46.353008 | 2025-10-03 12:56:46.353126 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-03 12:56:46.798599 | controller | ok 2025-10-03 12:56:46.804790 | 2025-10-03 12:56:46.804855 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-03 12:56:48.982830 | controller | Output suppressed because no_log was given 2025-10-03 12:56:48.996840 | 2025-10-03 12:56:48.996933 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 12:56:49.302989 | controller | changed: "logs" 2025-10-03 12:56:49.601442 | controller | changed: "artifacts" 2025-10-03 12:56:49.857744 | controller | changed: "docs" 2025-10-03 12:56:49.867190 | 2025-10-03 12:56:49.867318 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 12:56:50.234490 | controller | changed: "logs" 2025-10-03 12:56:50.234758 | controller | changed: All items complete 2025-10-03 12:56:50.234786 | 2025-10-03 12:56:50.634698 | controller | changed: "artifacts" 2025-10-03 12:56:50.865840 | controller | changed: "docs" 2025-10-03 12:56:50.892027 | 2025-10-03 12:56:50.892179 | TASK [Check if worker can sudo] 2025-10-03 12:56:51.939914 | controller | ok: Runtime: 0:00:00.102910 2025-10-03 12:56:51.945946 | 2025-10-03 12:56:51.946162 | TASK [configure-mirrors : Gather needed facts] 2025-10-03 12:56:52.062890 | controller | skipping: Conditional result was False 2025-10-03 12:56:52.069817 | 2025-10-03 12:56:52.070028 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-03 12:56:52.217640 | controller | ok 2025-10-03 12:56:52.317711 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-03 12:56:52.338336 | 2025-10-03 12:56:52.338570 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-03 12:56:52.681914 | controller | ok 2025-10-03 12:56:52.699835 | 2025-10-03 12:56:52.699965 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-03 12:56:52.831426 | controller | ok: "/var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-03 12:56:52.847428 | 2025-10-03 12:56:52.847613 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-03 12:56:53.917367 | controller | changed 2025-10-03 12:56:53.922803 | 2025-10-03 12:56:53.922868 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-03 12:56:53.980878 | controller | ok: "/var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-03 12:56:53.981103 | controller | ok: All items complete 2025-10-03 12:56:53.981131 | 2025-10-03 12:56:54.035210 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-03 12:56:54.045416 | 2025-10-03 12:56:54.045534 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-03 12:56:55.027085 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-03 12:56:55.754721 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-03 12:56:55.762477 | 2025-10-03 12:56:55.762591 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-03 12:56:56.224327 | controller | changed: section and option added 2025-10-03 12:56:56.244537 | 2025-10-03 12:56:56.244701 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-03 12:56:57.055479 | controller | 29 files removed 2025-10-03 12:56:57.055723 | controller | ok: Item: dnf clean all Runtime: 0:00:00.486477 2025-10-03 12:56:57.055766 | controller | changed: All items complete 2025-10-03 12:56:57.055787 | 2025-10-03 12:57:08.669532 | 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-03 12:57:08.669706 | controller | DNF version: 4.14.0 2025-10-03 12:57:08.669745 | controller | cachedir: /var/cache/dnf 2025-10-03 12:57:08.669772 | controller | Making cache files for all metadata files. 2025-10-03 12:57:08.669796 | controller | baseos: has expired and will be refreshed. 2025-10-03 12:57:08.669819 | controller | appstream: has expired and will be refreshed. 2025-10-03 12:57:08.669842 | controller | crb: has expired and will be refreshed. 2025-10-03 12:57:08.670017 | controller | extras-common: has expired and will be refreshed. 2025-10-03 12:57:08.670058 | controller | repo: downloading from remote: baseos 2025-10-03 12:57:08.670083 | controller | CentOS Stream 9 - BaseOS 61 MB/s | 8.8 MB 00:00 2025-10-03 12:57:08.670108 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-03 12:57:08.670131 | controller | repo: downloading from remote: appstream 2025-10-03 12:57:08.670154 | controller | CentOS Stream 9 - AppStream 69 MB/s | 25 MB 00:00 2025-10-03 12:57:08.670176 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-03 12:57:08.670199 | controller | repo: downloading from remote: crb 2025-10-03 12:57:08.670221 | controller | CentOS Stream 9 - CRB 64 MB/s | 7.1 MB 00:00 2025-10-03 12:57:08.670245 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-03 12:57:08.670267 | controller | repo: downloading from remote: extras-common 2025-10-03 12:57:08.670290 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-10-03 12:57:08.670313 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-03 12:57:08.670336 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-03 12:57:08.670359 | controller | Completion plugin: Generating completion cache... 2025-10-03 12:57:08.670381 | controller | Metadata cache created. 2025-10-03 12:57:08.670417 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.328726 2025-10-03 12:57:08.690216 | 2025-10-03 12:57:08.690371 | PLAY RECAP 2025-10-03 12:57:08.690421 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-03 12:57:08.690447 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 12:57:08.690465 | 2025-10-03 12:57:08.853569 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 12:57:08.854736 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 12:57:09.438708 | 2025-10-03 12:57:09.438819 | PLAY [all] 2025-10-03 12:57:09.460243 | 2025-10-03 12:57:09.460331 | TASK [Install binary dependencies] 2025-10-03 12:57:09.531603 | controller | ok 2025-10-03 12:57:09.551907 | 2025-10-03 12:57:09.551993 | TASK [bindep : Include find tasks] 2025-10-03 12:57:09.584837 | controller | ok 2025-10-03 12:57:09.592525 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-03 12:57:09.598855 | 2025-10-03 12:57:09.598920 | TASK [bindep : Look for bindep.txt] 2025-10-03 12:57:09.989572 | controller | ok 2025-10-03 12:57:09.996735 | 2025-10-03 12:57:09.996811 | TASK [bindep : Define bindep_file fact] 2025-10-03 12:57:10.057248 | controller | ok 2025-10-03 12:57:10.063106 | 2025-10-03 12:57:10.063180 | TASK [bindep : Look for other-requirements.txt] 2025-10-03 12:57:10.087744 | controller | skipping: Conditional result was False 2025-10-03 12:57:10.094546 | 2025-10-03 12:57:10.094616 | TASK [bindep : Define bindep_file fact] 2025-10-03 12:57:10.122300 | controller | skipping: Conditional result was False 2025-10-03 12:57:10.132797 | 2025-10-03 12:57:10.132872 | TASK [bindep : Look for bindep fallback file] 2025-10-03 12:57:10.158469 | controller | skipping: Conditional result was False 2025-10-03 12:57:10.168629 | 2025-10-03 12:57:10.168749 | TASK [bindep : Define bindep_file fact] 2025-10-03 12:57:10.196828 | controller | skipping: Conditional result was False 2025-10-03 12:57:10.204278 | 2025-10-03 12:57:10.204357 | TASK [bindep : Include bindep tasks] 2025-10-03 12:57:10.239615 | controller | ok 2025-10-03 12:57:10.246797 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-03 12:57:10.256449 | 2025-10-03 12:57:10.256510 | TASK [bindep : Look for bindep command] 2025-10-03 12:57:10.281133 | controller | skipping: Conditional result was False 2025-10-03 12:57:10.287879 | 2025-10-03 12:57:10.287943 | TASK [bindep : Check for system bindep] 2025-10-03 12:57:10.818972 | controller | ok: Runtime: 0:00:00.005816 2025-10-03 12:57:10.825114 | 2025-10-03 12:57:10.825176 | TASK [bindep : Define bindep_command fact] 2025-10-03 12:57:10.861025 | controller | skipping: Conditional result was False 2025-10-03 12:57:10.867248 | 2025-10-03 12:57:10.867317 | TASK [bindep : Include install tasks] 2025-10-03 12:57:10.907237 | controller | ok 2025-10-03 12:57:10.919342 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-03 12:57:10.931524 | 2025-10-03 12:57:10.931587 | TASK [bindep : Create temp dir for bindep] 2025-10-03 12:57:11.337384 | controller | changed 2025-10-03 12:57:11.342660 | 2025-10-03 12:57:11.342736 | TASK [Ensure we have pip dependencies] 2025-10-03 12:57:11.361538 | controller | ok 2025-10-03 12:57:11.384792 | 2025-10-03 12:57:11.384860 | TASK [ensure-pip : Check if pip is installed] 2025-10-03 08:57:11.661715 | controller | /usr/bin/pip3 2025-10-03 08:57:11.691544 | controller | /usr/bin/python3: No module named wheel 2025-10-03 12:57:11.913318 | controller | ok: Runtime: 0:00:00.039708 2025-10-03 12:57:11.919459 | 2025-10-03 12:57:11.919524 | LOOP [ensure-pip : Install pip from packages] 2025-10-03 12:57:11.951303 | controller | ok: "/var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-03 12:57:11.965546 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-03 12:57:11.976351 | 2025-10-03 12:57:11.976413 | TASK [ensure-pip : Install Python 3 pip] 2025-10-03 12:57:18.004720 | controller | changed 2025-10-03 12:57:18.011032 | 2025-10-03 12:57:18.011166 | TASK [ensure-pip : Check for EPEL repository] 2025-10-03 12:57:18.045890 | controller | skipping: Conditional result was False 2025-10-03 12:57:18.052605 | 2025-10-03 12:57:18.052689 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-03 12:57:18.087247 | controller | skipping: Conditional result was False 2025-10-03 12:57:18.093439 | 2025-10-03 12:57:18.093502 | TASK [ensure-pip : Install Python 2 pip] 2025-10-03 12:57:18.127836 | controller | skipping: Conditional result was False 2025-10-03 12:57:18.133499 | 2025-10-03 12:57:18.133564 | TASK [ensure-pip : Ensure setuptools] 2025-10-03 12:57:18.147790 | controller | skipping: Conditional result was False 2025-10-03 12:57:18.155387 | 2025-10-03 12:57:18.155453 | TASK [ensure-pip : Check for ensurepip module] 2025-10-03 12:57:18.684012 | controller | skipping: Conditional result was False 2025-10-03 12:57:18.690085 | 2025-10-03 12:57:18.690153 | TASK [ensure-pip : Ensure python3-venv] 2025-10-03 12:57:18.715053 | controller | skipping: Conditional result was False 2025-10-03 12:57:18.721293 | 2025-10-03 12:57:18.721362 | TASK [ensure-pip : Install pip from source] 2025-10-03 12:57:18.735907 | controller | skipping: Conditional result was False 2025-10-03 12:57:18.742306 | 2025-10-03 12:57:18.742373 | TASK [ensure-pip : Probe for venv python full path] 2025-10-03 08:57:19.019375 | controller | /usr/bin/python3 2025-10-03 12:57:19.272784 | controller | ok: Runtime: 0:00:00.010419 2025-10-03 12:57:19.283607 | 2025-10-03 12:57:19.283742 | TASK [ensure-pip : Set host default] 2025-10-03 12:57:19.349120 | controller | ok 2025-10-03 12:57:19.355603 | 2025-10-03 12:57:19.355750 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-03 12:57:19.409695 | controller | ok 2025-10-03 12:57:19.420042 | 2025-10-03 12:57:19.420106 | TASK [bindep : Install bindep into temporary venv] 2025-10-03 12:57:24.792595 | controller | changed 2025-10-03 12:57:24.799520 | 2025-10-03 12:57:24.799586 | TASK [bindep : Define bindep_command] 2025-10-03 12:57:24.829860 | controller | ok 2025-10-03 12:57:24.835557 | 2025-10-03 12:57:24.835620 | LOOP [bindep : Include package tasks] 2025-10-03 12:57:24.885492 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-03 12:57:24.885736 | controller | ok: All items complete 2025-10-03 12:57:24.885768 | 2025-10-03 12:57:24.902321 | controller | included: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-03 12:57:24.915549 | 2025-10-03 12:57:24.915625 | TASK [bindep : Define bindep_run fact] 2025-10-03 12:57:24.954753 | controller | ok 2025-10-03 12:57:24.960013 | 2025-10-03 12:57:24.960075 | TASK [bindep : Get list of packages to install from bindep] 2025-10-03 08:57:26.273426 | controller | podman 2025-10-03 08:57:26.298929 | controller | python3-jmespath 2025-10-03 08:57:26.298982 | controller | python3-libvirt 2025-10-03 08:57:26.299049 | controller | python3-lxml 2025-10-03 08:57:26.299059 | controller | python3-netaddr 2025-10-03 12:57:26.500803 | controller | ok: Runtime: 0:00:01.059569 2025-10-03 12:57:26.507505 | 2025-10-03 12:57:26.507582 | TASK [bindep : Install distro packages from bindep] 2025-10-03 12:58:54.372935 | controller | changed 2025-10-03 12:58:54.382059 | 2025-10-03 12:58:54.382173 | TASK [bindep : Check that packages are installed] 2025-10-03 12:58:56.447979 | controller | ok: Runtime: 0:00:01.336381 2025-10-03 12:58:56.454268 | 2025-10-03 12:58:56.454360 | TASK [bindep : Fail if we cannot install all packages] 2025-10-03 12:58:56.488993 | controller | skipping: Conditional result was False 2025-10-03 12:58:56.502787 | 2025-10-03 12:58:56.503113 | TASK [Run test-setup role] 2025-10-03 12:58:56.540240 | controller | ok 2025-10-03 12:58:56.560216 | 2025-10-03 12:58:56.560369 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-03 12:58:56.791967 | controller | ok 2025-10-03 12:58:56.797192 | 2025-10-03 12:58:56.797258 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-03 12:58:57.371997 | controller | skipping: Conditional result was False 2025-10-03 12:58:57.405188 | 2025-10-03 12:58:57.405297 | TASK [bindep : Remove bindep temp dir] 2025-10-03 12:58:57.864342 | controller | ok 2025-10-03 12:58:57.875978 | 2025-10-03 12:58:57.876034 | PLAY RECAP 2025-10-03 12:58:57.876073 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-03 12:58:57.876093 | 2025-10-03 12:58:58.019611 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 12:58:58.020529 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 12:58:58.589406 | 2025-10-03 12:58:58.589569 | PLAY [all] 2025-10-03 12:58:58.609306 | 2025-10-03 12:58:58.609380 | TASK [Abort when test_command variable is undefined] 2025-10-03 12:58:58.644251 | controller | skipping: Conditional result was False 2025-10-03 12:58:58.651148 | 2025-10-03 12:58:58.651225 | TASK [Convert test_command to list] 2025-10-03 12:58:58.695281 | controller | skipping: Conditional result was False 2025-10-03 12:58:58.702275 | 2025-10-03 12:58:58.702340 | TASK [Use test_command list] 2025-10-03 12:58:58.795539 | controller | ok 2025-10-03 12:58:58.802057 | 2025-10-03 12:58:58.802120 | LOOP [Run test_command] 2025-10-03 12:58:59.285676 | controller | no check to run 2025-10-03 12:58:59.285883 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007159 2025-10-03 12:58:59.327597 | 2025-10-03 12:58:59.327724 | PLAY RECAP 2025-10-03 12:58:59.327776 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 12:58:59.327797 | 2025-10-03 12:58:59.504053 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 12:58:59.505231 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 12:59:00.416173 | 2025-10-03 12:59:00.416300 | PLAY [all] 2025-10-03 12:59:00.451538 | 2025-10-03 12:59:00.451697 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-03 12:59:00.800848 | controller | changed: non-zero return code 2025-10-03 12:59:00.806325 | 2025-10-03 12:59:00.806401 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-03 12:59:00.820082 | controller | skipping: Conditional result was False 2025-10-03 12:59:00.826900 | 2025-10-03 12:59:00.826985 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-03 12:59:00.850319 | 2025-10-03 12:59:00.850557 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-03 12:59:00.873132 | 2025-10-03 12:59:00.873375 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-03 12:59:00.889179 | controller | skipping: Conditional result was False 2025-10-03 12:59:00.896192 | 2025-10-03 12:59:00.896283 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-03 12:59:00.917143 | 2025-10-03 12:59:00.917356 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-03 12:59:00.941957 | controller | skipping: Conditional result was False 2025-10-03 12:59:00.950950 | 2025-10-03 12:59:00.951047 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-03 12:59:00.964823 | controller | skipping: Conditional result was False 2025-10-03 12:59:00.971365 | 2025-10-03 12:59:00.971447 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-03 12:59:00.986047 | controller | skipping: Conditional result was False 2025-10-03 12:59:01.009481 | 2025-10-03 12:59:01.009538 | PLAY RECAP 2025-10-03 12:59:01.009578 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-03 12:59:01.009598 | 2025-10-03 12:59:01.124188 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 12:59:01.125020 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 12:59:01.717325 | 2025-10-03 12:59:01.717462 | PLAY [all] 2025-10-03 12:59:01.737501 | 2025-10-03 12:59:01.737615 | TASK [include_role : fetch-output] 2025-10-03 12:59:01.777444 | controller | ok 2025-10-03 12:59:01.795654 | 2025-10-03 12:59:01.795815 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-03 12:59:01.840427 | controller | skipping: Conditional result was False 2025-10-03 12:59:01.846256 | 2025-10-03 12:59:01.846326 | TASK [fetch-output : Set log path for single node] 2025-10-03 12:59:01.905188 | controller | ok 2025-10-03 12:59:01.913509 | 2025-10-03 12:59:01.913584 | LOOP [fetch-output : Ensure local output dirs] 2025-10-03 12:59:02.351286 | controller -> localhost | ok: "/var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/logs" 2025-10-03 12:59:02.583552 | controller -> localhost | changed: "/var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/artifacts" 2025-10-03 12:59:02.816122 | controller -> localhost | changed: "/var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/docs" 2025-10-03 12:59:02.827772 | 2025-10-03 12:59:02.827849 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-03 12:59:03.593823 | controller | changed: .d..t...... ./ 2025-10-03 12:59:03.594071 | controller | changed: All items complete 2025-10-03 12:59:03.594100 | 2025-10-03 12:59:04.130265 | controller | changed: .d..t...... ./ 2025-10-03 12:59:04.619175 | controller | changed: .d..t...... ./ 2025-10-03 12:59:04.643984 | 2025-10-03 12:59:04.644086 | TASK [include_role : fetch-output-openshift] 2025-10-03 12:59:04.668114 | controller | skipping: Conditional result was False 2025-10-03 12:59:04.676044 | 2025-10-03 12:59:04.676120 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-03 12:59:05.108368 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009344 2025-10-03 12:59:05.344796 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015267 2025-10-03 12:59:05.389239 | 2025-10-03 12:59:05.389326 | PLAY [all] 2025-10-03 12:59:05.418849 | 2025-10-03 12:59:05.418921 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-03 12:59:05.932022 | controller | changed 2025-10-03 12:59:05.963937 | 2025-10-03 12:59:05.964062 | PLAY RECAP 2025-10-03 12:59:05.964106 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 12:59:05.964127 | 2025-10-03 12:59:06.073224 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 12:59:06.074204 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-03 12:59:06.729185 | 2025-10-03 12:59:06.729305 | PLAY [localhost] 2025-10-03 12:59:06.762342 | 2025-10-03 12:59:06.762455 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-03 12:59:07.400252 | localhost | changed 2025-10-03 12:59:07.404900 | 2025-10-03 12:59:07.404975 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-03 12:59:07.434852 | localhost | ok 2025-10-03 12:59:07.442862 | 2025-10-03 12:59:07.442931 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-03 12:59:07.979804 | localhost | changed 2025-10-03 12:59:07.984734 | 2025-10-03 12:59:07.984804 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-03 12:59:08.805928 | localhost | changed 2025-10-03 12:59:08.810962 | 2025-10-03 12:59:08.811039 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-03 12:59:09.477223 | localhost | Identity added: /var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/tmp/ansible.hpcl7db4 (/var/lib/zuul/builds/2239728f6bb649bd9040046ba425b3bf/work/tmp/ansible.hpcl7db4) 2025-10-03 12:59:09.477409 | localhost | ok: Runtime: 0:00:00.031192 2025-10-03 12:59:09.481816 | 2025-10-03 12:59:09.481885 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-03 12:59:09.854568 | localhost | ok: Runtime: 0:00:00.021268 2025-10-03 12:59:09.859353 | 2025-10-03 12:59:09.859421 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-03 12:59:09.918095 | localhost | changed 2025-10-03 12:59:09.922566 | 2025-10-03 12:59:09.922630 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-03 12:59:10.295638 | localhost | changed 2025-10-03 12:59:10.315936 | 2025-10-03 12:59:10.315992 | PLAY [localhost] 2025-10-03 12:59:10.328429 | 2025-10-03 12:59:10.328489 | TASK [Generate bulk log download script] 2025-10-03 12:59:10.345844 | localhost | ok 2025-10-03 12:59:10.357910 | 2025-10-03 12:59:10.357993 | TASK [local-log-download : Check API endpoint is defined] 2025-10-03 12:59:10.385851 | localhost | ok: All assertions passed 2025-10-03 12:59:10.390356 | 2025-10-03 12:59:10.390419 | TASK [local-log-download : Create download script] 2025-10-03 12:59:10.811468 | localhost -> localhost | changed 2025-10-03 12:59:10.821554 | 2025-10-03 12:59:10.821627 | TASK [Register quick-download link] 2025-10-03 12:59:10.864972 | localhost | ok 2025-10-03 12:59:10.880771 | 2025-10-03 12:59:10.880831 | PLAY [logserver.rdoproject.org] 2025-10-03 12:59:10.890573 | 2025-10-03 12:59:10.890635 | TASK [Set zuul-log-path fact] 2025-10-03 12:59:10.907965 | logserver.rdoproject.org | ok 2025-10-03 12:59:10.930817 | 2025-10-03 12:59:10.930969 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 12:59:10.959339 | logserver.rdoproject.org | ok 2025-10-03 12:59:10.966829 | 2025-10-03 12:59:10.966915 | TASK [upload-logs : Create log directories] 2025-10-03 12:59:11.870355 | logserver.rdoproject.org | changed 2025-10-03 12:59:11.876114 | 2025-10-03 12:59:11.876210 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-03 12:59:12.147500 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006952 2025-10-03 12:59:12.154376 | 2025-10-03 12:59:12.154468 | TASK [upload-logs : Upload logs to log server] 2025-10-03 12:59:12.879427 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-03 12:59:12.884794 | 2025-10-03 12:59:12.884958 | LOOP [upload-logs : Compress console log and json output] 2025-10-03 12:59:12.958546 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:59:12.980974 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:59:12.986051 | 2025-10-03 12:59:12.986201 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-03 12:59:13.030899 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:59:13.031151 | 2025-10-03 12:59:13.035906 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:59:13.045792 | 2025-10-03 12:59:13.045905 | LOOP [upload-logs : Upload console log and json output]