2025-10-03 07:33:30.757636 | Job console starting... 2025-10-03 07:33:30.768111 | Updating repositories 2025-10-03 07:33:30.799595 | Preparing job workspace 2025-10-03 07:33:34.620309 | Running Ansible setup... 2025-10-03 07:33:38.501668 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 07:33:39.164064 | 2025-10-03 07:33:39.164190 | PLAY [localhost] 2025-10-03 07:33:39.174237 | 2025-10-03 07:33:39.174322 | TASK [Gathering Facts] 2025-10-03 07:33:40.173360 | localhost | ok 2025-10-03 07:33:40.187540 | 2025-10-03 07:33:40.187634 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-03 07:33:40.572885 | localhost -> localhost | changed 2025-10-03 07:33:40.579538 | 2025-10-03 07:33:40.579609 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-03 07:33:41.557637 | localhost -> localhost | changed 2025-10-03 07:33:41.566949 | 2025-10-03 07:33:41.567019 | TASK [Setup log path fact] 2025-10-03 07:33:41.590966 | localhost | ok 2025-10-03 07:33:41.604659 | 2025-10-03 07:33:41.604817 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 07:33:41.636564 | localhost | ok 2025-10-03 07:33:41.645578 | 2025-10-03 07:33:41.645649 | TASK [emit-job-header : Print job information] 2025-10-03 07:33:41.676209 | # Job Information 2025-10-03 07:33:41.676402 | Ansible Version: 2.15.12 2025-10-03 07:33:41.676428 | Job: cifmw-molecule-cifmw_external_dns 2025-10-03 07:33:41.676470 | Pipeline: github-check 2025-10-03 07:33:41.676492 | Executor: ze04.softwarefactory-project.io 2025-10-03 07:33:41.676511 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-03 07:33:41.676534 | Log URL (when completed): https://logserver.rdoproject.org/167/rdoproject.org/1670ebfd40da4b70b25808e9f9fd6928/ 2025-10-03 07:33:41.676554 | Event ID: f958eab0-a02a-11f0-9ba1-0df9636946d8 2025-10-03 07:33:41.684650 | 2025-10-03 07:33:41.684764 | LOOP [emit-job-header : Print node information] 2025-10-03 07:33:41.783203 | localhost | ok: 2025-10-03 07:33:41.783472 | localhost | # Node Information 2025-10-03 07:33:41.783500 | localhost | Inventory Hostname: controller 2025-10-03 07:33:41.783532 | localhost | Hostname: np0005468140 2025-10-03 07:33:41.783552 | localhost | Username: zuul 2025-10-03 07:33:41.783573 | localhost | Distro: CentOS 9 2025-10-03 07:33:41.783591 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-03 07:33:41.783608 | localhost | Region: RegionOne 2025-10-03 07:33:41.783625 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-03 07:33:41.783642 | localhost | Product Name: OpenStack Nova 2025-10-03 07:33:41.783659 | localhost | Interface IP: 38.102.83.5 2025-10-03 07:33:41.813410 | 2025-10-03 07:33:41.813529 | PLAY [all] 2025-10-03 07:33:41.820722 | 2025-10-03 07:33:41.820807 | TASK [Gather network facts] 2025-10-03 07:33:42.360006 | controller | ok 2025-10-03 07:33:42.385720 | 2025-10-03 07:33:42.385887 | TASK [include_role : start-zuul-console] 2025-10-03 07:33:42.418127 | controller | ok 2025-10-03 07:33:42.432068 | 2025-10-03 07:33:42.432169 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-03 07:33:42.890394 | controller | ok 2025-10-03 07:33:42.901278 | 2025-10-03 07:33:42.901355 | TASK [include_role : add-build-sshkey] 2025-10-03 07:33:42.931447 | controller | ok 2025-10-03 07:33:42.946313 | 2025-10-03 07:33:42.946425 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-03 07:33:43.500050 | controller -> localhost | ok 2025-10-03 07:33:43.511031 | 2025-10-03 07:33:43.511211 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-03 07:33:43.562023 | controller | ok 2025-10-03 07:33:43.616373 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-03 07:33:43.640735 | 2025-10-03 07:33:43.640902 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-03 07:33:44.751317 | controller -> localhost | Generating public/private rsa key pair. 2025-10-03 07:33:44.751567 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/1670ebfd40da4b70b25808e9f9fd6928_id_rsa. 2025-10-03 07:33:44.751602 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/1670ebfd40da4b70b25808e9f9fd6928_id_rsa.pub. 2025-10-03 07:33:44.751626 | controller -> localhost | The key fingerprint is: 2025-10-03 07:33:44.751647 | controller -> localhost | SHA256:MVhcKiAXEsO0wXzUSyxTG+MUE7XHj2mqJqWiuc4VlQc zuul-build-sshkey 2025-10-03 07:33:44.751670 | controller -> localhost | The key's randomart image is: 2025-10-03 07:33:44.751709 | controller -> localhost | +---[RSA 3072]----+ 2025-10-03 07:33:44.751730 | controller -> localhost | | =Bo=EO=o.. | 2025-10-03 07:33:44.751751 | controller -> localhost | | +B++*B.+ | 2025-10-03 07:33:44.751771 | controller -> localhost | | .. *=o= o | 2025-10-03 07:33:44.751790 | controller -> localhost | | . o. + + | 2025-10-03 07:33:44.751810 | controller -> localhost | | . S + . | 2025-10-03 07:33:44.751829 | controller -> localhost | | . . o | 2025-10-03 07:33:44.751848 | controller -> localhost | | . o . | 2025-10-03 07:33:44.751868 | controller -> localhost | |..o o .. | 2025-10-03 07:33:44.751887 | controller -> localhost | |== . o. | 2025-10-03 07:33:44.751914 | controller -> localhost | +----[SHA256]-----+ 2025-10-03 07:33:44.751975 | controller -> localhost | ok: Runtime: 0:00:00.510331 2025-10-03 07:33:44.758861 | 2025-10-03 07:33:44.758993 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-03 07:33:44.809765 | controller | ok 2025-10-03 07:33:44.834459 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-03 07:33:44.844548 | 2025-10-03 07:33:44.844777 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-03 07:33:44.870233 | controller | skipping: Conditional result was False 2025-10-03 07:33:44.877888 | 2025-10-03 07:33:44.877972 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-03 07:33:45.520250 | controller | changed 2025-10-03 07:33:45.536296 | 2025-10-03 07:33:45.536421 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-03 07:33:45.791977 | controller | ok 2025-10-03 07:33:45.798198 | 2025-10-03 07:33:45.798271 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-03 07:33:46.709746 | controller | changed 2025-10-03 07:33:46.717852 | 2025-10-03 07:33:46.718039 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-03 07:33:47.675730 | controller | changed 2025-10-03 07:33:47.684900 | 2025-10-03 07:33:47.684969 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-03 07:33:47.736619 | controller | skipping: Conditional result was False 2025-10-03 07:33:47.745462 | 2025-10-03 07:33:47.745741 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-03 07:33:48.237090 | controller -> localhost | changed 2025-10-03 07:33:48.257985 | 2025-10-03 07:33:48.258103 | TASK [add-build-sshkey : Add back temp key] 2025-10-03 07:33:48.555859 | controller -> localhost | Identity added: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/1670ebfd40da4b70b25808e9f9fd6928_id_rsa (zuul-build-sshkey) 2025-10-03 07:33:48.556302 | controller -> localhost | ok: Runtime: 0:00:00.021974 2025-10-03 07:33:48.569360 | 2025-10-03 07:33:48.569471 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-03 07:33:48.989146 | controller | ok 2025-10-03 07:33:49.001017 | 2025-10-03 07:33:49.002240 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-03 07:33:49.027882 | controller | skipping: Conditional result was False 2025-10-03 07:33:49.039509 | 2025-10-03 07:33:49.039645 | TASK [include_role : validate-host] 2025-10-03 07:33:49.059578 | controller | ok 2025-10-03 07:33:49.080397 | 2025-10-03 07:33:49.080506 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-03 07:33:49.121036 | controller | ok 2025-10-03 07:33:49.128136 | 2025-10-03 07:33:49.128203 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-03 07:33:49.424280 | controller -> localhost | ok 2025-10-03 07:33:49.430811 | 2025-10-03 07:33:49.430874 | TASK [validate-host : Collect information about the host] 2025-10-03 07:33:50.273346 | controller | ok 2025-10-03 07:33:50.296022 | 2025-10-03 07:33:50.296134 | TASK [validate-host : Sanitize hostname] 2025-10-03 07:33:50.380860 | controller | ok 2025-10-03 07:33:50.389338 | 2025-10-03 07:33:50.389449 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-03 07:33:50.936340 | controller -> localhost | changed 2025-10-03 07:33:50.945750 | 2025-10-03 07:33:50.945896 | TASK [validate-host : Collect information about zuul worker] 2025-10-03 07:33:51.427794 | controller | ok 2025-10-03 07:33:51.435517 | 2025-10-03 07:33:51.435669 | TASK [validate-host : Write out all zuul information for each host] 2025-10-03 07:33:51.950488 | controller -> localhost | changed 2025-10-03 07:33:51.973796 | 2025-10-03 07:33:51.973965 | TASK [include_role : prepare-workspace-openshift] 2025-10-03 07:33:51.999233 | controller | skipping: Conditional result was False 2025-10-03 07:33:52.007630 | 2025-10-03 07:33:52.007741 | TASK [include_role : remove-zuul-sshkey] 2025-10-03 07:33:52.034198 | controller | skipping: Conditional result was False 2025-10-03 07:33:52.045557 | 2025-10-03 07:33:52.045657 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 07:33:52.338624 | controller | ok: "logs" 2025-10-03 07:33:52.338953 | controller | ok: All items complete 2025-10-03 07:33:52.338982 | 2025-10-03 07:33:52.565482 | controller | ok: "artifacts" 2025-10-03 07:33:52.807273 | controller | ok: "docs" 2025-10-03 07:33:52.825011 | 2025-10-03 07:33:52.825209 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 07:33:53.122789 | controller | changed: "logs" 2025-10-03 07:33:53.355996 | controller | changed: "artifacts" 2025-10-03 07:33:53.617768 | controller | changed: "docs" 2025-10-03 07:33:53.641513 | 2025-10-03 07:33:53.641603 | PLAY RECAP 2025-10-03 07:33:53.641646 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-03 07:33:53.641671 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 07:33:53.641735 | 2025-10-03 07:33:53.804360 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 07:33:53.806117 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 07:33:54.479656 | 2025-10-03 07:33:54.479825 | PLAY [localhost] 2025-10-03 07:33:54.497219 | 2025-10-03 07:33:54.497301 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-03 07:33:54.900953 | localhost | ok 2025-10-03 07:33:54.913395 | 2025-10-03 07:33:54.913564 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-03 07:33:55.670286 | localhost | changed 2025-10-03 07:33:55.692868 | 2025-10-03 07:33:55.693009 | PLAY [all] 2025-10-03 07:33:55.709487 | 2025-10-03 07:33:55.709565 | TASK [include_role : prepare-workspace] 2025-10-03 07:33:55.740991 | controller | ok 2025-10-03 07:33:55.757034 | 2025-10-03 07:33:55.757113 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-03 07:33:56.231426 | controller | ok 2025-10-03 07:33:56.249602 | 2025-10-03 07:33:56.249834 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-03 07:33:58.266645 | controller | Output suppressed because no_log was given 2025-10-03 07:33:58.281143 | 2025-10-03 07:33:58.281248 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 07:33:58.584391 | controller | changed: "logs" 2025-10-03 07:33:58.867195 | controller | changed: "artifacts" 2025-10-03 07:33:59.107822 | controller | changed: "docs" 2025-10-03 07:33:59.125578 | 2025-10-03 07:33:59.125879 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 07:33:59.481962 | controller | changed: "logs" 2025-10-03 07:33:59.482402 | controller | changed: All items complete 2025-10-03 07:33:59.482466 | 2025-10-03 07:33:59.723887 | controller | changed: "artifacts" 2025-10-03 07:33:59.979193 | controller | changed: "docs" 2025-10-03 07:33:59.999167 | 2025-10-03 07:33:59.999321 | TASK [Check if worker can sudo] 2025-10-03 07:34:00.532047 | controller | ok: Runtime: 0:00:00.056602 2025-10-03 07:34:00.547809 | 2025-10-03 07:34:00.547960 | TASK [configure-mirrors : Gather needed facts] 2025-10-03 07:34:00.617650 | controller | skipping: Conditional result was False 2025-10-03 07:34:00.633292 | 2025-10-03 07:34:00.633479 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-03 07:34:00.756987 | controller | ok 2025-10-03 07:34:00.823661 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-03 07:34:00.830473 | 2025-10-03 07:34:00.830552 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-03 07:34:01.118871 | controller | ok 2025-10-03 07:34:01.124832 | 2025-10-03 07:34:01.124899 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-03 07:34:01.189838 | controller | ok: "/var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-03 07:34:01.197305 | 2025-10-03 07:34:01.197378 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-03 07:34:02.119330 | controller | changed 2025-10-03 07:34:02.131736 | 2025-10-03 07:34:02.131872 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-03 07:34:02.243415 | controller | ok: "/var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-03 07:34:02.243813 | controller | ok: All items complete 2025-10-03 07:34:02.243892 | 2025-10-03 07:34:02.334119 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-03 07:34:02.343193 | 2025-10-03 07:34:02.343319 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-03 07:34:03.403146 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-03 07:34:04.322999 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-03 07:34:04.341022 | 2025-10-03 07:34:04.341212 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-03 07:34:04.878241 | controller | changed: section and option added 2025-10-03 07:34:04.898958 | 2025-10-03 07:34:04.899046 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-03 07:34:05.748029 | controller | 29 files removed 2025-10-03 07:34:05.748383 | controller | ok: Item: dnf clean all Runtime: 0:00:00.543210 2025-10-03 07:34:05.748641 | controller | changed: All items complete 2025-10-03 07:34:05.748737 | 2025-10-03 07:34:16.337191 | 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 07:34:16.337347 | controller | DNF version: 4.14.0 2025-10-03 07:34:16.337372 | controller | cachedir: /var/cache/dnf 2025-10-03 07:34:16.337395 | controller | Making cache files for all metadata files. 2025-10-03 07:34:16.337414 | controller | baseos: has expired and will be refreshed. 2025-10-03 07:34:16.337432 | controller | appstream: has expired and will be refreshed. 2025-10-03 07:34:16.337449 | controller | crb: has expired and will be refreshed. 2025-10-03 07:34:16.337475 | controller | extras-common: has expired and will be refreshed. 2025-10-03 07:34:16.337493 | controller | repo: downloading from remote: baseos 2025-10-03 07:34:16.337509 | controller | CentOS Stream 9 - BaseOS 71 MB/s | 8.8 MB 00:00 2025-10-03 07:34:16.337526 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-03 07:34:16.337543 | controller | repo: downloading from remote: appstream 2025-10-03 07:34:16.337560 | controller | CentOS Stream 9 - AppStream 91 MB/s | 25 MB 00:00 2025-10-03 07:34:16.337576 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-03 07:34:16.337593 | controller | repo: downloading from remote: crb 2025-10-03 07:34:16.337609 | controller | CentOS Stream 9 - CRB 88 MB/s | 7.1 MB 00:00 2025-10-03 07:34:16.337626 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-03 07:34:16.337643 | controller | repo: downloading from remote: extras-common 2025-10-03 07:34:16.337660 | controller | CentOS Stream 9 - Extras packages 1.6 MB/s | 20 kB 00:00 2025-10-03 07:34:16.337771 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-03 07:34:16.337808 | controller | Last metadata expiration check: 0:00:01 ago on Fri 03 Oct 2025 03:34:14 AM EDT. 2025-10-03 07:34:16.337829 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-03 07:34:16.337881 | controller | Completion plugin: Generating completion cache... 2025-10-03 07:34:16.337900 | controller | Metadata cache created. 2025-10-03 07:34:16.337927 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.297505 2025-10-03 07:34:16.366896 | 2025-10-03 07:34:16.366982 | PLAY RECAP 2025-10-03 07:34:16.367036 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-03 07:34:16.367063 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 07:34:16.367082 | 2025-10-03 07:34:16.548662 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 07:34:16.549740 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 07:34:17.102455 | 2025-10-03 07:34:17.102587 | PLAY [all] 2025-10-03 07:34:17.124210 | 2025-10-03 07:34:17.124308 | TASK [Install binary dependencies] 2025-10-03 07:34:17.175861 | controller | ok 2025-10-03 07:34:17.195882 | 2025-10-03 07:34:17.195970 | TASK [bindep : Include find tasks] 2025-10-03 07:34:17.236890 | controller | ok 2025-10-03 07:34:17.244580 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-03 07:34:17.250739 | 2025-10-03 07:34:17.250804 | TASK [bindep : Look for bindep.txt] 2025-10-03 07:34:17.709604 | controller | ok 2025-10-03 07:34:17.721300 | 2025-10-03 07:34:17.721499 | TASK [bindep : Define bindep_file fact] 2025-10-03 07:34:17.758739 | controller | ok 2025-10-03 07:34:17.769674 | 2025-10-03 07:34:17.769839 | TASK [bindep : Look for other-requirements.txt] 2025-10-03 07:34:17.785222 | controller | skipping: Conditional result was False 2025-10-03 07:34:17.792494 | 2025-10-03 07:34:17.792586 | TASK [bindep : Define bindep_file fact] 2025-10-03 07:34:17.823666 | controller | skipping: Conditional result was False 2025-10-03 07:34:17.830599 | 2025-10-03 07:34:17.830702 | TASK [bindep : Look for bindep fallback file] 2025-10-03 07:34:17.865851 | controller | skipping: Conditional result was False 2025-10-03 07:34:17.872323 | 2025-10-03 07:34:17.872396 | TASK [bindep : Define bindep_file fact] 2025-10-03 07:34:17.897228 | controller | skipping: Conditional result was False 2025-10-03 07:34:17.904382 | 2025-10-03 07:34:17.904490 | TASK [bindep : Include bindep tasks] 2025-10-03 07:34:17.937264 | controller | ok 2025-10-03 07:34:17.945090 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-03 07:34:17.953190 | 2025-10-03 07:34:17.953259 | TASK [bindep : Look for bindep command] 2025-10-03 07:34:17.978515 | controller | skipping: Conditional result was False 2025-10-03 07:34:17.986373 | 2025-10-03 07:34:17.986442 | TASK [bindep : Check for system bindep] 2025-10-03 07:34:18.522326 | controller | ok: Runtime: 0:00:00.005238 2025-10-03 07:34:18.531416 | 2025-10-03 07:34:18.531532 | TASK [bindep : Define bindep_command fact] 2025-10-03 07:34:18.558335 | controller | skipping: Conditional result was False 2025-10-03 07:34:18.568872 | 2025-10-03 07:34:18.569024 | TASK [bindep : Include install tasks] 2025-10-03 07:34:18.625596 | controller | ok 2025-10-03 07:34:18.639346 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-03 07:34:18.654654 | 2025-10-03 07:34:18.654822 | TASK [bindep : Create temp dir for bindep] 2025-10-03 07:34:19.066421 | controller | changed 2025-10-03 07:34:19.075514 | 2025-10-03 07:34:19.075606 | TASK [Ensure we have pip dependencies] 2025-10-03 07:34:19.099934 | controller | ok 2025-10-03 07:34:19.133077 | 2025-10-03 07:34:19.133173 | TASK [ensure-pip : Check if pip is installed] 2025-10-03 03:34:19.428693 | controller | /usr/bin/pip3 2025-10-03 03:34:19.450314 | controller | /usr/bin/python3: No module named wheel 2025-10-03 07:34:19.660905 | controller | ok: Runtime: 0:00:00.031445 2025-10-03 07:34:19.670384 | 2025-10-03 07:34:19.670516 | LOOP [ensure-pip : Install pip from packages] 2025-10-03 07:34:19.722499 | controller | ok: "/var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-03 07:34:19.737329 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-03 07:34:19.749899 | 2025-10-03 07:34:19.749991 | TASK [ensure-pip : Install Python 3 pip] 2025-10-03 07:34:22.194248 | controller | changed 2025-10-03 07:34:22.200645 | 2025-10-03 07:34:22.200774 | TASK [ensure-pip : Check for EPEL repository] 2025-10-03 07:34:22.257462 | controller | skipping: Conditional result was False 2025-10-03 07:34:22.266121 | 2025-10-03 07:34:22.266282 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-03 07:34:22.312880 | controller | skipping: Conditional result was False 2025-10-03 07:34:22.319925 | 2025-10-03 07:34:22.320007 | TASK [ensure-pip : Install Python 2 pip] 2025-10-03 07:34:22.364842 | controller | skipping: Conditional result was False 2025-10-03 07:34:22.372301 | 2025-10-03 07:34:22.372376 | TASK [ensure-pip : Ensure setuptools] 2025-10-03 07:34:22.399265 | controller | skipping: Conditional result was False 2025-10-03 07:34:22.408451 | 2025-10-03 07:34:22.408550 | TASK [ensure-pip : Check for ensurepip module] 2025-10-03 07:34:22.942292 | controller | skipping: Conditional result was False 2025-10-03 07:34:22.953281 | 2025-10-03 07:34:22.953403 | TASK [ensure-pip : Ensure python3-venv] 2025-10-03 07:34:22.981243 | controller | skipping: Conditional result was False 2025-10-03 07:34:22.988955 | 2025-10-03 07:34:22.989094 | TASK [ensure-pip : Install pip from source] 2025-10-03 07:34:23.013543 | controller | skipping: Conditional result was False 2025-10-03 07:34:23.020902 | 2025-10-03 07:34:23.021018 | TASK [ensure-pip : Probe for venv python full path] 2025-10-03 03:34:23.307360 | controller | /usr/bin/python3 2025-10-03 07:34:23.560806 | controller | ok: Runtime: 0:00:00.005392 2025-10-03 07:34:23.574441 | 2025-10-03 07:34:23.574866 | TASK [ensure-pip : Set host default] 2025-10-03 07:34:23.655607 | controller | ok 2025-10-03 07:34:23.669974 | 2025-10-03 07:34:23.670136 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-03 07:34:23.733636 | controller | ok 2025-10-03 07:34:23.763481 | 2025-10-03 07:34:23.763674 | TASK [bindep : Install bindep into temporary venv] 2025-10-03 07:34:27.898202 | controller | changed 2025-10-03 07:34:27.904156 | 2025-10-03 07:34:27.904226 | TASK [bindep : Define bindep_command] 2025-10-03 07:34:27.946033 | controller | ok 2025-10-03 07:34:27.951978 | 2025-10-03 07:34:27.952060 | LOOP [bindep : Include package tasks] 2025-10-03 07:34:28.030736 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-03 07:34:28.031739 | controller | ok: All items complete 2025-10-03 07:34:28.031833 | 2025-10-03 07:34:28.050222 | controller | included: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-03 07:34:28.062450 | 2025-10-03 07:34:28.062518 | TASK [bindep : Define bindep_run fact] 2025-10-03 07:34:28.093119 | controller | ok 2025-10-03 07:34:28.098359 | 2025-10-03 07:34:28.098421 | TASK [bindep : Get list of packages to install from bindep] 2025-10-03 03:34:29.400306 | controller | podman 2025-10-03 03:34:29.433781 | controller | python3-jmespath 2025-10-03 03:34:29.433951 | controller | python3-libvirt 2025-10-03 03:34:29.433964 | controller | python3-lxml 2025-10-03 03:34:29.433974 | controller | python3-netaddr 2025-10-03 07:34:29.634356 | controller | ok: Runtime: 0:00:01.068357 2025-10-03 07:34:29.645809 | 2025-10-03 07:34:29.645963 | TASK [bindep : Install distro packages from bindep] 2025-10-03 07:35:31.082652 | controller | changed 2025-10-03 07:35:31.147999 | 2025-10-03 07:35:31.148201 | TASK [bindep : Check that packages are installed] 2025-10-03 07:35:32.700932 | controller | ok: Runtime: 0:00:01.084086 2025-10-03 07:35:32.715811 | 2025-10-03 07:35:32.716019 | TASK [bindep : Fail if we cannot install all packages] 2025-10-03 07:35:32.745432 | controller | skipping: Conditional result was False 2025-10-03 07:35:32.776745 | 2025-10-03 07:35:32.776987 | TASK [Run test-setup role] 2025-10-03 07:35:32.802773 | controller | ok 2025-10-03 07:35:32.829285 | 2025-10-03 07:35:32.829464 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-03 07:35:33.117897 | controller | ok 2025-10-03 07:35:33.126715 | 2025-10-03 07:35:33.126825 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-03 07:35:33.674117 | controller | skipping: Conditional result was False 2025-10-03 07:35:33.695631 | 2025-10-03 07:35:33.695819 | TASK [bindep : Remove bindep temp dir] 2025-10-03 07:35:34.083662 | controller | ok 2025-10-03 07:35:34.097653 | 2025-10-03 07:35:34.097793 | PLAY RECAP 2025-10-03 07:35:34.097834 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-03 07:35:34.097855 | 2025-10-03 07:35:34.262001 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 07:35:34.263276 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 07:35:34.954410 | 2025-10-03 07:35:34.954568 | PLAY [all] 2025-10-03 07:35:34.975067 | 2025-10-03 07:35:34.975233 | TASK [Abort when test_command variable is undefined] 2025-10-03 07:35:35.046810 | controller | skipping: Conditional result was False 2025-10-03 07:35:35.053625 | 2025-10-03 07:35:35.053829 | TASK [Convert test_command to list] 2025-10-03 07:35:35.099918 | controller | skipping: Conditional result was False 2025-10-03 07:35:35.106501 | 2025-10-03 07:35:35.106578 | TASK [Use test_command list] 2025-10-03 07:35:35.156748 | controller | ok 2025-10-03 07:35:35.162257 | 2025-10-03 07:35:35.162321 | LOOP [Run test_command] 2025-10-03 07:35:35.600013 | controller | no check to run 2025-10-03 07:35:35.600200 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006184 2025-10-03 07:35:35.628257 | 2025-10-03 07:35:35.628413 | PLAY RECAP 2025-10-03 07:35:35.628456 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 07:35:35.628488 | 2025-10-03 07:35:35.747179 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 07:35:35.748160 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 07:35:36.382707 | 2025-10-03 07:35:36.382876 | PLAY [all] 2025-10-03 07:35:36.403545 | 2025-10-03 07:35:36.403631 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-03 07:35:36.748409 | controller | changed: non-zero return code 2025-10-03 07:35:36.758444 | 2025-10-03 07:35:36.758622 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-03 07:35:36.785272 | controller | skipping: Conditional result was False 2025-10-03 07:35:36.791470 | 2025-10-03 07:35:36.791639 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-03 07:35:36.836477 | 2025-10-03 07:35:36.837673 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-03 07:35:36.880851 | 2025-10-03 07:35:36.881030 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-03 07:35:36.899459 | controller | skipping: Conditional result was False 2025-10-03 07:35:36.906607 | 2025-10-03 07:35:36.906719 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-03 07:35:36.949366 | 2025-10-03 07:35:36.949546 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-03 07:35:36.976154 | controller | skipping: Conditional result was False 2025-10-03 07:35:36.981800 | 2025-10-03 07:35:36.981892 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-03 07:35:36.995922 | controller | skipping: Conditional result was False 2025-10-03 07:35:37.002105 | 2025-10-03 07:35:37.002171 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-03 07:35:37.016280 | controller | skipping: Conditional result was False 2025-10-03 07:35:37.040933 | 2025-10-03 07:35:37.041023 | PLAY RECAP 2025-10-03 07:35:37.041067 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-03 07:35:37.041087 | 2025-10-03 07:35:37.173767 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 07:35:37.174627 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 07:35:37.732778 | 2025-10-03 07:35:37.732918 | PLAY [all] 2025-10-03 07:35:37.752278 | 2025-10-03 07:35:37.752367 | TASK [include_role : fetch-output] 2025-10-03 07:35:37.782864 | controller | ok 2025-10-03 07:35:37.801348 | 2025-10-03 07:35:37.801434 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-03 07:35:37.845838 | controller | skipping: Conditional result was False 2025-10-03 07:35:37.851903 | 2025-10-03 07:35:37.851973 | TASK [fetch-output : Set log path for single node] 2025-10-03 07:35:37.881388 | controller | ok 2025-10-03 07:35:37.886899 | 2025-10-03 07:35:37.886969 | LOOP [fetch-output : Ensure local output dirs] 2025-10-03 07:35:38.349022 | controller -> localhost | ok: "/var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/logs" 2025-10-03 07:35:38.556917 | controller -> localhost | changed: "/var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/artifacts" 2025-10-03 07:35:38.779597 | controller -> localhost | changed: "/var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/docs" 2025-10-03 07:35:38.792184 | 2025-10-03 07:35:38.792331 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-03 07:35:39.444275 | controller | changed: .d..t...... ./ 2025-10-03 07:35:39.444505 | controller | changed: All items complete 2025-10-03 07:35:39.444532 | 2025-10-03 07:35:39.911350 | controller | changed: .d..t...... ./ 2025-10-03 07:35:40.363667 | controller | changed: .d..t...... ./ 2025-10-03 07:35:40.380947 | 2025-10-03 07:35:40.381096 | TASK [include_role : fetch-output-openshift] 2025-10-03 07:35:40.406076 | controller | skipping: Conditional result was False 2025-10-03 07:35:40.413065 | 2025-10-03 07:35:40.413139 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-03 07:35:40.897476 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.028751 2025-10-03 07:35:41.148111 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015313 2025-10-03 07:35:41.183455 | 2025-10-03 07:35:41.183650 | PLAY [all] 2025-10-03 07:35:41.198567 | 2025-10-03 07:35:41.198716 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-03 07:35:41.659531 | controller | changed 2025-10-03 07:35:41.692211 | 2025-10-03 07:35:41.692343 | PLAY RECAP 2025-10-03 07:35:41.692399 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 07:35:41.692429 | 2025-10-03 07:35:41.831747 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 07:35:41.832622 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-03 07:35:42.475612 | 2025-10-03 07:35:42.475829 | PLAY [localhost] 2025-10-03 07:35:42.496425 | 2025-10-03 07:35:42.496530 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-03 07:35:42.877301 | localhost | changed 2025-10-03 07:35:42.886636 | 2025-10-03 07:35:42.886823 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-03 07:35:42.915890 | localhost | ok 2025-10-03 07:35:42.923985 | 2025-10-03 07:35:42.924049 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-03 07:35:43.272108 | localhost | changed 2025-10-03 07:35:43.286051 | 2025-10-03 07:35:43.286160 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-03 07:35:44.021443 | localhost | changed 2025-10-03 07:35:44.029584 | 2025-10-03 07:35:44.029672 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-03 07:35:44.541012 | localhost | Identity added: /var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/tmp/ansible.b8y_u7w_ (/var/lib/zuul/builds/1670ebfd40da4b70b25808e9f9fd6928/work/tmp/ansible.b8y_u7w_) 2025-10-03 07:35:44.541211 | localhost | ok: Runtime: 0:00:00.017588 2025-10-03 07:35:44.548158 | 2025-10-03 07:35:44.548303 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-03 07:35:44.814992 | localhost | ok: Runtime: 0:00:00.006816 2025-10-03 07:35:44.820128 | 2025-10-03 07:35:44.820195 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-03 07:35:44.881932 | localhost | changed 2025-10-03 07:35:44.886408 | 2025-10-03 07:35:44.886492 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-03 07:35:45.282587 | localhost | changed 2025-10-03 07:35:45.309607 | 2025-10-03 07:35:45.309724 | PLAY [localhost] 2025-10-03 07:35:45.322053 | 2025-10-03 07:35:45.322143 | TASK [Generate bulk log download script] 2025-10-03 07:35:45.343829 | localhost | ok 2025-10-03 07:35:45.356160 | 2025-10-03 07:35:45.356226 | TASK [local-log-download : Check API endpoint is defined] 2025-10-03 07:35:45.397271 | localhost | ok: All assertions passed 2025-10-03 07:35:45.402747 | 2025-10-03 07:35:45.402818 | TASK [local-log-download : Create download script] 2025-10-03 07:35:45.776762 | localhost -> localhost | changed 2025-10-03 07:35:45.790203 | 2025-10-03 07:35:45.790319 | TASK [Register quick-download link] 2025-10-03 07:35:45.811734 | localhost | ok 2025-10-03 07:35:45.861716 | 2025-10-03 07:35:45.861846 | PLAY [logserver.rdoproject.org] 2025-10-03 07:35:45.872256 | 2025-10-03 07:35:45.872325 | TASK [Set zuul-log-path fact] 2025-10-03 07:35:45.890181 | logserver.rdoproject.org | ok 2025-10-03 07:35:45.900435 | 2025-10-03 07:35:45.900501 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 07:35:45.929370 | logserver.rdoproject.org | ok 2025-10-03 07:35:45.939349 | 2025-10-03 07:35:45.939434 | TASK [upload-logs : Create log directories] 2025-10-03 07:35:46.668752 | logserver.rdoproject.org | changed 2025-10-03 07:35:46.677111 | 2025-10-03 07:35:46.677255 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-03 07:35:47.045095 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.030678 2025-10-03 07:35:47.050125 | 2025-10-03 07:35:47.050190 | TASK [upload-logs : Upload logs to log server] 2025-10-03 07:35:47.714853 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-03 07:35:47.718045 | 2025-10-03 07:35:47.718110 | LOOP [upload-logs : Compress console log and json output] 2025-10-03 07:35:47.790152 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 07:35:47.804497 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 07:35:47.812133 | 2025-10-03 07:35:47.812281 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-03 07:35:47.857982 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 07:35:47.858280 | 2025-10-03 07:35:47.863231 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 07:35:47.874744 | 2025-10-03 07:35:47.874901 | LOOP [upload-logs : Upload console log and json output]