2025-10-13 14:31:33.853881 | Job console starting... 2025-10-13 14:31:33.866001 | Updating repositories 2025-10-13 14:31:33.900510 | Preparing job workspace 2025-10-13 14:31:38.689742 | Running Ansible setup... 2025-10-13 14:31:42.665784 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:31:43.403115 | 2025-10-13 14:31:43.403236 | PLAY [localhost] 2025-10-13 14:31:43.412714 | 2025-10-13 14:31:43.412785 | TASK [Gathering Facts] 2025-10-13 14:31:44.453391 | localhost | ok 2025-10-13 14:31:44.474203 | 2025-10-13 14:31:44.474359 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 14:31:44.872101 | localhost -> localhost | changed 2025-10-13 14:31:44.877764 | 2025-10-13 14:31:44.877860 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 14:31:45.758573 | localhost -> localhost | changed 2025-10-13 14:31:45.767343 | 2025-10-13 14:31:45.767406 | TASK [Setup log path fact] 2025-10-13 14:31:45.785502 | localhost | ok 2025-10-13 14:31:45.798972 | 2025-10-13 14:31:45.799068 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:31:45.828711 | localhost | ok 2025-10-13 14:31:45.837092 | 2025-10-13 14:31:45.837209 | TASK [emit-job-header : Print job information] 2025-10-13 14:31:45.865786 | # Job Information 2025-10-13 14:31:45.865971 | Ansible Version: 2.15.12 2025-10-13 14:31:45.866000 | Job: cifmw-molecule-ci_dcn_site 2025-10-13 14:31:45.866020 | Pipeline: github-check 2025-10-13 14:31:45.866040 | Executor: ze04.softwarefactory-project.io 2025-10-13 14:31:45.866060 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402 2025-10-13 14:31:45.866080 | Log URL (when completed): https://logserver.rdoproject.org/7b8/rdoproject.org/7b881291c4fd4678826a4d2ec470711e/ 2025-10-13 14:31:45.866099 | Event ID: 1ffd4d00-a841-11f0-85e6-969c5520c1b0 2025-10-13 14:31:45.870773 | 2025-10-13 14:31:45.870848 | LOOP [emit-job-header : Print node information] 2025-10-13 14:31:45.980394 | localhost | ok: 2025-10-13 14:31:45.980551 | localhost | # Node Information 2025-10-13 14:31:45.980590 | localhost | Inventory Hostname: controller 2025-10-13 14:31:45.980618 | localhost | Hostname: np0005485040 2025-10-13 14:31:45.980643 | localhost | Username: zuul 2025-10-13 14:31:45.980669 | localhost | Distro: CentOS 9 2025-10-13 14:31:45.980708 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 14:31:45.980732 | localhost | Region: RegionOne 2025-10-13 14:31:45.980754 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 14:31:45.980775 | localhost | Product Name: OpenStack Nova 2025-10-13 14:31:45.980797 | localhost | Interface IP: 38.102.83.238 2025-10-13 14:31:46.002973 | 2025-10-13 14:31:46.003082 | PLAY [all] 2025-10-13 14:31:46.009722 | 2025-10-13 14:31:46.009790 | TASK [Gather network facts] 2025-10-13 14:31:46.477723 | controller | ok 2025-10-13 14:31:46.506243 | 2025-10-13 14:31:46.506399 | TASK [include_role : start-zuul-console] 2025-10-13 14:31:46.525738 | controller | ok 2025-10-13 14:31:46.539576 | 2025-10-13 14:31:46.539691 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 14:31:47.000981 | controller | ok 2025-10-13 14:31:47.014282 | 2025-10-13 14:31:47.014383 | TASK [include_role : add-build-sshkey] 2025-10-13 14:31:47.033766 | controller | ok 2025-10-13 14:31:47.054806 | 2025-10-13 14:31:47.054927 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 14:31:47.292210 | controller -> localhost | ok 2025-10-13 14:31:47.301484 | 2025-10-13 14:31:47.301600 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 14:31:47.357014 | controller | ok 2025-10-13 14:31:47.382554 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 14:31:47.389643 | 2025-10-13 14:31:47.389730 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 14:31:47.916974 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 14:31:47.917212 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/7b881291c4fd4678826a4d2ec470711e_id_rsa. 2025-10-13 14:31:47.917248 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/7b881291c4fd4678826a4d2ec470711e_id_rsa.pub. 2025-10-13 14:31:47.917270 | controller -> localhost | The key fingerprint is: 2025-10-13 14:31:47.917289 | controller -> localhost | SHA256:jEUSA2EggApUy6HysnZu+sOVIy/twGYsB5Hw0ttz028 zuul-build-sshkey 2025-10-13 14:31:47.917307 | controller -> localhost | The key's randomart image is: 2025-10-13 14:31:47.917326 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 14:31:47.917343 | controller -> localhost | |B.o++o+.. | 2025-10-13 14:31:47.917362 | controller -> localhost | |+++.o + | 2025-10-13 14:31:47.917379 | controller -> localhost | |=+oo . | 2025-10-13 14:31:47.917397 | controller -> localhost | |oo.o = | 2025-10-13 14:31:47.917414 | controller -> localhost | |..o o = S | 2025-10-13 14:31:47.917432 | controller -> localhost | | o+. * . . | 2025-10-13 14:31:47.917449 | controller -> localhost | |.o.O= . E | 2025-10-13 14:31:47.917468 | controller -> localhost | |. B=.o . | 2025-10-13 14:31:47.917485 | controller -> localhost | | .+o+. | 2025-10-13 14:31:47.917502 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 14:31:47.917545 | controller -> localhost | ok: Runtime: 0:00:00.117996 2025-10-13 14:31:47.924299 | 2025-10-13 14:31:47.924359 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 14:31:47.954833 | controller | ok 2025-10-13 14:31:47.969196 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 14:31:47.984842 | 2025-10-13 14:31:47.984975 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 14:31:48.010322 | controller | skipping: Conditional result was False 2025-10-13 14:31:48.017716 | 2025-10-13 14:31:48.017802 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 14:31:48.527402 | controller | changed 2025-10-13 14:31:48.534262 | 2025-10-13 14:31:48.534327 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 14:31:48.807620 | controller | ok 2025-10-13 14:31:48.812804 | 2025-10-13 14:31:48.812865 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 14:31:49.603173 | controller | changed 2025-10-13 14:31:49.608351 | 2025-10-13 14:31:49.608413 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 14:31:50.499484 | controller | changed 2025-10-13 14:31:50.504717 | 2025-10-13 14:31:50.504823 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 14:31:50.528901 | controller | skipping: Conditional result was False 2025-10-13 14:31:50.537852 | 2025-10-13 14:31:50.537964 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 14:31:51.005074 | controller -> localhost | changed 2025-10-13 14:31:51.024598 | 2025-10-13 14:31:51.024695 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 14:31:51.508396 | controller -> localhost | Identity added: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/7b881291c4fd4678826a4d2ec470711e_id_rsa (zuul-build-sshkey) 2025-10-13 14:31:51.508564 | controller -> localhost | ok: Runtime: 0:00:00.041457 2025-10-13 14:31:51.514110 | 2025-10-13 14:31:51.514171 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 14:31:51.897764 | controller | ok 2025-10-13 14:31:51.904951 | 2025-10-13 14:31:51.905014 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 14:31:51.949740 | controller | skipping: Conditional result was False 2025-10-13 14:31:51.964543 | 2025-10-13 14:31:51.964620 | TASK [include_role : validate-host] 2025-10-13 14:31:51.983302 | controller | ok 2025-10-13 14:31:52.008917 | 2025-10-13 14:31:52.009093 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 14:31:52.054024 | controller | ok 2025-10-13 14:31:52.058771 | 2025-10-13 14:31:52.058844 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 14:31:52.287697 | controller -> localhost | ok 2025-10-13 14:31:52.293850 | 2025-10-13 14:31:52.293913 | TASK [validate-host : Collect information about the host] 2025-10-13 14:31:53.075133 | controller | ok 2025-10-13 14:31:53.085221 | 2025-10-13 14:31:53.085296 | TASK [validate-host : Sanitize hostname] 2025-10-13 14:31:53.136892 | controller | ok 2025-10-13 14:31:53.149918 | 2025-10-13 14:31:53.150033 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 14:31:53.801137 | controller -> localhost | changed 2025-10-13 14:31:53.814764 | 2025-10-13 14:31:53.814973 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 14:31:54.353599 | controller | ok 2025-10-13 14:31:54.358727 | 2025-10-13 14:31:54.358794 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 14:31:55.237616 | controller -> localhost | changed 2025-10-13 14:31:55.248078 | 2025-10-13 14:31:55.248146 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 14:31:55.302188 | controller | skipping: Conditional result was False 2025-10-13 14:31:55.308542 | 2025-10-13 14:31:55.308618 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 14:31:55.352602 | controller | skipping: Conditional result was False 2025-10-13 14:31:55.358202 | 2025-10-13 14:31:55.358275 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:31:55.687706 | controller | ok: "logs" 2025-10-13 14:31:55.688004 | controller | ok: All items complete 2025-10-13 14:31:55.688034 | 2025-10-13 14:31:55.901556 | controller | ok: "artifacts" 2025-10-13 14:31:56.113218 | controller | ok: "docs" 2025-10-13 14:31:56.137656 | 2025-10-13 14:31:56.141088 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:31:56.560018 | controller | changed: "logs" 2025-10-13 14:31:56.772717 | controller | changed: "artifacts" 2025-10-13 14:31:57.018774 | controller | changed: "docs" 2025-10-13 14:31:57.069803 | 2025-10-13 14:31:57.069902 | PLAY RECAP 2025-10-13 14:31:57.069945 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 14:31:57.069971 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:31:57.069989 | 2025-10-13 14:31:57.355823 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 14:31:57.356611 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:31:58.501452 | 2025-10-13 14:31:58.501574 | PLAY [localhost] 2025-10-13 14:31:58.525343 | 2025-10-13 14:31:58.525483 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 14:31:59.230795 | localhost | ok 2025-10-13 14:31:59.241655 | 2025-10-13 14:31:59.241835 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 14:32:00.775796 | localhost | changed 2025-10-13 14:32:00.847564 | 2025-10-13 14:32:00.847657 | PLAY [all] 2025-10-13 14:32:00.882326 | 2025-10-13 14:32:00.882430 | TASK [include_role : prepare-workspace] 2025-10-13 14:32:00.935167 | controller | ok 2025-10-13 14:32:00.964494 | 2025-10-13 14:32:00.964647 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 14:32:01.474040 | controller | ok 2025-10-13 14:32:01.487730 | 2025-10-13 14:32:01.487820 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 14:32:04.290960 | controller | Output suppressed because no_log was given 2025-10-13 14:32:04.325073 | 2025-10-13 14:32:04.325189 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 14:32:04.635446 | controller | changed: "logs" 2025-10-13 14:32:04.894208 | controller | changed: "artifacts" 2025-10-13 14:32:05.140966 | controller | changed: "docs" 2025-10-13 14:32:05.150886 | 2025-10-13 14:32:05.151010 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 14:32:05.427366 | controller | changed: "logs" 2025-10-13 14:32:05.427593 | controller | changed: All items complete 2025-10-13 14:32:05.427622 | 2025-10-13 14:32:05.643943 | controller | changed: "artifacts" 2025-10-13 14:32:05.884792 | controller | changed: "docs" 2025-10-13 14:32:05.912296 | 2025-10-13 14:32:05.912413 | TASK [Check if worker can sudo] 2025-10-13 14:32:06.487783 | controller | ok: Runtime: 0:00:00.059455 2025-10-13 14:32:06.494231 | 2025-10-13 14:32:06.494314 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 14:32:06.601825 | controller | skipping: Conditional result was False 2025-10-13 14:32:06.634644 | 2025-10-13 14:32:06.634774 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 14:32:06.704717 | controller | ok 2025-10-13 14:32:06.713250 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 14:32:06.720278 | 2025-10-13 14:32:06.720668 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 14:32:06.982582 | controller | ok 2025-10-13 14:32:06.988189 | 2025-10-13 14:32:06.988254 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 14:32:07.072637 | controller | ok: "/var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 14:32:07.092792 | 2025-10-13 14:32:07.092924 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 14:32:07.960955 | controller | changed 2025-10-13 14:32:07.968170 | 2025-10-13 14:32:07.968316 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 14:32:08.051455 | controller | ok: "/var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 14:32:08.051621 | controller | ok: All items complete 2025-10-13 14:32:08.051647 | 2025-10-13 14:32:08.130012 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 14:32:08.137240 | 2025-10-13 14:32:08.137332 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 14:32:09.113698 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 14:32:09.941355 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 14:32:09.956625 | 2025-10-13 14:32:09.956767 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 14:32:10.410639 | controller | changed: section and option added 2025-10-13 14:32:10.441722 | 2025-10-13 14:32:10.441839 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 14:32:11.281756 | controller | 29 files removed 2025-10-13 14:32:11.281986 | controller | ok: Item: dnf clean all Runtime: 0:00:00.528344 2025-10-13 14:32:11.282025 | controller | changed: All items complete 2025-10-13 14:32:11.282046 | 2025-10-13 14:32:22.246333 | 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-13 14:32:22.246581 | controller | DNF version: 4.14.0 2025-10-13 14:32:22.246618 | controller | cachedir: /var/cache/dnf 2025-10-13 14:32:22.246641 | controller | Making cache files for all metadata files. 2025-10-13 14:32:22.246660 | controller | baseos: has expired and will be refreshed. 2025-10-13 14:32:22.246693 | controller | appstream: has expired and will be refreshed. 2025-10-13 14:32:22.246716 | controller | crb: has expired and will be refreshed. 2025-10-13 14:32:22.246741 | controller | extras-common: has expired and will be refreshed. 2025-10-13 14:32:22.246757 | controller | repo: downloading from remote: baseos 2025-10-13 14:32:22.246773 | controller | CentOS Stream 9 - BaseOS 72 MB/s | 8.8 MB 00:00 2025-10-13 14:32:22.246788 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 14:32:22.246804 | controller | repo: downloading from remote: appstream 2025-10-13 14:32:22.246820 | controller | CentOS Stream 9 - AppStream 61 MB/s | 25 MB 00:00 2025-10-13 14:32:22.246836 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 14:32:22.246852 | controller | repo: downloading from remote: crb 2025-10-13 14:32:22.246870 | controller | CentOS Stream 9 - CRB 99 MB/s | 7.2 MB 00:00 2025-10-13 14:32:22.246894 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 14:32:22.246917 | controller | repo: downloading from remote: extras-common 2025-10-13 14:32:22.246938 | controller | CentOS Stream 9 - Extras packages 1.1 MB/s | 20 kB 00:00 2025-10-13 14:32:22.246955 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 14:32:22.246971 | controller | Last metadata expiration check: 0:00:01 ago on Mon 13 Oct 2025 10:32:20 AM EDT. 2025-10-13 14:32:22.246987 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 14:32:22.247002 | controller | Completion plugin: Generating completion cache... 2025-10-13 14:32:22.247018 | controller | Metadata cache created. 2025-10-13 14:32:22.247043 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.722142 2025-10-13 14:32:22.332961 | 2025-10-13 14:32:22.333061 | PLAY RECAP 2025-10-13 14:32:22.333185 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 14:32:22.333217 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:32:22.333236 | 2025-10-13 14:32:22.476646 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:32:22.477645 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:32:23.329296 | 2025-10-13 14:32:23.329498 | PLAY [all] 2025-10-13 14:32:23.362518 | 2025-10-13 14:32:23.362631 | TASK [Install binary dependencies] 2025-10-13 14:32:23.443136 | controller | ok 2025-10-13 14:32:23.464241 | 2025-10-13 14:32:23.464365 | TASK [bindep : Include find tasks] 2025-10-13 14:32:23.504721 | controller | ok 2025-10-13 14:32:23.513147 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 14:32:23.519247 | 2025-10-13 14:32:23.519313 | TASK [bindep : Look for bindep.txt] 2025-10-13 14:32:23.977326 | controller | ok 2025-10-13 14:32:23.992371 | 2025-10-13 14:32:23.992487 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:32:24.048275 | controller | ok 2025-10-13 14:32:24.057348 | 2025-10-13 14:32:24.057712 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 14:32:24.094885 | controller | skipping: Conditional result was False 2025-10-13 14:32:24.103868 | 2025-10-13 14:32:24.103982 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:32:24.150811 | controller | skipping: Conditional result was False 2025-10-13 14:32:24.159231 | 2025-10-13 14:32:24.159322 | TASK [bindep : Look for bindep fallback file] 2025-10-13 14:32:24.204621 | controller | skipping: Conditional result was False 2025-10-13 14:32:24.211015 | 2025-10-13 14:32:24.211084 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:32:24.235433 | controller | skipping: Conditional result was False 2025-10-13 14:32:24.242088 | 2025-10-13 14:32:24.242154 | TASK [bindep : Include bindep tasks] 2025-10-13 14:32:24.292952 | controller | ok 2025-10-13 14:32:24.300238 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 14:32:24.320840 | 2025-10-13 14:32:24.321000 | TASK [bindep : Look for bindep command] 2025-10-13 14:32:24.346485 | controller | skipping: Conditional result was False 2025-10-13 14:32:24.357878 | 2025-10-13 14:32:24.358058 | TASK [bindep : Check for system bindep] 2025-10-13 14:32:24.896044 | controller | ok: Runtime: 0:00:00.008225 2025-10-13 14:32:24.902633 | 2025-10-13 14:32:24.902790 | TASK [bindep : Define bindep_command fact] 2025-10-13 14:32:24.926937 | controller | skipping: Conditional result was False 2025-10-13 14:32:24.936016 | 2025-10-13 14:32:24.936169 | TASK [bindep : Include install tasks] 2025-10-13 14:32:24.969849 | controller | ok 2025-10-13 14:32:24.982805 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 14:32:25.010420 | 2025-10-13 14:32:25.010533 | TASK [bindep : Create temp dir for bindep] 2025-10-13 14:32:25.483315 | controller | changed 2025-10-13 14:32:25.495906 | 2025-10-13 14:32:25.496018 | TASK [Ensure we have pip dependencies] 2025-10-13 14:32:25.554740 | controller | ok 2025-10-13 14:32:25.610813 | 2025-10-13 14:32:25.610935 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 10:32:25.882072 | controller | /usr/bin/pip3 2025-10-13 10:32:25.904723 | controller | /usr/bin/python3: No module named wheel 2025-10-13 14:32:26.147440 | controller | ok: Runtime: 0:00:00.034222 2025-10-13 14:32:26.163218 | 2025-10-13 14:32:26.163335 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 14:32:26.218905 | controller | ok: "/var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 14:32:26.232554 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 14:32:26.247268 | 2025-10-13 14:32:26.247442 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 14:32:28.746847 | controller | changed 2025-10-13 14:32:28.752617 | 2025-10-13 14:32:28.752709 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 14:32:28.786949 | controller | skipping: Conditional result was False 2025-10-13 14:32:28.793766 | 2025-10-13 14:32:28.793859 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 14:32:28.833593 | controller | skipping: Conditional result was False 2025-10-13 14:32:28.844232 | 2025-10-13 14:32:28.844346 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 14:32:28.881177 | controller | skipping: Conditional result was False 2025-10-13 14:32:28.891813 | 2025-10-13 14:32:28.891934 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 14:32:28.907367 | controller | skipping: Conditional result was False 2025-10-13 14:32:28.916474 | 2025-10-13 14:32:28.916627 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 14:32:29.457601 | controller | skipping: Conditional result was False 2025-10-13 14:32:29.470332 | 2025-10-13 14:32:29.470461 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 14:32:29.497087 | controller | skipping: Conditional result was False 2025-10-13 14:32:29.506398 | 2025-10-13 14:32:29.506497 | TASK [ensure-pip : Install pip from source] 2025-10-13 14:32:29.532568 | controller | skipping: Conditional result was False 2025-10-13 14:32:29.538520 | 2025-10-13 14:32:29.538606 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 10:32:29.803752 | controller | /usr/bin/python3 2025-10-13 14:32:30.077229 | controller | ok: Runtime: 0:00:00.009670 2025-10-13 14:32:30.083369 | 2025-10-13 14:32:30.083439 | TASK [ensure-pip : Set host default] 2025-10-13 14:32:30.144196 | controller | ok 2025-10-13 14:32:30.150354 | 2025-10-13 14:32:30.150424 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 14:32:30.205655 | controller | ok 2025-10-13 14:32:30.215987 | 2025-10-13 14:32:30.216054 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 14:32:34.502955 | controller | changed 2025-10-13 14:32:34.513066 | 2025-10-13 14:32:34.513305 | TASK [bindep : Define bindep_command] 2025-10-13 14:32:34.552032 | controller | ok 2025-10-13 14:32:34.558338 | 2025-10-13 14:32:34.558407 | LOOP [bindep : Include package tasks] 2025-10-13 14:32:34.604004 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 14:32:34.604247 | controller | ok: All items complete 2025-10-13 14:32:34.604275 | 2025-10-13 14:32:34.621537 | controller | included: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 14:32:34.631637 | 2025-10-13 14:32:34.631728 | TASK [bindep : Define bindep_run fact] 2025-10-13 14:32:34.664362 | controller | ok 2025-10-13 14:32:34.670626 | 2025-10-13 14:32:34.670752 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 10:32:36.263312 | controller | podman 2025-10-13 10:32:36.296943 | controller | python3-jmespath 2025-10-13 10:32:36.297044 | controller | python3-libvirt 2025-10-13 10:32:36.297056 | controller | python3-lxml 2025-10-13 10:32:36.297110 | controller | python3-netaddr 2025-10-13 14:32:36.708282 | controller | ok: Runtime: 0:00:01.359997 2025-10-13 14:32:36.721459 | 2025-10-13 14:32:36.721637 | TASK [bindep : Install distro packages from bindep] 2025-10-13 14:33:41.000153 | controller | changed 2025-10-13 14:33:41.015539 | 2025-10-13 14:33:41.015786 | TASK [bindep : Check that packages are installed] 2025-10-13 14:33:42.563564 | controller | ok: Runtime: 0:00:01.144924 2025-10-13 14:33:42.576761 | 2025-10-13 14:33:42.577028 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 14:33:42.606781 | controller | skipping: Conditional result was False 2025-10-13 14:33:42.630823 | 2025-10-13 14:33:42.631087 | TASK [Run test-setup role] 2025-10-13 14:33:42.655141 | controller | ok 2025-10-13 14:33:42.683631 | 2025-10-13 14:33:42.683822 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 14:33:42.899965 | controller | ok 2025-10-13 14:33:42.907060 | 2025-10-13 14:33:42.907148 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 14:33:43.447639 | controller | skipping: Conditional result was False 2025-10-13 14:33:43.467158 | 2025-10-13 14:33:43.467241 | TASK [bindep : Remove bindep temp dir] 2025-10-13 14:33:43.860567 | controller | ok 2025-10-13 14:33:43.900021 | 2025-10-13 14:33:43.900155 | PLAY RECAP 2025-10-13 14:33:43.900214 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 14:33:43.900244 | 2025-10-13 14:33:44.032586 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:33:44.033483 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:33:44.566777 | 2025-10-13 14:33:44.566888 | PLAY [all] 2025-10-13 14:33:44.586290 | 2025-10-13 14:33:44.586383 | TASK [Abort when test_command variable is undefined] 2025-10-13 14:33:44.621486 | controller | skipping: Conditional result was False 2025-10-13 14:33:44.627007 | 2025-10-13 14:33:44.627080 | TASK [Convert test_command to list] 2025-10-13 14:33:44.660398 | controller | skipping: Conditional result was False 2025-10-13 14:33:44.666919 | 2025-10-13 14:33:44.666987 | TASK [Use test_command list] 2025-10-13 14:33:44.747124 | controller | ok 2025-10-13 14:33:44.754329 | 2025-10-13 14:33:44.754390 | LOOP [Run test_command] 2025-10-13 14:33:45.178314 | controller | no check to run 2025-10-13 14:33:45.178576 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005861 2025-10-13 14:33:45.229304 | 2025-10-13 14:33:45.229425 | PLAY RECAP 2025-10-13 14:33:45.229479 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:33:45.229518 | 2025-10-13 14:33:45.333564 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:33:45.335365 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:33:45.980061 | 2025-10-13 14:33:45.980204 | PLAY [all] 2025-10-13 14:33:46.001074 | 2025-10-13 14:33:46.001166 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 14:33:46.333336 | controller | changed: non-zero return code 2025-10-13 14:33:46.346197 | 2025-10-13 14:33:46.346355 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 14:33:46.363578 | controller | skipping: Conditional result was False 2025-10-13 14:33:46.371456 | 2025-10-13 14:33:46.371548 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 14:33:46.394457 | 2025-10-13 14:33:46.394616 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 14:33:46.416899 | 2025-10-13 14:33:46.417051 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 14:33:46.431661 | controller | skipping: Conditional result was False 2025-10-13 14:33:46.439870 | 2025-10-13 14:33:46.439969 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 14:33:46.462663 | 2025-10-13 14:33:46.462838 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 14:33:46.477994 | controller | skipping: Conditional result was False 2025-10-13 14:33:46.487625 | 2025-10-13 14:33:46.487737 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 14:33:46.512858 | controller | skipping: Conditional result was False 2025-10-13 14:33:46.520453 | 2025-10-13 14:33:46.520555 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 14:33:46.545416 | controller | skipping: Conditional result was False 2025-10-13 14:33:46.579521 | 2025-10-13 14:33:46.579631 | PLAY RECAP 2025-10-13 14:33:46.579705 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 14:33:46.579739 | 2025-10-13 14:33:46.697811 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:33:46.699454 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:33:47.276477 | 2025-10-13 14:33:47.276603 | PLAY [all] 2025-10-13 14:33:47.296089 | 2025-10-13 14:33:47.296171 | TASK [include_role : fetch-output] 2025-10-13 14:33:47.346024 | controller | ok 2025-10-13 14:33:47.368012 | 2025-10-13 14:33:47.368248 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 14:33:47.453933 | controller | skipping: Conditional result was False 2025-10-13 14:33:47.459726 | 2025-10-13 14:33:47.459794 | TASK [fetch-output : Set log path for single node] 2025-10-13 14:33:47.514305 | controller | ok 2025-10-13 14:33:47.519584 | 2025-10-13 14:33:47.519651 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 14:33:47.895875 | controller -> localhost | ok: "/var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/logs" 2025-10-13 14:33:48.104490 | controller -> localhost | changed: "/var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/artifacts" 2025-10-13 14:33:48.357869 | controller -> localhost | changed: "/var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/docs" 2025-10-13 14:33:48.385517 | 2025-10-13 14:33:48.385735 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 14:33:49.061745 | controller | changed: .d..t...... ./ 2025-10-13 14:33:49.061993 | controller | changed: All items complete 2025-10-13 14:33:49.062031 | 2025-10-13 14:33:49.649258 | controller | changed: .d..t...... ./ 2025-10-13 14:33:50.138177 | controller | changed: .d..t...... ./ 2025-10-13 14:33:50.167653 | 2025-10-13 14:33:50.167853 | TASK [include_role : fetch-output-openshift] 2025-10-13 14:33:50.196041 | controller | skipping: Conditional result was False 2025-10-13 14:33:50.205627 | 2025-10-13 14:33:50.205793 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 14:33:50.706995 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013025 2025-10-13 14:33:50.961473 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.025541 2025-10-13 14:33:51.006773 | 2025-10-13 14:33:51.006927 | PLAY [all] 2025-10-13 14:33:51.021764 | 2025-10-13 14:33:51.021836 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 14:33:51.467896 | controller | changed 2025-10-13 14:33:51.506352 | 2025-10-13 14:33:51.506449 | PLAY RECAP 2025-10-13 14:33:51.506487 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:33:51.506508 | 2025-10-13 14:33:51.649845 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:33:51.650760 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 14:33:52.396789 | 2025-10-13 14:33:52.396911 | PLAY [localhost] 2025-10-13 14:33:52.419483 | 2025-10-13 14:33:52.419605 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 14:33:52.842527 | localhost | changed 2025-10-13 14:33:52.852927 | 2025-10-13 14:33:52.853043 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 14:33:52.901254 | localhost | ok 2025-10-13 14:33:52.910094 | 2025-10-13 14:33:52.910201 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 14:33:53.273402 | localhost | changed 2025-10-13 14:33:53.279104 | 2025-10-13 14:33:53.279171 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 14:33:54.022503 | localhost | changed 2025-10-13 14:33:54.042078 | 2025-10-13 14:33:54.042282 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 14:33:54.567368 | localhost | Identity added: /var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/tmp/ansible.r135na58 (/var/lib/zuul/builds/7b881291c4fd4678826a4d2ec470711e/work/tmp/ansible.r135na58) 2025-10-13 14:33:54.567580 | localhost | ok: Runtime: 0:00:00.014623 2025-10-13 14:33:54.577894 | 2025-10-13 14:33:54.577980 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 14:33:54.949943 | localhost | ok: Runtime: 0:00:00.009054 2025-10-13 14:33:54.962408 | 2025-10-13 14:33:54.962556 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 14:33:55.059498 | localhost | changed 2025-10-13 14:33:55.080056 | 2025-10-13 14:33:55.080217 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 14:33:55.568288 | localhost | changed 2025-10-13 14:33:55.610641 | 2025-10-13 14:33:55.610784 | PLAY [localhost] 2025-10-13 14:33:55.633567 | 2025-10-13 14:33:55.633718 | TASK [Generate bulk log download script] 2025-10-13 14:33:55.666235 | localhost | ok 2025-10-13 14:33:55.684669 | 2025-10-13 14:33:55.684837 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 14:33:55.735622 | localhost | ok: All assertions passed 2025-10-13 14:33:55.740735 | 2025-10-13 14:33:55.740833 | TASK [local-log-download : Create download script] 2025-10-13 14:33:56.311766 | localhost -> localhost | changed 2025-10-13 14:33:56.321209 | 2025-10-13 14:33:56.321336 | TASK [Register quick-download link] 2025-10-13 14:33:56.340822 | localhost | ok 2025-10-13 14:33:56.387725 | 2025-10-13 14:33:56.387821 | PLAY [logserver.rdoproject.org] 2025-10-13 14:33:56.397752 | 2025-10-13 14:33:56.397820 | TASK [Set zuul-log-path fact] 2025-10-13 14:33:56.413972 | logserver.rdoproject.org | ok 2025-10-13 14:33:56.423948 | 2025-10-13 14:33:56.424025 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:33:56.451154 | logserver.rdoproject.org | ok 2025-10-13 14:33:56.456845 | 2025-10-13 14:33:56.456905 | TASK [upload-logs : Create log directories] 2025-10-13 14:33:57.131788 | logserver.rdoproject.org | changed 2025-10-13 14:33:57.140191 | 2025-10-13 14:33:57.140334 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 14:33:57.517937 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006238 2025-10-13 14:33:57.522860 | 2025-10-13 14:33:57.522953 | TASK [upload-logs : Upload logs to log server] 2025-10-13 14:33:58.190963 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 14:33:58.193903 | 2025-10-13 14:33:58.193987 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 14:33:58.234824 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:33:58.258303 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:33:58.262193 | 2025-10-13 14:33:58.262265 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 14:33:58.304771 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:33:58.305006 | 2025-10-13 14:33:58.308701 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:33:58.320322 | 2025-10-13 14:33:58.320415 | LOOP [upload-logs : Upload console log and json output]