2025-10-13 09:22:13.794351 | Job console starting... 2025-10-13 09:22:13.808815 | Updating repositories 2025-10-13 09:22:13.840064 | Preparing job workspace 2025-10-13 09:22:17.590259 | Running Ansible setup... 2025-10-13 09:22:21.976572 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 09:22:22.779426 | 2025-10-13 09:22:22.779566 | PLAY [localhost] 2025-10-13 09:22:22.789291 | 2025-10-13 09:22:22.789423 | TASK [Gathering Facts] 2025-10-13 09:22:23.995130 | localhost | ok 2025-10-13 09:22:24.012045 | 2025-10-13 09:22:24.012236 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 09:22:24.429594 | localhost -> localhost | changed 2025-10-13 09:22:24.435329 | 2025-10-13 09:22:24.435415 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 09:22:25.422358 | localhost -> localhost | changed 2025-10-13 09:22:25.431673 | 2025-10-13 09:22:25.431779 | TASK [Setup log path fact] 2025-10-13 09:22:25.449865 | localhost | ok 2025-10-13 09:22:25.462420 | 2025-10-13 09:22:25.462512 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 09:22:25.490422 | localhost | ok 2025-10-13 09:22:25.499355 | 2025-10-13 09:22:25.499887 | TASK [emit-job-header : Print job information] 2025-10-13 09:22:25.538557 | # Job Information 2025-10-13 09:22:25.538717 | Ansible Version: 2.15.12 2025-10-13 09:22:25.538771 | Job: cifmw-molecule-federation 2025-10-13 09:22:25.538794 | Pipeline: github-check 2025-10-13 09:22:25.538812 | Executor: ze03.softwarefactory-project.io 2025-10-13 09:22:25.538833 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-13 09:22:25.538855 | Log URL (when completed): https://logserver.rdoproject.org/f6f/rdoproject.org/f6f3db3d175c4e52856218ceb55b90f2/ 2025-10-13 09:22:25.538873 | Event ID: dc7e7520-a815-11f0-9fb0-d110e1a8d56a 2025-10-13 09:22:25.543062 | 2025-10-13 09:22:25.543132 | LOOP [emit-job-header : Print node information] 2025-10-13 09:22:25.652629 | localhost | ok: 2025-10-13 09:22:25.652810 | localhost | # Node Information 2025-10-13 09:22:25.652838 | localhost | Inventory Hostname: controller 2025-10-13 09:22:25.652861 | localhost | Hostname: np0005483019 2025-10-13 09:22:25.652880 | localhost | Username: zuul 2025-10-13 09:22:25.652900 | localhost | Distro: CentOS 9 2025-10-13 09:22:25.652918 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 09:22:25.652934 | localhost | Region: RegionOne 2025-10-13 09:22:25.652951 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 09:22:25.652967 | localhost | Product Name: OpenStack Nova 2025-10-13 09:22:25.652983 | localhost | Interface IP: 38.102.83.166 2025-10-13 09:22:25.679291 | 2025-10-13 09:22:25.679396 | PLAY [all] 2025-10-13 09:22:25.685987 | 2025-10-13 09:22:25.686059 | TASK [Gather network facts] 2025-10-13 09:22:26.160798 | controller | ok 2025-10-13 09:22:26.182189 | 2025-10-13 09:22:26.182342 | TASK [include_role : start-zuul-console] 2025-10-13 09:22:26.202672 | controller | ok 2025-10-13 09:22:26.217027 | 2025-10-13 09:22:26.217178 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 09:22:26.634847 | controller | ok 2025-10-13 09:22:26.644009 | 2025-10-13 09:22:26.644096 | TASK [include_role : add-build-sshkey] 2025-10-13 09:22:26.663702 | controller | ok 2025-10-13 09:22:26.692509 | 2025-10-13 09:22:26.692656 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 09:22:26.999576 | controller -> localhost | ok 2025-10-13 09:22:27.006114 | 2025-10-13 09:22:27.006222 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 09:22:27.034691 | controller | ok 2025-10-13 09:22:27.055892 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 09:22:27.064128 | 2025-10-13 09:22:27.064247 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 09:22:27.598561 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 09:22:27.598819 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/f6f3db3d175c4e52856218ceb55b90f2_id_rsa. 2025-10-13 09:22:27.598853 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/f6f3db3d175c4e52856218ceb55b90f2_id_rsa.pub. 2025-10-13 09:22:27.598875 | controller -> localhost | The key fingerprint is: 2025-10-13 09:22:27.598897 | controller -> localhost | SHA256:grlcGBPjzdRXlsWKkDrIqCc+2n30TYV8xrp1mri7aYw zuul-build-sshkey 2025-10-13 09:22:27.598917 | controller -> localhost | The key's randomart image is: 2025-10-13 09:22:27.598936 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 09:22:27.598955 | controller -> localhost | | o .. . .o+. | 2025-10-13 09:22:27.598974 | controller -> localhost | | . * + ... . | 2025-10-13 09:22:27.598993 | controller -> localhost | | o+.o. + + . | 2025-10-13 09:22:27.599012 | controller -> localhost | | . o*o + * | 2025-10-13 09:22:27.599030 | controller -> localhost | | . + o.S = | 2025-10-13 09:22:27.599048 | controller -> localhost | |o .. o.. o . . | 2025-10-13 09:22:27.599065 | controller -> localhost | |.o o. . = + + | 2025-10-13 09:22:27.599083 | controller -> localhost | | + . . E *.o | 2025-10-13 09:22:27.599100 | controller -> localhost | |o o .. .=+ | 2025-10-13 09:22:27.599117 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 09:22:27.599160 | controller -> localhost | ok: Runtime: 0:00:00.104125 2025-10-13 09:22:27.605579 | 2025-10-13 09:22:27.605685 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 09:22:27.638371 | controller | ok 2025-10-13 09:22:27.648841 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 09:22:27.659443 | 2025-10-13 09:22:27.659587 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 09:22:27.684642 | controller | skipping: Conditional result was False 2025-10-13 09:22:27.693063 | 2025-10-13 09:22:27.693197 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 09:22:28.151119 | controller | changed 2025-10-13 09:22:28.165629 | 2025-10-13 09:22:28.165896 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 09:22:28.406236 | controller | ok 2025-10-13 09:22:28.417209 | 2025-10-13 09:22:28.417324 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 09:22:29.183540 | controller | changed 2025-10-13 09:22:29.196642 | 2025-10-13 09:22:29.196855 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 09:22:30.035756 | controller | changed 2025-10-13 09:22:30.047297 | 2025-10-13 09:22:30.047455 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 09:22:30.080381 | controller | skipping: Conditional result was False 2025-10-13 09:22:30.091008 | 2025-10-13 09:22:30.091300 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 09:22:30.534643 | controller -> localhost | changed 2025-10-13 09:22:30.547898 | 2025-10-13 09:22:30.548026 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 09:22:30.861052 | controller -> localhost | Identity added: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/f6f3db3d175c4e52856218ceb55b90f2_id_rsa (zuul-build-sshkey) 2025-10-13 09:22:30.861255 | controller -> localhost | ok: Runtime: 0:00:00.020045 2025-10-13 09:22:30.873463 | 2025-10-13 09:22:30.873618 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 09:22:31.340170 | controller | ok 2025-10-13 09:22:31.348690 | 2025-10-13 09:22:31.348853 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 09:22:31.384515 | controller | skipping: Conditional result was False 2025-10-13 09:22:31.399093 | 2025-10-13 09:22:31.399214 | TASK [include_role : validate-host] 2025-10-13 09:22:31.423248 | controller | ok 2025-10-13 09:22:31.446427 | 2025-10-13 09:22:31.446538 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 09:22:31.475484 | controller | ok 2025-10-13 09:22:31.480911 | 2025-10-13 09:22:31.480982 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 09:22:31.783404 | controller -> localhost | ok 2025-10-13 09:22:31.789356 | 2025-10-13 09:22:31.789422 | TASK [validate-host : Collect information about the host] 2025-10-13 09:22:32.535525 | controller | ok 2025-10-13 09:22:32.559107 | 2025-10-13 09:22:32.559240 | TASK [validate-host : Sanitize hostname] 2025-10-13 09:22:32.644446 | controller | ok 2025-10-13 09:22:32.650117 | 2025-10-13 09:22:32.650238 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 09:22:33.190379 | controller -> localhost | changed 2025-10-13 09:22:33.203119 | 2025-10-13 09:22:33.203262 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 09:22:33.614080 | controller | ok 2025-10-13 09:22:33.619139 | 2025-10-13 09:22:33.619289 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 09:22:34.205121 | controller -> localhost | changed 2025-10-13 09:22:34.219449 | 2025-10-13 09:22:34.219578 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 09:22:34.244057 | controller | skipping: Conditional result was False 2025-10-13 09:22:34.250168 | 2025-10-13 09:22:34.250253 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 09:22:34.284965 | controller | skipping: Conditional result was False 2025-10-13 09:22:34.290616 | 2025-10-13 09:22:34.290713 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 09:22:34.592405 | controller | ok: "logs" 2025-10-13 09:22:34.593053 | controller | ok: All items complete 2025-10-13 09:22:34.593096 | 2025-10-13 09:22:34.887136 | controller | ok: "artifacts" 2025-10-13 09:22:35.195591 | controller | ok: "docs" 2025-10-13 09:22:35.222891 | 2025-10-13 09:22:35.223287 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 09:22:35.529309 | controller | changed: "logs" 2025-10-13 09:22:35.770965 | controller | changed: "artifacts" 2025-10-13 09:22:35.986284 | controller | changed: "docs" 2025-10-13 09:22:36.045838 | 2025-10-13 09:22:36.045952 | PLAY RECAP 2025-10-13 09:22:36.046013 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 09:22:36.046051 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 09:22:36.046078 | 2025-10-13 09:22:36.170755 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 09:22:36.171541 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 09:22:36.919047 | 2025-10-13 09:22:36.919164 | PLAY [localhost] 2025-10-13 09:22:36.937122 | 2025-10-13 09:22:36.937285 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 09:22:37.398940 | localhost | ok 2025-10-13 09:22:37.407223 | 2025-10-13 09:22:37.407366 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 09:22:38.288898 | localhost | changed 2025-10-13 09:22:38.327429 | 2025-10-13 09:22:38.327553 | PLAY [all] 2025-10-13 09:22:38.351330 | 2025-10-13 09:22:38.351465 | TASK [include_role : prepare-workspace] 2025-10-13 09:22:38.385997 | controller | ok 2025-10-13 09:22:38.406318 | 2025-10-13 09:22:38.406451 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 09:22:38.837303 | controller | ok 2025-10-13 09:22:38.845205 | 2025-10-13 09:22:38.845299 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 09:22:40.491120 | controller | Output suppressed because no_log was given 2025-10-13 09:22:40.503235 | 2025-10-13 09:22:40.503352 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 09:22:40.791091 | controller | changed: "logs" 2025-10-13 09:22:41.017268 | controller | changed: "artifacts" 2025-10-13 09:22:41.281792 | controller | changed: "docs" 2025-10-13 09:22:41.298301 | 2025-10-13 09:22:41.298431 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 09:22:41.603840 | controller | changed: "logs" 2025-10-13 09:22:41.604155 | controller | changed: All items complete 2025-10-13 09:22:41.604200 | 2025-10-13 09:22:41.835472 | controller | changed: "artifacts" 2025-10-13 09:22:42.059290 | controller | changed: "docs" 2025-10-13 09:22:42.075045 | 2025-10-13 09:22:42.075187 | TASK [Check if worker can sudo] 2025-10-13 09:22:42.618512 | controller | ok: Runtime: 0:00:00.041656 2025-10-13 09:22:42.624232 | 2025-10-13 09:22:42.624533 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 09:22:42.716851 | controller | skipping: Conditional result was False 2025-10-13 09:22:42.722534 | 2025-10-13 09:22:42.722637 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 09:22:42.794325 | controller | ok 2025-10-13 09:22:42.805299 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 09:22:42.813080 | 2025-10-13 09:22:42.813195 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 09:22:43.155179 | controller | ok 2025-10-13 09:22:43.161229 | 2025-10-13 09:22:43.161356 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 09:22:43.240496 | controller | ok: "/var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 09:22:43.257568 | 2025-10-13 09:22:43.257697 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 09:22:44.050417 | controller | changed 2025-10-13 09:22:44.058018 | 2025-10-13 09:22:44.058257 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 09:22:44.126086 | controller | ok: "/var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 09:22:44.126493 | controller | ok: All items complete 2025-10-13 09:22:44.126525 | 2025-10-13 09:22:44.189618 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 09:22:44.199308 | 2025-10-13 09:22:44.199510 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 09:22:45.316863 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 09:22:46.187953 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 09:22:46.202535 | 2025-10-13 09:22:46.202665 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 09:22:46.712011 | controller | changed: section and option added 2025-10-13 09:22:46.732680 | 2025-10-13 09:22:46.732847 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 09:22:47.595218 | controller | 29 files removed 2025-10-13 09:22:47.595489 | controller | ok: Item: dnf clean all Runtime: 0:00:00.528080 2025-10-13 09:22:47.595554 | controller | changed: All items complete 2025-10-13 09:22:47.595593 | 2025-10-13 09:22:59.617812 | 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 09:22:59.617946 | controller | DNF version: 4.14.0 2025-10-13 09:22:59.617983 | controller | cachedir: /var/cache/dnf 2025-10-13 09:22:59.618227 | controller | Making cache files for all metadata files. 2025-10-13 09:22:59.618278 | controller | baseos: has expired and will be refreshed. 2025-10-13 09:22:59.618307 | controller | appstream: has expired and will be refreshed. 2025-10-13 09:22:59.618333 | controller | crb: has expired and will be refreshed. 2025-10-13 09:22:59.618370 | controller | extras-common: has expired and will be refreshed. 2025-10-13 09:22:59.618395 | controller | repo: downloading from remote: baseos 2025-10-13 09:22:59.618419 | controller | CentOS Stream 9 - BaseOS 79 MB/s | 8.8 MB 00:00 2025-10-13 09:22:59.618443 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 09:22:59.618467 | controller | repo: downloading from remote: appstream 2025-10-13 09:22:59.618490 | controller | CentOS Stream 9 - AppStream 110 MB/s | 25 MB 00:00 2025-10-13 09:22:59.618514 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 09:22:59.618537 | controller | repo: downloading from remote: crb 2025-10-13 09:22:59.618560 | controller | CentOS Stream 9 - CRB 62 MB/s | 7.2 MB 00:00 2025-10-13 09:22:59.618583 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 09:22:59.618607 | controller | repo: downloading from remote: extras-common 2025-10-13 09:22:59.618630 | controller | CentOS Stream 9 - Extras packages 401 kB/s | 20 kB 00:00 2025-10-13 09:22:59.618654 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 09:22:59.618677 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 09:22:59.618701 | controller | Completion plugin: Generating completion cache... 2025-10-13 09:22:59.618751 | controller | Metadata cache created. 2025-10-13 09:22:59.618820 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.758758 2025-10-13 09:22:59.648054 | 2025-10-13 09:22:59.648175 | PLAY RECAP 2025-10-13 09:22:59.648234 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 09:22:59.648272 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 09:22:59.648299 | 2025-10-13 09:22:59.830231 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 09:22:59.831137 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 09:23:00.692632 | 2025-10-13 09:23:00.692786 | PLAY [all] 2025-10-13 09:23:00.718285 | 2025-10-13 09:23:00.718425 | TASK [Install binary dependencies] 2025-10-13 09:23:00.789549 | controller | ok 2025-10-13 09:23:00.828884 | 2025-10-13 09:23:00.829064 | TASK [bindep : Include find tasks] 2025-10-13 09:23:00.863724 | controller | ok 2025-10-13 09:23:00.872995 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 09:23:00.879084 | 2025-10-13 09:23:00.879188 | TASK [bindep : Look for bindep.txt] 2025-10-13 09:23:01.358314 | controller | ok 2025-10-13 09:23:01.377605 | 2025-10-13 09:23:01.377759 | TASK [bindep : Define bindep_file fact] 2025-10-13 09:23:01.415779 | controller | ok 2025-10-13 09:23:01.421769 | 2025-10-13 09:23:01.421912 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 09:23:01.452055 | controller | skipping: Conditional result was False 2025-10-13 09:23:01.458384 | 2025-10-13 09:23:01.458472 | TASK [bindep : Define bindep_file fact] 2025-10-13 09:23:01.489347 | controller | skipping: Conditional result was False 2025-10-13 09:23:01.497682 | 2025-10-13 09:23:01.497827 | TASK [bindep : Look for bindep fallback file] 2025-10-13 09:23:01.555851 | controller | skipping: Conditional result was False 2025-10-13 09:23:01.562016 | 2025-10-13 09:23:01.562112 | TASK [bindep : Define bindep_file fact] 2025-10-13 09:23:01.607035 | controller | skipping: Conditional result was False 2025-10-13 09:23:01.613044 | 2025-10-13 09:23:01.613162 | TASK [bindep : Include bindep tasks] 2025-10-13 09:23:01.661773 | controller | ok 2025-10-13 09:23:01.679224 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 09:23:01.692412 | 2025-10-13 09:23:01.692526 | TASK [bindep : Look for bindep command] 2025-10-13 09:23:01.729277 | controller | skipping: Conditional result was False 2025-10-13 09:23:01.737461 | 2025-10-13 09:23:01.737567 | TASK [bindep : Check for system bindep] 2025-10-13 09:23:02.300523 | controller | ok: Runtime: 0:00:00.005808 2025-10-13 09:23:02.306466 | 2025-10-13 09:23:02.306556 | TASK [bindep : Define bindep_command fact] 2025-10-13 09:23:02.361394 | controller | skipping: Conditional result was False 2025-10-13 09:23:02.367355 | 2025-10-13 09:23:02.367460 | TASK [bindep : Include install tasks] 2025-10-13 09:23:02.427244 | controller | ok 2025-10-13 09:23:02.436670 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 09:23:02.446200 | 2025-10-13 09:23:02.446275 | TASK [bindep : Create temp dir for bindep] 2025-10-13 09:23:02.872122 | controller | changed 2025-10-13 09:23:02.877553 | 2025-10-13 09:23:02.877624 | TASK [Ensure we have pip dependencies] 2025-10-13 09:23:02.903079 | controller | ok 2025-10-13 09:23:02.932581 | 2025-10-13 09:23:02.932755 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 05:23:03.255528 | controller | /usr/bin/pip3 2025-10-13 05:23:03.279474 | controller | /usr/bin/python3: No module named wheel 2025-10-13 09:23:03.478959 | controller | ok: Runtime: 0:00:00.048024 2025-10-13 09:23:03.484757 | 2025-10-13 09:23:03.484827 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 09:23:03.513630 | controller | ok: "/var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 09:23:03.530718 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 09:23:03.541269 | 2025-10-13 09:23:03.541385 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 09:23:09.215582 | controller | changed 2025-10-13 09:23:09.223543 | 2025-10-13 09:23:09.223715 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 09:23:09.292232 | controller | skipping: Conditional result was False 2025-10-13 09:23:09.304828 | 2025-10-13 09:23:09.304993 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 09:23:09.351002 | controller | skipping: Conditional result was False 2025-10-13 09:23:09.360305 | 2025-10-13 09:23:09.360462 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 09:23:09.457611 | controller | skipping: Conditional result was False 2025-10-13 09:23:09.463632 | 2025-10-13 09:23:09.463762 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 09:23:09.479547 | controller | skipping: Conditional result was False 2025-10-13 09:23:09.486634 | 2025-10-13 09:23:09.486718 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 09:23:10.017686 | controller | skipping: Conditional result was False 2025-10-13 09:23:10.024043 | 2025-10-13 09:23:10.024144 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 09:23:10.048303 | controller | skipping: Conditional result was False 2025-10-13 09:23:10.054597 | 2025-10-13 09:23:10.054679 | TASK [ensure-pip : Install pip from source] 2025-10-13 09:23:10.078839 | controller | skipping: Conditional result was False 2025-10-13 09:23:10.085024 | 2025-10-13 09:23:10.085120 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 05:23:10.405705 | controller | /usr/bin/python3 2025-10-13 09:23:10.618029 | controller | ok: Runtime: 0:00:00.038191 2025-10-13 09:23:10.632089 | 2025-10-13 09:23:10.632265 | TASK [ensure-pip : Set host default] 2025-10-13 09:23:10.712458 | controller | ok 2025-10-13 09:23:10.724052 | 2025-10-13 09:23:10.724360 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 09:23:10.811060 | controller | ok 2025-10-13 09:23:10.824298 | 2025-10-13 09:23:10.824405 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 09:23:15.199541 | controller | changed 2025-10-13 09:23:15.207448 | 2025-10-13 09:23:15.207567 | TASK [bindep : Define bindep_command] 2025-10-13 09:23:15.249751 | controller | ok 2025-10-13 09:23:15.257167 | 2025-10-13 09:23:15.257259 | LOOP [bindep : Include package tasks] 2025-10-13 09:23:15.332412 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 09:23:15.332691 | controller | ok: All items complete 2025-10-13 09:23:15.332954 | 2025-10-13 09:23:15.353255 | controller | included: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 09:23:15.375387 | 2025-10-13 09:23:15.375546 | TASK [bindep : Define bindep_run fact] 2025-10-13 09:23:15.409905 | controller | ok 2025-10-13 09:23:15.417300 | 2025-10-13 09:23:15.417413 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 05:23:16.782930 | controller | podman 2025-10-13 05:23:16.815929 | controller | python3-jmespath 2025-10-13 05:23:16.816177 | controller | python3-libvirt 2025-10-13 05:23:16.816189 | controller | python3-lxml 2025-10-13 05:23:16.816199 | controller | python3-netaddr 2025-10-13 09:23:16.965639 | controller | ok: Runtime: 0:00:01.116634 2025-10-13 09:23:16.974366 | 2025-10-13 09:23:16.974521 | TASK [bindep : Install distro packages from bindep] 2025-10-13 09:24:22.520387 | controller | changed 2025-10-13 09:24:22.528350 | 2025-10-13 09:24:22.528503 | TASK [bindep : Check that packages are installed] 2025-10-13 09:24:24.063116 | controller | ok: Runtime: 0:00:01.155384 2025-10-13 09:24:24.071070 | 2025-10-13 09:24:24.071196 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 09:24:24.096019 | controller | skipping: Conditional result was False 2025-10-13 09:24:24.107952 | 2025-10-13 09:24:24.108070 | TASK [Run test-setup role] 2025-10-13 09:24:24.128027 | controller | ok 2025-10-13 09:24:24.184349 | 2025-10-13 09:24:24.184465 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 09:24:24.411824 | controller | ok 2025-10-13 09:24:24.420851 | 2025-10-13 09:24:24.421020 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 09:24:24.966464 | controller | skipping: Conditional result was False 2025-10-13 09:24:24.995847 | 2025-10-13 09:24:24.995988 | TASK [bindep : Remove bindep temp dir] 2025-10-13 09:24:25.376944 | controller | ok 2025-10-13 09:24:25.391874 | 2025-10-13 09:24:25.391984 | PLAY RECAP 2025-10-13 09:24:25.392040 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 09:24:25.392069 | 2025-10-13 09:24:25.547699 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 09:24:25.548547 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 09:24:26.189609 | 2025-10-13 09:24:26.189757 | PLAY [all] 2025-10-13 09:24:26.210563 | 2025-10-13 09:24:26.210709 | TASK [Abort when test_command variable is undefined] 2025-10-13 09:24:26.255356 | controller | skipping: Conditional result was False 2025-10-13 09:24:26.261480 | 2025-10-13 09:24:26.261587 | TASK [Convert test_command to list] 2025-10-13 09:24:26.306075 | controller | skipping: Conditional result was False 2025-10-13 09:24:26.312499 | 2025-10-13 09:24:26.312587 | TASK [Use test_command list] 2025-10-13 09:24:26.384512 | controller | ok 2025-10-13 09:24:26.390915 | 2025-10-13 09:24:26.391009 | LOOP [Run test_command] 2025-10-13 09:24:26.852376 | controller | no check to run 2025-10-13 09:24:26.852610 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006937 2025-10-13 09:24:26.883072 | 2025-10-13 09:24:26.883212 | PLAY RECAP 2025-10-13 09:24:26.883266 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 09:24:26.883316 | 2025-10-13 09:24:27.014067 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 09:24:27.015937 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 09:24:27.669614 | 2025-10-13 09:24:27.669783 | PLAY [all] 2025-10-13 09:24:27.695875 | 2025-10-13 09:24:27.696032 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 09:24:28.040855 | controller | changed: non-zero return code 2025-10-13 09:24:28.047090 | 2025-10-13 09:24:28.047227 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 09:24:28.062165 | controller | skipping: Conditional result was False 2025-10-13 09:24:28.069548 | 2025-10-13 09:24:28.069694 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 09:24:28.094453 | 2025-10-13 09:24:28.094613 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 09:24:28.115508 | 2025-10-13 09:24:28.115793 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 09:24:28.134816 | controller | skipping: Conditional result was False 2025-10-13 09:24:28.141441 | 2025-10-13 09:24:28.141561 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 09:24:28.162808 | 2025-10-13 09:24:28.162974 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 09:24:28.178789 | controller | skipping: Conditional result was False 2025-10-13 09:24:28.187259 | 2025-10-13 09:24:28.187450 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 09:24:28.201938 | controller | skipping: Conditional result was False 2025-10-13 09:24:28.209273 | 2025-10-13 09:24:28.209382 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 09:24:28.223487 | controller | skipping: Conditional result was False 2025-10-13 09:24:28.250377 | 2025-10-13 09:24:28.250501 | PLAY RECAP 2025-10-13 09:24:28.250551 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 09:24:28.250581 | 2025-10-13 09:24:28.404456 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 09:24:28.405507 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 09:24:29.306283 | 2025-10-13 09:24:29.306455 | PLAY [all] 2025-10-13 09:24:29.336817 | 2025-10-13 09:24:29.337002 | TASK [include_role : fetch-output] 2025-10-13 09:24:29.368282 | controller | ok 2025-10-13 09:24:29.386036 | 2025-10-13 09:24:29.386297 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 09:24:29.441218 | controller | skipping: Conditional result was False 2025-10-13 09:24:29.447350 | 2025-10-13 09:24:29.447518 | TASK [fetch-output : Set log path for single node] 2025-10-13 09:24:29.477182 | controller | ok 2025-10-13 09:24:29.482313 | 2025-10-13 09:24:29.482388 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 09:24:29.919230 | controller -> localhost | ok: "/var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/logs" 2025-10-13 09:24:30.188313 | controller -> localhost | changed: "/var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/artifacts" 2025-10-13 09:24:30.470394 | controller -> localhost | changed: "/var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/docs" 2025-10-13 09:24:30.483788 | 2025-10-13 09:24:30.483933 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 09:24:31.158432 | controller | changed: .d..t...... ./ 2025-10-13 09:24:31.158698 | controller | changed: All items complete 2025-10-13 09:24:31.158769 | 2025-10-13 09:24:31.646953 | controller | changed: .d..t...... ./ 2025-10-13 09:24:32.135229 | controller | changed: .d..t...... ./ 2025-10-13 09:24:32.164388 | 2025-10-13 09:24:32.164524 | TASK [include_role : fetch-output-openshift] 2025-10-13 09:24:32.189832 | controller | skipping: Conditional result was False 2025-10-13 09:24:32.197066 | 2025-10-13 09:24:32.197155 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 09:24:32.681270 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009132 2025-10-13 09:24:32.943138 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008475 2025-10-13 09:24:32.993791 | 2025-10-13 09:24:32.993937 | PLAY [all] 2025-10-13 09:24:33.017773 | 2025-10-13 09:24:33.017902 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 09:24:33.505675 | controller | changed 2025-10-13 09:24:33.546433 | 2025-10-13 09:24:33.546555 | PLAY RECAP 2025-10-13 09:24:33.546606 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 09:24:33.546627 | 2025-10-13 09:24:33.680357 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 09:24:33.681449 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 09:24:34.363128 | 2025-10-13 09:24:34.363306 | PLAY [localhost] 2025-10-13 09:24:34.383483 | 2025-10-13 09:24:34.383618 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 09:24:34.760479 | localhost | changed 2025-10-13 09:24:34.765248 | 2025-10-13 09:24:34.765345 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 09:24:34.793639 | localhost | ok 2025-10-13 09:24:34.802407 | 2025-10-13 09:24:34.802537 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 09:24:35.188796 | localhost | changed 2025-10-13 09:24:35.194646 | 2025-10-13 09:24:35.194787 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 09:24:35.981586 | localhost | changed 2025-10-13 09:24:35.986570 | 2025-10-13 09:24:35.986643 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 09:24:36.420957 | localhost | Identity added: /var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/tmp/ansible.5mihlkk2 (/var/lib/zuul/builds/f6f3db3d175c4e52856218ceb55b90f2/work/tmp/ansible.5mihlkk2) 2025-10-13 09:24:36.421327 | localhost | ok: Runtime: 0:00:00.012422 2025-10-13 09:24:36.429488 | 2025-10-13 09:24:36.429705 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 09:24:36.716264 | localhost | ok: Runtime: 0:00:00.005171 2025-10-13 09:24:36.722806 | 2025-10-13 09:24:36.722948 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 09:24:36.776312 | localhost | changed 2025-10-13 09:24:36.781670 | 2025-10-13 09:24:36.781851 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 09:24:37.239797 | localhost | changed 2025-10-13 09:24:37.265643 | 2025-10-13 09:24:37.265741 | PLAY [localhost] 2025-10-13 09:24:37.278709 | 2025-10-13 09:24:37.278871 | TASK [Generate bulk log download script] 2025-10-13 09:24:37.297478 | localhost | ok 2025-10-13 09:24:37.310197 | 2025-10-13 09:24:37.310295 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 09:24:37.338875 | localhost | ok: All assertions passed 2025-10-13 09:24:37.344199 | 2025-10-13 09:24:37.344272 | TASK [local-log-download : Create download script] 2025-10-13 09:24:37.804249 | localhost -> localhost | changed 2025-10-13 09:24:37.813404 | 2025-10-13 09:24:37.813502 | TASK [Register quick-download link] 2025-10-13 09:24:37.832274 | localhost | ok 2025-10-13 09:24:37.881757 | 2025-10-13 09:24:37.881851 | PLAY [logserver.rdoproject.org] 2025-10-13 09:24:37.895059 | 2025-10-13 09:24:37.895170 | TASK [Set zuul-log-path fact] 2025-10-13 09:24:37.913253 | logserver.rdoproject.org | ok 2025-10-13 09:24:37.926101 | 2025-10-13 09:24:37.926228 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 09:24:37.954449 | logserver.rdoproject.org | ok 2025-10-13 09:24:37.962039 | 2025-10-13 09:24:37.962136 | TASK [upload-logs : Create log directories] 2025-10-13 09:24:38.655280 | logserver.rdoproject.org | changed 2025-10-13 09:24:38.660403 | 2025-10-13 09:24:38.660513 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 09:24:38.940721 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007787 2025-10-13 09:24:38.946985 | 2025-10-13 09:24:38.947097 | TASK [upload-logs : Upload logs to log server] 2025-10-13 09:24:39.662062 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 09:24:39.669531 | 2025-10-13 09:24:39.669687 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 09:24:39.722233 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:24:39.732833 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:24:39.741196 | 2025-10-13 09:24:39.741291 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 09:24:39.784244 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:24:39.784465 | 2025-10-13 09:24:39.787424 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 09:24:39.798639 | 2025-10-13 09:24:39.798713 | LOOP [upload-logs : Upload console log and json output]