2025-12-17 09:39:58.598799 | Job console starting... 2025-12-17 09:39:58.626770 | Updating repositories 2025-12-17 09:39:58.664486 | Preparing job workspace 2025-12-17 09:40:04.534421 | Running Ansible setup... 2025-12-17 09:40:09.052723 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-17 09:40:10.093514 | 2025-12-17 09:40:10.093674 | PLAY [localhost] 2025-12-17 09:40:10.112932 | 2025-12-17 09:40:10.113079 | TASK [Gathering Facts] 2025-12-17 09:40:11.634371 | localhost | ok 2025-12-17 09:40:11.652366 | 2025-12-17 09:40:11.652570 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-17 09:40:12.507808 | localhost -> localhost | changed 2025-12-17 09:40:12.519633 | 2025-12-17 09:40:12.519755 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-17 09:40:13.771647 | localhost -> localhost | changed 2025-12-17 09:40:13.782316 | 2025-12-17 09:40:13.782427 | TASK [Setup log path fact] 2025-12-17 09:40:13.841309 | localhost | ok 2025-12-17 09:40:13.874844 | 2025-12-17 09:40:13.874981 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-17 09:40:13.906647 | localhost | ok 2025-12-17 09:40:13.915122 | 2025-12-17 09:40:13.915235 | TASK [emit-job-header : Print job information] 2025-12-17 09:40:13.946889 | # Job Information 2025-12-17 09:40:13.947118 | Ansible Version: 2.15.12 2025-12-17 09:40:13.947146 | Job: cifmw-molecule-cifmw_external_dns 2025-12-17 09:40:13.947167 | Pipeline: github-check 2025-12-17 09:40:13.947186 | Executor: ze01.softwarefactory-project.io 2025-12-17 09:40:13.947205 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451 2025-12-17 09:40:13.947224 | Log URL (when completed): https://logserver.rdoproject.org/3a2/rdoproject.org/3a26a4937ce9400ca2e90ff0d6d1b169/ 2025-12-17 09:40:13.947242 | Event ID: 187218e0-db2c-11f0-951e-56c3f6f4f79d 2025-12-17 09:40:13.951389 | 2025-12-17 09:40:13.951484 | LOOP [emit-job-header : Print node information] 2025-12-17 09:40:14.091448 | localhost | ok: 2025-12-17 09:40:14.091616 | localhost | # Node Information 2025-12-17 09:40:14.091655 | localhost | Inventory Hostname: controller 2025-12-17 09:40:14.091688 | localhost | Hostname: np0005563367 2025-12-17 09:40:14.091717 | localhost | Username: zuul 2025-12-17 09:40:14.091743 | localhost | Distro: CentOS 9 2025-12-17 09:40:14.091764 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-17 09:40:14.091783 | localhost | Region: RegionOne 2025-12-17 09:40:14.091800 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-17 09:40:14.091817 | localhost | Product Name: OpenStack Nova 2025-12-17 09:40:14.091834 | localhost | Interface IP: 38.129.56.41 2025-12-17 09:40:14.123610 | 2025-12-17 09:40:14.123715 | PLAY [all] 2025-12-17 09:40:14.171949 | 2025-12-17 09:40:14.172100 | TASK [Gather network facts] 2025-12-17 09:40:14.643907 | controller | ok 2025-12-17 09:40:14.674313 | 2025-12-17 09:40:14.674435 | TASK [include_role : start-zuul-console] 2025-12-17 09:40:14.692655 | controller | ok 2025-12-17 09:40:14.707554 | 2025-12-17 09:40:14.707677 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-17 09:40:15.168540 | controller | ok 2025-12-17 09:40:15.188079 | 2025-12-17 09:40:15.188214 | TASK [include_role : add-build-sshkey] 2025-12-17 09:40:15.218963 | controller | ok 2025-12-17 09:40:15.235078 | 2025-12-17 09:40:15.235198 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-17 09:40:15.537372 | controller -> localhost | ok 2025-12-17 09:40:15.543597 | 2025-12-17 09:40:15.543660 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-17 09:40:15.620945 | controller | ok 2025-12-17 09:40:15.657786 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-17 09:40:15.692626 | 2025-12-17 09:40:15.692729 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-17 09:40:16.561436 | controller -> localhost | Generating public/private rsa key pair. 2025-12-17 09:40:16.561618 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/3a26a4937ce9400ca2e90ff0d6d1b169_id_rsa. 2025-12-17 09:40:16.561671 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/3a26a4937ce9400ca2e90ff0d6d1b169_id_rsa.pub. 2025-12-17 09:40:16.561696 | controller -> localhost | The key fingerprint is: 2025-12-17 09:40:16.561717 | controller -> localhost | SHA256:Xd5KWHk6phdzHvsu5UExrvpGQTGEYkd4VT5QtCLGPhw zuul-build-sshkey 2025-12-17 09:40:16.561738 | controller -> localhost | The key's randomart image is: 2025-12-17 09:40:16.561758 | controller -> localhost | +---[RSA 3072]----+ 2025-12-17 09:40:16.561776 | controller -> localhost | | o.+*=+ | 2025-12-17 09:40:16.561796 | controller -> localhost | | +.+ o+o.| 2025-12-17 09:40:16.561815 | controller -> localhost | | . +E=.o+o| 2025-12-17 09:40:16.561833 | controller -> localhost | | .+=o=.o.| 2025-12-17 09:40:16.561850 | controller -> localhost | | S o+O B | 2025-12-17 09:40:16.561867 | controller -> localhost | | +.X +.| 2025-12-17 09:40:16.561884 | controller -> localhost | | . = oo.| 2025-12-17 09:40:16.561902 | controller -> localhost | | o ....| 2025-12-17 09:40:16.561919 | controller -> localhost | | o. oo| 2025-12-17 09:40:16.561937 | controller -> localhost | +----[SHA256]-----+ 2025-12-17 09:40:16.561984 | controller -> localhost | ok: Runtime: 0:00:00.040171 2025-12-17 09:40:16.567932 | 2025-12-17 09:40:16.568000 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-17 09:40:16.621623 | controller | ok 2025-12-17 09:40:16.642978 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-17 09:40:16.670736 | 2025-12-17 09:40:16.670863 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-17 09:40:16.715049 | controller | skipping: Conditional result was False 2025-12-17 09:40:16.720792 | 2025-12-17 09:40:16.720865 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-17 09:40:17.352628 | controller | changed 2025-12-17 09:40:17.360804 | 2025-12-17 09:40:17.360930 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-17 09:40:17.631286 | controller | ok 2025-12-17 09:40:17.643951 | 2025-12-17 09:40:17.644060 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-17 09:40:18.471447 | controller | changed 2025-12-17 09:40:18.491552 | 2025-12-17 09:40:18.491697 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-17 09:40:19.324025 | controller | changed 2025-12-17 09:40:19.329799 | 2025-12-17 09:40:19.329924 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-17 09:40:19.354115 | controller | skipping: Conditional result was False 2025-12-17 09:40:19.359784 | 2025-12-17 09:40:19.360114 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-17 09:40:19.845314 | controller -> localhost | changed 2025-12-17 09:40:19.854911 | 2025-12-17 09:40:19.855148 | TASK [add-build-sshkey : Add back temp key] 2025-12-17 09:40:20.134185 | controller -> localhost | Identity added: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/3a26a4937ce9400ca2e90ff0d6d1b169_id_rsa (zuul-build-sshkey) 2025-12-17 09:40:20.134369 | controller -> localhost | ok: Runtime: 0:00:00.008822 2025-12-17 09:40:20.140467 | 2025-12-17 09:40:20.140567 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-17 09:40:20.527684 | controller | ok 2025-12-17 09:40:20.534363 | 2025-12-17 09:40:20.534537 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-17 09:40:20.568734 | controller | skipping: Conditional result was False 2025-12-17 09:40:20.583473 | 2025-12-17 09:40:20.583599 | TASK [include_role : validate-host] 2025-12-17 09:40:20.606705 | controller | ok 2025-12-17 09:40:20.672697 | 2025-12-17 09:40:20.672821 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-17 09:40:20.702004 | controller | ok 2025-12-17 09:40:20.707148 | 2025-12-17 09:40:20.707212 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-17 09:40:20.962982 | controller -> localhost | ok 2025-12-17 09:40:20.969440 | 2025-12-17 09:40:20.969526 | TASK [validate-host : Collect information about the host] 2025-12-17 09:40:21.760673 | controller | ok 2025-12-17 09:40:21.775995 | 2025-12-17 09:40:21.776131 | TASK [validate-host : Sanitize hostname] 2025-12-17 09:40:21.838648 | controller | ok 2025-12-17 09:40:21.844316 | 2025-12-17 09:40:21.844406 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-17 09:40:22.402752 | controller -> localhost | changed 2025-12-17 09:40:22.408882 | 2025-12-17 09:40:22.408972 | TASK [validate-host : Collect information about zuul worker] 2025-12-17 09:40:22.805332 | controller | ok 2025-12-17 09:40:22.810661 | 2025-12-17 09:40:22.810747 | TASK [validate-host : Write out all zuul information for each host] 2025-12-17 09:40:23.400316 | controller -> localhost | changed 2025-12-17 09:40:23.416880 | 2025-12-17 09:40:23.417058 | TASK [include_role : prepare-workspace-openshift] 2025-12-17 09:40:23.442102 | controller | skipping: Conditional result was False 2025-12-17 09:40:23.448328 | 2025-12-17 09:40:23.448394 | TASK [include_role : remove-zuul-sshkey] 2025-12-17 09:40:23.472145 | controller | skipping: Conditional result was False 2025-12-17 09:40:23.482256 | 2025-12-17 09:40:23.482338 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-17 09:40:23.729301 | controller | ok: "logs" 2025-12-17 09:40:23.729551 | controller | ok: All items complete 2025-12-17 09:40:23.729580 | 2025-12-17 09:40:23.944968 | controller | ok: "artifacts" 2025-12-17 09:40:24.158286 | controller | ok: "docs" 2025-12-17 09:40:24.173621 | 2025-12-17 09:40:24.173754 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-17 09:40:24.424740 | controller | changed: "logs" 2025-12-17 09:40:24.628761 | controller | changed: "artifacts" 2025-12-17 09:40:24.854701 | controller | changed: "docs" 2025-12-17 09:40:24.910400 | 2025-12-17 09:40:24.910524 | PLAY RECAP 2025-12-17 09:40:24.910582 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-17 09:40:24.910621 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-17 09:40:24.910647 | 2025-12-17 09:40:25.042316 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-17 09:40:25.043182 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-17 09:40:25.697358 | 2025-12-17 09:40:25.697479 | PLAY [localhost] 2025-12-17 09:40:25.714650 | 2025-12-17 09:40:25.714779 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-17 09:40:26.182174 | localhost | ok 2025-12-17 09:40:26.189032 | 2025-12-17 09:40:26.189144 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-17 09:40:26.983614 | localhost | changed 2025-12-17 09:40:27.004543 | 2025-12-17 09:40:27.004640 | PLAY [all] 2025-12-17 09:40:27.020416 | 2025-12-17 09:40:27.020505 | TASK [include_role : prepare-workspace] 2025-12-17 09:40:27.039464 | controller | ok 2025-12-17 09:40:27.054359 | 2025-12-17 09:40:27.054460 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-17 09:40:27.428811 | controller | ok 2025-12-17 09:40:27.436873 | 2025-12-17 09:40:27.436965 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-17 09:40:29.595623 | controller | Output suppressed because no_log was given 2025-12-17 09:40:29.608967 | 2025-12-17 09:40:29.609405 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-17 09:40:29.862582 | controller | changed: "logs" 2025-12-17 09:40:30.076425 | controller | changed: "artifacts" 2025-12-17 09:40:30.315199 | controller | changed: "docs" 2025-12-17 09:40:30.327807 | 2025-12-17 09:40:30.327927 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-17 09:40:30.612423 | controller | changed: "logs" 2025-12-17 09:40:30.612728 | controller | changed: All items complete 2025-12-17 09:40:30.612761 | 2025-12-17 09:40:30.817279 | controller | changed: "artifacts" 2025-12-17 09:40:31.006761 | controller | changed: "docs" 2025-12-17 09:40:31.028282 | 2025-12-17 09:40:31.028483 | TASK [Check if worker can sudo] 2025-12-17 09:40:31.571832 | controller | ok: Runtime: 0:00:00.027867 2025-12-17 09:40:31.580137 | 2025-12-17 09:40:31.580277 | TASK [configure-mirrors : Gather needed facts] 2025-12-17 09:40:31.761091 | controller | skipping: Conditional result was False 2025-12-17 09:40:31.768917 | 2025-12-17 09:40:31.769090 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-17 09:40:31.985119 | controller | ok 2025-12-17 09:40:31.993195 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-17 09:40:31.998885 | 2025-12-17 09:40:31.998954 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-17 09:40:32.286765 | controller | ok 2025-12-17 09:40:32.295241 | 2025-12-17 09:40:32.295327 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-17 09:40:32.372668 | controller | ok: "/var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-17 09:40:32.390732 | 2025-12-17 09:40:32.390901 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-17 09:40:33.387187 | controller | changed 2025-12-17 09:40:33.393545 | 2025-12-17 09:40:33.393667 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-17 09:40:33.463468 | controller | ok: "/var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-17 09:40:33.463710 | controller | ok: All items complete 2025-12-17 09:40:33.463736 | 2025-12-17 09:40:33.530583 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-17 09:40:33.540234 | 2025-12-17 09:40:33.540362 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-17 09:40:34.420898 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-17 09:40:35.327561 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-17 09:40:35.344415 | 2025-12-17 09:40:35.344553 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-17 09:40:36.016817 | controller | changed: section and option added 2025-12-17 09:40:36.046465 | 2025-12-17 09:40:36.046689 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-17 09:40:36.698921 | controller | 29 files removed 2025-12-17 09:40:36.699247 | controller | ok: Item: dnf clean all Runtime: 0:00:00.351028 2025-12-17 09:40:36.699298 | controller | changed: All items complete 2025-12-17 09:40:36.699319 | 2025-12-17 09:40:48.035203 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-17 09:40:48.035766 | controller | DNF version: 4.14.0 2025-12-17 09:40:48.035807 | controller | cachedir: /var/cache/dnf 2025-12-17 09:40:48.035829 | controller | Making cache files for all metadata files. 2025-12-17 09:40:48.035848 | controller | baseos: has expired and will be refreshed. 2025-12-17 09:40:48.035865 | controller | appstream: has expired and will be refreshed. 2025-12-17 09:40:48.035881 | controller | crb: has expired and will be refreshed. 2025-12-17 09:40:48.036183 | controller | extras-common: has expired and will be refreshed. 2025-12-17 09:40:48.036214 | controller | repo: downloading from remote: baseos 2025-12-17 09:40:48.036233 | controller | CentOS Stream 9 - BaseOS 61 MB/s | 8.8 MB 00:00 2025-12-17 09:40:48.036250 | controller | baseos: using metadata from Mon 15 Dec 2025 11:30:30 AM EST. 2025-12-17 09:40:48.036266 | controller | repo: downloading from remote: appstream 2025-12-17 09:40:48.036282 | controller | CentOS Stream 9 - AppStream 66 MB/s | 26 MB 00:00 2025-12-17 09:40:48.036298 | controller | appstream: using metadata from Mon 15 Dec 2025 11:33:53 AM EST. 2025-12-17 09:40:48.036313 | controller | repo: downloading from remote: crb 2025-12-17 09:40:48.036329 | controller | CentOS Stream 9 - CRB 44 MB/s | 7.4 MB 00:00 2025-12-17 09:40:48.036345 | controller | crb: using metadata from Mon 15 Dec 2025 11:38:02 AM EST. 2025-12-17 09:40:48.036361 | controller | repo: downloading from remote: extras-common 2025-12-17 09:40:48.036392 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-12-17 09:40:48.036410 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-17 09:40:48.036426 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-17 09:40:48.036442 | controller | Completion plugin: Generating completion cache... 2025-12-17 09:40:48.036458 | controller | Metadata cache created. 2025-12-17 09:40:48.036487 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.093050 2025-12-17 09:40:48.078797 | 2025-12-17 09:40:48.079412 | PLAY RECAP 2025-12-17 09:40:48.079472 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-17 09:40:48.079500 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-17 09:40:48.079518 | 2025-12-17 09:40:48.377280 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-17 09:40:48.378487 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-17 09:40:49.578934 | 2025-12-17 09:40:49.579088 | PLAY [all] 2025-12-17 09:40:49.647399 | 2025-12-17 09:40:49.647547 | TASK [Install binary dependencies] 2025-12-17 09:40:49.804822 | controller | ok 2025-12-17 09:40:49.859239 | 2025-12-17 09:40:49.859391 | TASK [bindep : Include find tasks] 2025-12-17 09:40:49.933814 | controller | ok 2025-12-17 09:40:49.948199 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-17 09:40:49.955207 | 2025-12-17 09:40:49.955287 | TASK [bindep : Look for bindep.txt] 2025-12-17 09:40:50.501320 | controller | ok 2025-12-17 09:40:50.509622 | 2025-12-17 09:40:50.509736 | TASK [bindep : Define bindep_file fact] 2025-12-17 09:40:50.568138 | controller | ok 2025-12-17 09:40:50.586284 | 2025-12-17 09:40:50.586591 | TASK [bindep : Look for other-requirements.txt] 2025-12-17 09:40:50.612086 | controller | skipping: Conditional result was False 2025-12-17 09:40:50.617952 | 2025-12-17 09:40:50.618049 | TASK [bindep : Define bindep_file fact] 2025-12-17 09:40:50.693857 | controller | skipping: Conditional result was False 2025-12-17 09:40:50.700100 | 2025-12-17 09:40:50.700190 | TASK [bindep : Look for bindep fallback file] 2025-12-17 09:40:50.765918 | controller | skipping: Conditional result was False 2025-12-17 09:40:50.772925 | 2025-12-17 09:40:50.773085 | TASK [bindep : Define bindep_file fact] 2025-12-17 09:40:50.838618 | controller | skipping: Conditional result was False 2025-12-17 09:40:50.845786 | 2025-12-17 09:40:50.845869 | TASK [bindep : Include bindep tasks] 2025-12-17 09:40:50.905964 | controller | ok 2025-12-17 09:40:50.915584 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-17 09:40:50.929772 | 2025-12-17 09:40:50.929997 | TASK [bindep : Look for bindep command] 2025-12-17 09:40:50.977876 | controller | skipping: Conditional result was False 2025-12-17 09:40:50.987738 | 2025-12-17 09:40:50.988157 | TASK [bindep : Check for system bindep] 2025-12-17 09:40:52.081283 | controller | ok: Runtime: 0:00:00.007423 2025-12-17 09:40:52.087955 | 2025-12-17 09:40:52.088072 | TASK [bindep : Define bindep_command fact] 2025-12-17 09:40:52.114355 | controller | skipping: Conditional result was False 2025-12-17 09:40:52.121536 | 2025-12-17 09:40:52.121653 | TASK [bindep : Include install tasks] 2025-12-17 09:40:52.157462 | controller | ok 2025-12-17 09:40:52.167621 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-17 09:40:52.178316 | 2025-12-17 09:40:52.178399 | TASK [bindep : Create temp dir for bindep] 2025-12-17 09:40:52.624833 | controller | changed 2025-12-17 09:40:52.631376 | 2025-12-17 09:40:52.631523 | TASK [Ensure we have pip dependencies] 2025-12-17 09:40:52.652478 | controller | ok 2025-12-17 09:40:52.677873 | 2025-12-17 09:40:52.677984 | TASK [ensure-pip : Check if pip is installed] 2025-12-17 04:40:52.948047 | controller | /usr/bin/pip3 2025-12-17 04:40:52.970465 | controller | /usr/bin/python3: No module named wheel 2025-12-17 09:40:53.208704 | controller | ok: Runtime: 0:00:00.032656 2025-12-17 09:40:53.218537 | 2025-12-17 09:40:53.218671 | LOOP [ensure-pip : Install pip from packages] 2025-12-17 09:40:53.288437 | controller | ok: "/var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-17 09:40:53.300432 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-17 09:40:53.317143 | 2025-12-17 09:40:53.317272 | TASK [ensure-pip : Install Python 3 pip] 2025-12-17 09:40:55.203661 | controller | changed 2025-12-17 09:40:55.214374 | 2025-12-17 09:40:55.214512 | TASK [ensure-pip : Check for EPEL repository] 2025-12-17 09:40:55.259568 | controller | skipping: Conditional result was False 2025-12-17 09:40:55.265910 | 2025-12-17 09:40:55.266293 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-17 09:40:55.311612 | controller | skipping: Conditional result was False 2025-12-17 09:40:55.318438 | 2025-12-17 09:40:55.318550 | TASK [ensure-pip : Install Python 2 pip] 2025-12-17 09:40:55.354113 | controller | skipping: Conditional result was False 2025-12-17 09:40:55.362042 | 2025-12-17 09:40:55.362207 | TASK [ensure-pip : Ensure setuptools] 2025-12-17 09:40:55.376625 | controller | skipping: Conditional result was False 2025-12-17 09:40:55.383778 | 2025-12-17 09:40:55.383893 | TASK [ensure-pip : Check for ensurepip module] 2025-12-17 09:40:55.914622 | controller | skipping: Conditional result was False 2025-12-17 09:40:55.925797 | 2025-12-17 09:40:55.926051 | TASK [ensure-pip : Ensure python3-venv] 2025-12-17 09:40:55.964607 | controller | skipping: Conditional result was False 2025-12-17 09:40:55.978417 | 2025-12-17 09:40:55.978581 | TASK [ensure-pip : Install pip from source] 2025-12-17 09:40:56.005643 | controller | skipping: Conditional result was False 2025-12-17 09:40:56.015334 | 2025-12-17 09:40:56.015462 | TASK [ensure-pip : Probe for venv python full path] 2025-12-17 04:40:56.298707 | controller | /usr/bin/python3 2025-12-17 09:40:56.558320 | controller | ok: Runtime: 0:00:00.006215 2025-12-17 09:40:56.567799 | 2025-12-17 09:40:56.567927 | TASK [ensure-pip : Set host default] 2025-12-17 09:40:56.633492 | controller | ok 2025-12-17 09:40:56.648349 | 2025-12-17 09:40:56.648560 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-17 09:40:56.715520 | controller | ok 2025-12-17 09:40:56.730542 | 2025-12-17 09:40:56.730675 | TASK [bindep : Install bindep into temporary venv] 2025-12-17 09:41:00.943802 | controller | changed 2025-12-17 09:41:00.957528 | 2025-12-17 09:41:00.957702 | TASK [bindep : Define bindep_command] 2025-12-17 09:41:00.991902 | controller | ok 2025-12-17 09:41:00.999731 | 2025-12-17 09:41:00.999881 | LOOP [bindep : Include package tasks] 2025-12-17 09:41:01.048642 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-17 09:41:01.048881 | controller | ok: All items complete 2025-12-17 09:41:01.048908 | 2025-12-17 09:41:01.069469 | controller | included: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-17 09:41:01.092903 | 2025-12-17 09:41:01.093094 | TASK [bindep : Define bindep_run fact] 2025-12-17 09:41:01.128435 | controller | ok 2025-12-17 09:41:01.134527 | 2025-12-17 09:41:01.134600 | TASK [bindep : Get list of packages to install from bindep] 2025-12-17 04:41:02.434369 | controller | podman 2025-12-17 04:41:02.472672 | controller | python3-jmespath 2025-12-17 04:41:02.472798 | controller | python3-libvirt 2025-12-17 04:41:02.472808 | controller | python3-lxml 2025-12-17 04:41:02.472819 | controller | python3-netaddr 2025-12-17 09:41:02.670277 | controller | ok: Runtime: 0:00:01.093959 2025-12-17 09:41:02.678854 | 2025-12-17 09:41:02.678968 | TASK [bindep : Install distro packages from bindep] 2025-12-17 09:42:04.451225 | controller | changed 2025-12-17 09:42:04.467186 | 2025-12-17 09:42:04.467355 | TASK [bindep : Check that packages are installed] 2025-12-17 09:42:06.021224 | controller | ok: Runtime: 0:00:01.169598 2025-12-17 09:42:06.037697 | 2025-12-17 09:42:06.037921 | TASK [bindep : Fail if we cannot install all packages] 2025-12-17 09:42:06.077082 | controller | skipping: Conditional result was False 2025-12-17 09:42:06.107257 | 2025-12-17 09:42:06.107457 | TASK [Run test-setup role] 2025-12-17 09:42:06.134309 | controller | ok 2025-12-17 09:42:06.161563 | 2025-12-17 09:42:06.161690 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-17 09:42:06.408312 | controller | ok 2025-12-17 09:42:06.415740 | 2025-12-17 09:42:06.415850 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-17 09:42:06.951133 | controller | skipping: Conditional result was False 2025-12-17 09:42:06.978006 | 2025-12-17 09:42:06.978184 | TASK [bindep : Remove bindep temp dir] 2025-12-17 09:42:07.407826 | controller | ok 2025-12-17 09:42:07.430519 | 2025-12-17 09:42:07.430639 | PLAY RECAP 2025-12-17 09:42:07.430740 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-17 09:42:07.430777 | 2025-12-17 09:42:07.601181 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-17 09:42:07.602170 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-17 09:42:08.276856 | 2025-12-17 09:42:08.276983 | PLAY [all] 2025-12-17 09:42:08.307523 | 2025-12-17 09:42:08.307635 | TASK [Abort when test_command variable is undefined] 2025-12-17 09:42:08.352239 | controller | skipping: Conditional result was False 2025-12-17 09:42:08.358917 | 2025-12-17 09:42:08.359111 | TASK [Convert test_command to list] 2025-12-17 09:42:08.406727 | controller | skipping: Conditional result was False 2025-12-17 09:42:08.411880 | 2025-12-17 09:42:08.411947 | TASK [Use test_command list] 2025-12-17 09:42:08.473363 | controller | ok 2025-12-17 09:42:08.480186 | 2025-12-17 09:42:08.480304 | LOOP [Run test_command] 2025-12-17 09:42:08.910728 | controller | no check to run 2025-12-17 09:42:08.911083 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007187 2025-12-17 09:42:08.960425 | 2025-12-17 09:42:08.960549 | PLAY RECAP 2025-12-17 09:42:08.960604 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-17 09:42:08.960634 | 2025-12-17 09:42:09.067878 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-17 09:42:09.068843 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-17 09:42:09.711083 | 2025-12-17 09:42:09.711373 | PLAY [all] 2025-12-17 09:42:09.733957 | 2025-12-17 09:42:09.734120 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-17 09:42:10.070129 | controller | changed: non-zero return code 2025-12-17 09:42:10.091222 | 2025-12-17 09:42:10.091386 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-17 09:42:10.117478 | controller | skipping: Conditional result was False 2025-12-17 09:42:10.129122 | 2025-12-17 09:42:10.129312 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-17 09:42:10.165635 | 2025-12-17 09:42:10.165856 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-17 09:42:10.199503 | 2025-12-17 09:42:10.199682 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-17 09:42:10.214386 | controller | skipping: Conditional result was False 2025-12-17 09:42:10.221684 | 2025-12-17 09:42:10.221797 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-17 09:42:10.252986 | 2025-12-17 09:42:10.253193 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-17 09:42:10.277643 | controller | skipping: Conditional result was False 2025-12-17 09:42:10.286563 | 2025-12-17 09:42:10.286687 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-17 09:42:10.312391 | controller | skipping: Conditional result was False 2025-12-17 09:42:10.322725 | 2025-12-17 09:42:10.322883 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-17 09:42:10.349215 | controller | skipping: Conditional result was False 2025-12-17 09:42:10.384047 | 2025-12-17 09:42:10.384155 | PLAY RECAP 2025-12-17 09:42:10.384196 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-17 09:42:10.384216 | 2025-12-17 09:42:10.497914 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-17 09:42:10.498827 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-17 09:42:11.149559 | 2025-12-17 09:42:11.149700 | PLAY [all] 2025-12-17 09:42:11.185030 | 2025-12-17 09:42:11.185196 | TASK [include_role : fetch-output] 2025-12-17 09:42:11.215359 | controller | ok 2025-12-17 09:42:11.234926 | 2025-12-17 09:42:11.235098 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-17 09:42:11.280089 | controller | skipping: Conditional result was False 2025-12-17 09:42:11.286780 | 2025-12-17 09:42:11.286916 | TASK [fetch-output : Set log path for single node] 2025-12-17 09:42:11.320781 | controller | ok 2025-12-17 09:42:11.326267 | 2025-12-17 09:42:11.329640 | LOOP [fetch-output : Ensure local output dirs] 2025-12-17 09:42:11.807342 | controller -> localhost | ok: "/var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/logs" 2025-12-17 09:42:12.083890 | controller -> localhost | changed: "/var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/artifacts" 2025-12-17 09:42:12.296645 | controller -> localhost | changed: "/var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/docs" 2025-12-17 09:42:12.310979 | 2025-12-17 09:42:12.311126 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-17 09:42:12.943695 | controller | changed: .d..t...... ./ 2025-12-17 09:42:12.943958 | controller | changed: All items complete 2025-12-17 09:42:12.944043 | 2025-12-17 09:42:13.400824 | controller | changed: .d..t...... ./ 2025-12-17 09:42:13.907151 | controller | changed: .d..t...... ./ 2025-12-17 09:42:13.943071 | 2025-12-17 09:42:13.943228 | TASK [include_role : fetch-output-openshift] 2025-12-17 09:42:13.969994 | controller | skipping: Conditional result was False 2025-12-17 09:42:13.979733 | 2025-12-17 09:42:13.979880 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-17 09:42:14.462470 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012621 2025-12-17 09:42:14.728169 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008392 2025-12-17 09:42:14.756656 | 2025-12-17 09:42:14.756784 | PLAY [all] 2025-12-17 09:42:14.772149 | 2025-12-17 09:42:14.772283 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-17 09:42:15.231818 | controller | changed 2025-12-17 09:42:15.268782 | 2025-12-17 09:42:15.268909 | PLAY RECAP 2025-12-17 09:42:15.268963 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-17 09:42:15.268991 | 2025-12-17 09:42:15.384719 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-17 09:42:15.386495 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-17 09:42:16.125753 | 2025-12-17 09:42:16.125888 | PLAY [localhost] 2025-12-17 09:42:16.145301 | 2025-12-17 09:42:16.145444 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-17 09:42:16.572854 | localhost | changed 2025-12-17 09:42:16.578107 | 2025-12-17 09:42:16.578190 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-17 09:42:16.617570 | localhost | ok 2025-12-17 09:42:16.626861 | 2025-12-17 09:42:16.626975 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-17 09:42:17.111930 | localhost | changed 2025-12-17 09:42:17.121479 | 2025-12-17 09:42:17.121771 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-17 09:42:17.843854 | localhost | changed 2025-12-17 09:42:17.849391 | 2025-12-17 09:42:17.849484 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-17 09:42:18.305892 | localhost | Identity added: /var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/tmp/ansible.r39e57ix (/var/lib/zuul/builds/3a26a4937ce9400ca2e90ff0d6d1b169/work/tmp/ansible.r39e57ix) 2025-12-17 09:42:18.306111 | localhost | ok: Runtime: 0:00:00.013876 2025-12-17 09:42:18.310424 | 2025-12-17 09:42:18.310600 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-17 09:42:18.577055 | localhost | ok: Runtime: 0:00:00.005349 2025-12-17 09:42:18.582656 | 2025-12-17 09:42:18.582723 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-17 09:42:18.631781 | localhost | changed 2025-12-17 09:42:18.636042 | 2025-12-17 09:42:18.636106 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-17 09:42:19.071119 | localhost | changed 2025-12-17 09:42:19.091709 | 2025-12-17 09:42:19.091770 | PLAY [localhost] 2025-12-17 09:42:19.104083 | 2025-12-17 09:42:19.104156 | TASK [Generate bulk log download script] 2025-12-17 09:42:19.121988 | localhost | ok 2025-12-17 09:42:19.135194 | 2025-12-17 09:42:19.135270 | TASK [local-log-download : Check API endpoint is defined] 2025-12-17 09:42:19.165871 | localhost | ok: All assertions passed 2025-12-17 09:42:19.172045 | 2025-12-17 09:42:19.172143 | TASK [local-log-download : Create download script] 2025-12-17 09:42:19.606964 | localhost -> localhost | changed 2025-12-17 09:42:19.616885 | 2025-12-17 09:42:19.616980 | TASK [Register quick-download link] 2025-12-17 09:42:19.646614 | localhost | ok 2025-12-17 09:42:19.686899 | 2025-12-17 09:42:19.686990 | PLAY [logserver.rdoproject.org] 2025-12-17 09:42:19.697462 | 2025-12-17 09:42:19.697525 | TASK [Set zuul-log-path fact] 2025-12-17 09:42:19.714540 | logserver.rdoproject.org | ok 2025-12-17 09:42:19.724503 | 2025-12-17 09:42:19.724571 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-17 09:42:19.753777 | logserver.rdoproject.org | ok 2025-12-17 09:42:19.759498 | 2025-12-17 09:42:19.759562 | TASK [upload-logs : Create log directories] 2025-12-17 09:42:20.422104 | logserver.rdoproject.org | changed 2025-12-17 09:42:20.425286 | 2025-12-17 09:42:20.425348 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-17 09:42:20.703596 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008178 2025-12-17 09:42:20.708379 | 2025-12-17 09:42:20.708444 | TASK [upload-logs : Upload logs to log server] 2025-12-17 09:42:21.450801 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-17 09:42:21.454212 | 2025-12-17 09:42:21.454275 | LOOP [upload-logs : Compress console log and json output] 2025-12-17 09:42:21.526561 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 09:42:21.540370 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 09:42:21.545205 | 2025-12-17 09:42:21.545337 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-17 09:42:21.594185 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 09:42:21.594481 | 2025-12-17 09:42:21.598105 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-17 09:42:21.605944 | 2025-12-17 09:42:21.606141 | LOOP [upload-logs : Upload console log and json output]