2025-10-08 10:41:50.986609 | Job console starting... 2025-10-08 10:41:50.996271 | Updating repositories 2025-10-08 10:41:51.035158 | Preparing job workspace 2025-10-08 10:41:54.516724 | Running Ansible setup... 2025-10-08 10:41:58.364846 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 10:41:58.912124 | 2025-10-08 10:41:58.912239 | PLAY [localhost] 2025-10-08 10:41:58.921104 | 2025-10-08 10:41:58.921173 | TASK [Gathering Facts] 2025-10-08 10:41:59.953996 | localhost | ok 2025-10-08 10:41:59.970292 | 2025-10-08 10:41:59.970386 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 10:42:00.384422 | localhost -> localhost | changed 2025-10-08 10:42:00.390587 | 2025-10-08 10:42:00.390666 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 10:42:01.547322 | localhost -> localhost | changed 2025-10-08 10:42:01.555760 | 2025-10-08 10:42:01.555841 | TASK [Setup log path fact] 2025-10-08 10:42:01.589593 | localhost | ok 2025-10-08 10:42:01.601658 | 2025-10-08 10:42:01.601805 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 10:42:01.629638 | localhost | ok 2025-10-08 10:42:01.637576 | 2025-10-08 10:42:01.637641 | TASK [emit-job-header : Print job information] 2025-10-08 10:42:01.677161 | # Job Information 2025-10-08 10:42:01.677321 | Ansible Version: 2.15.12 2025-10-08 10:42:01.677347 | Job: cifmw-molecule-switch_config 2025-10-08 10:42:01.677367 | Pipeline: github-check 2025-10-08 10:42:01.677385 | Executor: ze04.softwarefactory-project.io 2025-10-08 10:42:01.677402 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-08 10:42:01.677422 | Log URL (when completed): https://logserver.rdoproject.org/ea8/rdoproject.org/ea800577b581487bad3f66dafa4e6d85/ 2025-10-08 10:42:01.677440 | Event ID: 29448890-a433-11f0-8438-3fbae9028d16 2025-10-08 10:42:01.681595 | 2025-10-08 10:42:01.681656 | LOOP [emit-job-header : Print node information] 2025-10-08 10:42:01.783969 | localhost | ok: 2025-10-08 10:42:01.784192 | localhost | # Node Information 2025-10-08 10:42:01.784231 | localhost | Inventory Hostname: controller 2025-10-08 10:42:01.784262 | localhost | Hostname: np0005475745 2025-10-08 10:42:01.784293 | localhost | Username: zuul 2025-10-08 10:42:01.784326 | localhost | Distro: CentOS 9 2025-10-08 10:42:01.784357 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 10:42:01.784387 | localhost | Region: RegionOne 2025-10-08 10:42:01.784419 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 10:42:01.784449 | localhost | Product Name: OpenStack Nova 2025-10-08 10:42:01.784479 | localhost | Interface IP: 38.129.56.144 2025-10-08 10:42:01.819301 | 2025-10-08 10:42:01.819389 | PLAY [all] 2025-10-08 10:42:01.837561 | 2025-10-08 10:42:01.837625 | TASK [Gather network facts] 2025-10-08 10:42:02.348552 | controller | ok 2025-10-08 10:42:02.363919 | 2025-10-08 10:42:02.363983 | TASK [include_role : start-zuul-console] 2025-10-08 10:42:02.383850 | controller | ok 2025-10-08 10:42:02.396332 | 2025-10-08 10:42:02.396404 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 10:42:02.810244 | controller | ok 2025-10-08 10:42:02.830410 | 2025-10-08 10:42:02.830514 | TASK [include_role : add-build-sshkey] 2025-10-08 10:42:02.862093 | controller | ok 2025-10-08 10:42:02.880120 | 2025-10-08 10:42:02.880208 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 10:42:03.127966 | controller -> localhost | ok 2025-10-08 10:42:03.134854 | 2025-10-08 10:42:03.134918 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 10:42:03.154469 | controller | ok 2025-10-08 10:42:03.169327 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 10:42:03.176803 | 2025-10-08 10:42:03.176868 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 10:42:03.779400 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 10:42:03.779607 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/ea800577b581487bad3f66dafa4e6d85_id_rsa. 2025-10-08 10:42:03.779638 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/ea800577b581487bad3f66dafa4e6d85_id_rsa.pub. 2025-10-08 10:42:03.779660 | controller -> localhost | The key fingerprint is: 2025-10-08 10:42:03.779696 | controller -> localhost | SHA256:fWirqyonFN6pGcoLRlRkqA3cyjqkllI4Gz5I9ci6NtI zuul-build-sshkey 2025-10-08 10:42:03.779720 | controller -> localhost | The key's randomart image is: 2025-10-08 10:42:03.779739 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 10:42:03.779756 | controller -> localhost | |. ++ | 2025-10-08 10:42:03.779775 | controller -> localhost | |.ooo | 2025-10-08 10:42:03.779792 | controller -> localhost | |o=+ o | 2025-10-08 10:42:03.779810 | controller -> localhost | |*=+o . . . | 2025-10-08 10:42:03.779827 | controller -> localhost | |BBoo . S + . | 2025-10-08 10:42:03.779844 | controller -> localhost | |O*+ o . o | 2025-10-08 10:42:03.779861 | controller -> localhost | |=*o+ . | 2025-10-08 10:42:03.779878 | controller -> localhost | |==E . . | 2025-10-08 10:42:03.779894 | controller -> localhost | |o.o+....o. | 2025-10-08 10:42:03.779910 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 10:42:03.779960 | controller -> localhost | ok: Runtime: 0:00:00.083116 2025-10-08 10:42:03.786652 | 2025-10-08 10:42:03.786737 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 10:42:03.817151 | controller | ok 2025-10-08 10:42:03.827823 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 10:42:03.836177 | 2025-10-08 10:42:03.836239 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 10:42:03.861479 | controller | skipping: Conditional result was False 2025-10-08 10:42:03.868611 | 2025-10-08 10:42:03.868703 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 10:42:04.431013 | controller | changed 2025-10-08 10:42:04.436937 | 2025-10-08 10:42:04.437049 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 10:42:04.698979 | controller | ok 2025-10-08 10:42:04.710165 | 2025-10-08 10:42:04.710304 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 10:42:05.730136 | controller | changed 2025-10-08 10:42:05.743428 | 2025-10-08 10:42:05.743577 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 10:42:06.695928 | controller | changed 2025-10-08 10:42:06.702949 | 2025-10-08 10:42:06.703040 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 10:42:06.717652 | controller | skipping: Conditional result was False 2025-10-08 10:42:06.725473 | 2025-10-08 10:42:06.725564 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 10:42:07.168271 | controller -> localhost | changed 2025-10-08 10:42:07.178087 | 2025-10-08 10:42:07.178150 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 10:42:07.456147 | controller -> localhost | Identity added: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/ea800577b581487bad3f66dafa4e6d85_id_rsa (zuul-build-sshkey) 2025-10-08 10:42:07.456373 | controller -> localhost | ok: Runtime: 0:00:00.009946 2025-10-08 10:42:07.464521 | 2025-10-08 10:42:07.464608 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 10:42:07.863896 | controller | ok 2025-10-08 10:42:07.872366 | 2025-10-08 10:42:07.872462 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 10:42:07.908362 | controller | skipping: Conditional result was False 2025-10-08 10:42:07.918713 | 2025-10-08 10:42:07.918779 | TASK [include_role : validate-host] 2025-10-08 10:42:07.947388 | controller | ok 2025-10-08 10:42:07.967821 | 2025-10-08 10:42:07.967918 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 10:42:08.006708 | controller | ok 2025-10-08 10:42:08.011367 | 2025-10-08 10:42:08.011430 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 10:42:08.258525 | controller -> localhost | ok 2025-10-08 10:42:08.265431 | 2025-10-08 10:42:08.265492 | TASK [validate-host : Collect information about the host] 2025-10-08 10:42:09.118503 | controller | ok 2025-10-08 10:42:09.137855 | 2025-10-08 10:42:09.137944 | TASK [validate-host : Sanitize hostname] 2025-10-08 10:42:09.201722 | controller | ok 2025-10-08 10:42:09.210503 | 2025-10-08 10:42:09.210602 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 10:42:09.757600 | controller -> localhost | changed 2025-10-08 10:42:09.774930 | 2025-10-08 10:42:09.775051 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 10:42:10.199627 | controller | ok 2025-10-08 10:42:10.204475 | 2025-10-08 10:42:10.204541 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 10:42:10.635102 | controller -> localhost | changed 2025-10-08 10:42:10.649448 | 2025-10-08 10:42:10.649547 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 10:42:10.670072 | controller | skipping: Conditional result was False 2025-10-08 10:42:10.677029 | 2025-10-08 10:42:10.677112 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 10:42:10.692026 | controller | skipping: Conditional result was False 2025-10-08 10:42:10.699659 | 2025-10-08 10:42:10.699784 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 10:42:10.955357 | controller | ok: "logs" 2025-10-08 10:42:10.955584 | controller | ok: All items complete 2025-10-08 10:42:10.955612 | 2025-10-08 10:42:11.183399 | controller | ok: "artifacts" 2025-10-08 10:42:11.410186 | controller | ok: "docs" 2025-10-08 10:42:11.420032 | 2025-10-08 10:42:11.420127 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 10:42:11.681061 | controller | changed: "logs" 2025-10-08 10:42:11.894186 | controller | changed: "artifacts" 2025-10-08 10:42:12.128042 | controller | changed: "docs" 2025-10-08 10:42:12.184719 | 2025-10-08 10:42:12.184852 | PLAY RECAP 2025-10-08 10:42:12.184908 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 10:42:12.184943 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 10:42:12.184967 | 2025-10-08 10:42:12.317716 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 10:42:12.318524 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 10:42:12.905580 | 2025-10-08 10:42:12.905738 | PLAY [localhost] 2025-10-08 10:42:12.922124 | 2025-10-08 10:42:12.922201 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 10:42:13.315464 | localhost | ok 2025-10-08 10:42:13.340047 | 2025-10-08 10:42:13.340394 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 10:42:14.027650 | localhost | changed 2025-10-08 10:42:14.098077 | 2025-10-08 10:42:14.098240 | PLAY [all] 2025-10-08 10:42:14.121811 | 2025-10-08 10:42:14.121982 | TASK [include_role : prepare-workspace] 2025-10-08 10:42:14.154791 | controller | ok 2025-10-08 10:42:14.174380 | 2025-10-08 10:42:14.174529 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 10:42:14.584798 | controller | ok 2025-10-08 10:42:14.598356 | 2025-10-08 10:42:14.598560 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 10:42:16.263531 | controller | Output suppressed because no_log was given 2025-10-08 10:42:16.280925 | 2025-10-08 10:42:16.281114 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 10:42:16.546778 | controller | changed: "logs" 2025-10-08 10:42:16.744236 | controller | changed: "artifacts" 2025-10-08 10:42:16.965363 | controller | changed: "docs" 2025-10-08 10:42:16.989930 | 2025-10-08 10:42:16.990138 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 10:42:17.259667 | controller | changed: "logs" 2025-10-08 10:42:17.260188 | controller | changed: All items complete 2025-10-08 10:42:17.260248 | 2025-10-08 10:42:17.463217 | controller | changed: "artifacts" 2025-10-08 10:42:17.663513 | controller | changed: "docs" 2025-10-08 10:42:17.712031 | 2025-10-08 10:42:17.712199 | TASK [Check if worker can sudo] 2025-10-08 10:42:18.253545 | controller | ok: Runtime: 0:00:00.048491 2025-10-08 10:42:18.261305 | 2025-10-08 10:42:18.261391 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 10:42:18.337469 | controller | skipping: Conditional result was False 2025-10-08 10:42:18.350922 | 2025-10-08 10:42:18.351078 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 10:42:18.436617 | controller | ok 2025-10-08 10:42:18.451301 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 10:42:18.459598 | 2025-10-08 10:42:18.459741 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 10:42:18.874555 | controller | ok 2025-10-08 10:42:18.883089 | 2025-10-08 10:42:18.883176 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 10:42:19.008619 | controller | ok: "/var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 10:42:19.032265 | 2025-10-08 10:42:19.032493 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 10:42:19.893936 | controller | changed 2025-10-08 10:42:19.900136 | 2025-10-08 10:42:19.900212 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 10:42:19.956756 | controller | ok: "/var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 10:42:19.956948 | controller | ok: All items complete 2025-10-08 10:42:19.956993 | 2025-10-08 10:42:20.007810 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 10:42:20.014483 | 2025-10-08 10:42:20.014546 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 10:42:20.846105 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 10:42:21.584026 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 10:42:21.599153 | 2025-10-08 10:42:21.599287 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 10:42:22.011714 | controller | changed: section and option added 2025-10-08 10:42:22.031093 | 2025-10-08 10:42:22.031164 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 10:42:22.777338 | controller | 29 files removed 2025-10-08 10:42:22.777629 | controller | ok: Item: dnf clean all Runtime: 0:00:00.453532 2025-10-08 10:42:22.777704 | controller | changed: All items complete 2025-10-08 10:42:22.777741 | 2025-10-08 10:42:34.422278 | 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-08 10:42:34.422399 | controller | DNF version: 4.14.0 2025-10-08 10:42:34.422425 | controller | cachedir: /var/cache/dnf 2025-10-08 10:42:34.422446 | controller | Making cache files for all metadata files. 2025-10-08 10:42:34.422465 | controller | baseos: has expired and will be refreshed. 2025-10-08 10:42:34.422484 | controller | appstream: has expired and will be refreshed. 2025-10-08 10:42:34.422502 | controller | crb: has expired and will be refreshed. 2025-10-08 10:42:34.422530 | controller | extras-common: has expired and will be refreshed. 2025-10-08 10:42:34.422548 | controller | repo: downloading from remote: baseos 2025-10-08 10:42:34.422566 | controller | CentOS Stream 9 - BaseOS 64 MB/s | 8.8 MB 00:00 2025-10-08 10:42:34.422584 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 10:42:34.422602 | controller | repo: downloading from remote: appstream 2025-10-08 10:42:34.422619 | controller | CentOS Stream 9 - AppStream 26 MB/s | 25 MB 00:00 2025-10-08 10:42:34.422637 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 10:42:34.422654 | controller | repo: downloading from remote: crb 2025-10-08 10:42:34.424831 | controller | CentOS Stream 9 - CRB 54 MB/s | 7.1 MB 00:00 2025-10-08 10:42:34.424883 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 10:42:34.424905 | controller | repo: downloading from remote: extras-common 2025-10-08 10:42:34.424924 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-08 10:42:34.424942 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 10:42:34.424960 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 10:42:34.424978 | controller | Completion plugin: Generating completion cache... 2025-10-08 10:42:34.424996 | controller | Metadata cache created. 2025-10-08 10:42:34.425027 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.382245 2025-10-08 10:42:34.444106 | 2025-10-08 10:42:34.444257 | PLAY RECAP 2025-10-08 10:42:34.444312 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 10:42:34.444346 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 10:42:34.444365 | 2025-10-08 10:42:34.568387 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 10:42:34.569247 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 10:42:35.118349 | 2025-10-08 10:42:35.118456 | PLAY [all] 2025-10-08 10:42:35.139651 | 2025-10-08 10:42:35.139888 | TASK [Install binary dependencies] 2025-10-08 10:42:35.190062 | controller | ok 2025-10-08 10:42:35.209595 | 2025-10-08 10:42:35.209691 | TASK [bindep : Include find tasks] 2025-10-08 10:42:35.238811 | controller | ok 2025-10-08 10:42:35.246456 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 10:42:35.252539 | 2025-10-08 10:42:35.252615 | TASK [bindep : Look for bindep.txt] 2025-10-08 10:42:35.669712 | controller | ok 2025-10-08 10:42:35.676090 | 2025-10-08 10:42:35.676158 | TASK [bindep : Define bindep_file fact] 2025-10-08 10:42:35.705545 | controller | ok 2025-10-08 10:42:35.710608 | 2025-10-08 10:42:35.710709 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 10:42:35.725015 | controller | skipping: Conditional result was False 2025-10-08 10:42:35.731377 | 2025-10-08 10:42:35.731454 | TASK [bindep : Define bindep_file fact] 2025-10-08 10:42:35.757538 | controller | skipping: Conditional result was False 2025-10-08 10:42:35.763329 | 2025-10-08 10:42:35.763396 | TASK [bindep : Look for bindep fallback file] 2025-10-08 10:42:35.793042 | controller | skipping: Conditional result was False 2025-10-08 10:42:35.798859 | 2025-10-08 10:42:35.798934 | TASK [bindep : Define bindep_file fact] 2025-10-08 10:42:35.822952 | controller | skipping: Conditional result was False 2025-10-08 10:42:35.829106 | 2025-10-08 10:42:35.829172 | TASK [bindep : Include bindep tasks] 2025-10-08 10:42:35.870195 | controller | ok 2025-10-08 10:42:35.878586 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 10:42:35.888866 | 2025-10-08 10:42:35.888933 | TASK [bindep : Look for bindep command] 2025-10-08 10:42:35.913104 | controller | skipping: Conditional result was False 2025-10-08 10:42:35.920164 | 2025-10-08 10:42:35.920231 | TASK [bindep : Check for system bindep] 2025-10-08 10:42:36.451744 | controller | ok: Runtime: 0:00:00.007934 2025-10-08 10:42:36.476590 | 2025-10-08 10:42:36.476750 | TASK [bindep : Define bindep_command fact] 2025-10-08 10:42:36.501848 | controller | skipping: Conditional result was False 2025-10-08 10:42:36.520478 | 2025-10-08 10:42:36.520643 | TASK [bindep : Include install tasks] 2025-10-08 10:42:36.552829 | controller | ok 2025-10-08 10:42:36.565547 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 10:42:36.574351 | 2025-10-08 10:42:36.574414 | TASK [bindep : Create temp dir for bindep] 2025-10-08 10:42:36.930504 | controller | changed 2025-10-08 10:42:36.937745 | 2025-10-08 10:42:36.937870 | TASK [Ensure we have pip dependencies] 2025-10-08 10:42:36.958142 | controller | ok 2025-10-08 10:42:36.982373 | 2025-10-08 10:42:36.982494 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 06:42:37.237910 | controller | /usr/bin/pip3 2025-10-08 06:42:37.262670 | controller | /usr/bin/python3: No module named wheel 2025-10-08 10:42:37.511806 | controller | ok: Runtime: 0:00:00.033836 2025-10-08 10:42:37.520200 | 2025-10-08 10:42:37.520303 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 10:42:37.561886 | controller | ok: "/var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 10:42:37.577966 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 10:42:37.591823 | 2025-10-08 10:42:37.591889 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 10:42:40.018370 | controller | changed 2025-10-08 10:42:40.031704 | 2025-10-08 10:42:40.031846 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 10:42:40.100938 | controller | skipping: Conditional result was False 2025-10-08 10:42:40.122406 | 2025-10-08 10:42:40.122620 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 10:42:40.171058 | controller | skipping: Conditional result was False 2025-10-08 10:42:40.178706 | 2025-10-08 10:42:40.178787 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 10:42:40.218626 | controller | skipping: Conditional result was False 2025-10-08 10:42:40.226173 | 2025-10-08 10:42:40.226250 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 10:42:40.240931 | controller | skipping: Conditional result was False 2025-10-08 10:42:40.248179 | 2025-10-08 10:42:40.248270 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 10:42:40.777853 | controller | skipping: Conditional result was False 2025-10-08 10:42:40.791004 | 2025-10-08 10:42:40.791150 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 10:42:40.818252 | controller | skipping: Conditional result was False 2025-10-08 10:42:40.833847 | 2025-10-08 10:42:40.834007 | TASK [ensure-pip : Install pip from source] 2025-10-08 10:42:40.862308 | controller | skipping: Conditional result was False 2025-10-08 10:42:40.875785 | 2025-10-08 10:42:40.875939 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 06:42:41.215235 | controller | /usr/bin/python3 2025-10-08 10:42:41.423142 | controller | ok: Runtime: 0:00:00.005762 2025-10-08 10:42:41.435583 | 2025-10-08 10:42:41.435766 | TASK [ensure-pip : Set host default] 2025-10-08 10:42:41.508397 | controller | ok 2025-10-08 10:42:41.515087 | 2025-10-08 10:42:41.515168 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 10:42:41.582783 | controller | ok 2025-10-08 10:42:41.604895 | 2025-10-08 10:42:41.604993 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 10:42:45.840811 | controller | changed 2025-10-08 10:42:45.846635 | 2025-10-08 10:42:45.846802 | TASK [bindep : Define bindep_command] 2025-10-08 10:42:45.881195 | controller | ok 2025-10-08 10:42:45.888467 | 2025-10-08 10:42:45.888543 | LOOP [bindep : Include package tasks] 2025-10-08 10:42:45.934864 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 10:42:45.935285 | controller | ok: All items complete 2025-10-08 10:42:45.935322 | 2025-10-08 10:42:45.959150 | controller | included: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 10:42:45.970456 | 2025-10-08 10:42:45.970532 | TASK [bindep : Define bindep_run fact] 2025-10-08 10:42:46.005828 | controller | ok 2025-10-08 10:42:46.011725 | 2025-10-08 10:42:46.011799 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 06:42:47.255890 | controller | podman 2025-10-08 06:42:47.291388 | controller | python3-jmespath 2025-10-08 06:42:47.291419 | controller | python3-libvirt 2025-10-08 06:42:47.291429 | controller | python3-lxml 2025-10-08 06:42:47.291437 | controller | python3-netaddr 2025-10-08 10:42:47.544607 | controller | ok: Runtime: 0:00:01.051988 2025-10-08 10:42:47.558782 | 2025-10-08 10:42:47.558933 | TASK [bindep : Install distro packages from bindep] 2025-10-08 10:43:55.716907 | controller | changed 2025-10-08 10:43:55.723542 | 2025-10-08 10:43:55.723610 | TASK [bindep : Check that packages are installed] 2025-10-08 10:43:57.289153 | controller | ok: Runtime: 0:00:01.093772 2025-10-08 10:43:57.299558 | 2025-10-08 10:43:57.299729 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 10:43:57.325843 | controller | skipping: Conditional result was False 2025-10-08 10:43:57.346422 | 2025-10-08 10:43:57.346554 | TASK [Run test-setup role] 2025-10-08 10:43:57.377663 | controller | ok 2025-10-08 10:43:57.396733 | 2025-10-08 10:43:57.396803 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 10:43:57.621451 | controller | ok 2025-10-08 10:43:57.626645 | 2025-10-08 10:43:57.626728 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 10:43:58.156906 | controller | skipping: Conditional result was False 2025-10-08 10:43:58.208927 | 2025-10-08 10:43:58.209106 | TASK [bindep : Remove bindep temp dir] 2025-10-08 10:43:58.568170 | controller | ok 2025-10-08 10:43:58.594017 | 2025-10-08 10:43:58.594220 | PLAY RECAP 2025-10-08 10:43:58.594292 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 10:43:58.594322 | 2025-10-08 10:43:58.769419 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 10:43:58.770319 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 10:43:59.321846 | 2025-10-08 10:43:59.322030 | PLAY [all] 2025-10-08 10:43:59.342508 | 2025-10-08 10:43:59.342583 | TASK [Abort when test_command variable is undefined] 2025-10-08 10:43:59.387276 | controller | skipping: Conditional result was False 2025-10-08 10:43:59.393989 | 2025-10-08 10:43:59.394089 | TASK [Convert test_command to list] 2025-10-08 10:43:59.438643 | controller | skipping: Conditional result was False 2025-10-08 10:43:59.445407 | 2025-10-08 10:43:59.445477 | TASK [Use test_command list] 2025-10-08 10:43:59.506730 | controller | ok 2025-10-08 10:43:59.512040 | 2025-10-08 10:43:59.512101 | LOOP [Run test_command] 2025-10-08 10:43:59.920549 | controller | no check to run 2025-10-08 10:43:59.920784 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005374 2025-10-08 10:43:59.951829 | 2025-10-08 10:43:59.951946 | PLAY RECAP 2025-10-08 10:43:59.951989 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 10:43:59.952009 | 2025-10-08 10:44:00.051243 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 10:44:00.052165 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 10:44:00.823813 | 2025-10-08 10:44:00.823949 | PLAY [all] 2025-10-08 10:44:00.850550 | 2025-10-08 10:44:00.850749 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 10:44:01.220539 | controller | changed: non-zero return code 2025-10-08 10:44:01.236956 | 2025-10-08 10:44:01.237084 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 10:44:01.262781 | controller | skipping: Conditional result was False 2025-10-08 10:44:01.277669 | 2025-10-08 10:44:01.278018 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 10:44:01.321239 | 2025-10-08 10:44:01.322098 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 10:44:01.360610 | 2025-10-08 10:44:01.360821 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 10:44:01.378065 | controller | skipping: Conditional result was False 2025-10-08 10:44:01.392252 | 2025-10-08 10:44:01.392371 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 10:44:01.427385 | 2025-10-08 10:44:01.427569 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 10:44:01.454315 | controller | skipping: Conditional result was False 2025-10-08 10:44:01.461514 | 2025-10-08 10:44:01.461600 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 10:44:01.486503 | controller | skipping: Conditional result was False 2025-10-08 10:44:01.492972 | 2025-10-08 10:44:01.493041 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 10:44:01.518418 | controller | skipping: Conditional result was False 2025-10-08 10:44:01.546894 | 2025-10-08 10:44:01.547204 | PLAY RECAP 2025-10-08 10:44:01.547265 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 10:44:01.547287 | 2025-10-08 10:44:01.700608 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 10:44:01.701463 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 10:44:02.302882 | 2025-10-08 10:44:02.303050 | PLAY [all] 2025-10-08 10:44:02.322853 | 2025-10-08 10:44:02.322947 | TASK [include_role : fetch-output] 2025-10-08 10:44:02.352758 | controller | ok 2025-10-08 10:44:02.375313 | 2025-10-08 10:44:02.375437 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 10:44:02.430113 | controller | skipping: Conditional result was False 2025-10-08 10:44:02.435845 | 2025-10-08 10:44:02.435917 | TASK [fetch-output : Set log path for single node] 2025-10-08 10:44:02.464785 | controller | ok 2025-10-08 10:44:02.469920 | 2025-10-08 10:44:02.469984 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 10:44:02.858924 | controller -> localhost | ok: "/var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/logs" 2025-10-08 10:44:03.125903 | controller -> localhost | changed: "/var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/artifacts" 2025-10-08 10:44:03.375353 | controller -> localhost | changed: "/var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/docs" 2025-10-08 10:44:03.386908 | 2025-10-08 10:44:03.387027 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 10:44:04.020616 | controller | changed: .d..t...... ./ 2025-10-08 10:44:04.020879 | controller | changed: All items complete 2025-10-08 10:44:04.020917 | 2025-10-08 10:44:04.499275 | controller | changed: .d..t...... ./ 2025-10-08 10:44:04.990480 | controller | changed: .d..t...... ./ 2025-10-08 10:44:05.010806 | 2025-10-08 10:44:05.010939 | TASK [include_role : fetch-output-openshift] 2025-10-08 10:44:05.034884 | controller | skipping: Conditional result was False 2025-10-08 10:44:05.041331 | 2025-10-08 10:44:05.041401 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 10:44:05.499501 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.017488 2025-10-08 10:44:05.726159 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008410 2025-10-08 10:44:05.758393 | 2025-10-08 10:44:05.758490 | PLAY [all] 2025-10-08 10:44:05.772745 | 2025-10-08 10:44:05.772814 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 10:44:06.298896 | controller | changed 2025-10-08 10:44:06.334662 | 2025-10-08 10:44:06.334806 | PLAY RECAP 2025-10-08 10:44:06.334853 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 10:44:06.334876 | 2025-10-08 10:44:06.463149 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 10:44:06.464369 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 10:44:07.084846 | 2025-10-08 10:44:07.085010 | PLAY [localhost] 2025-10-08 10:44:07.107191 | 2025-10-08 10:44:07.107284 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 10:44:07.470916 | localhost | changed 2025-10-08 10:44:07.476038 | 2025-10-08 10:44:07.476184 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 10:44:07.516907 | localhost | ok 2025-10-08 10:44:07.531425 | 2025-10-08 10:44:07.531498 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 10:44:07.875461 | localhost | changed 2025-10-08 10:44:07.882201 | 2025-10-08 10:44:07.882275 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 10:44:08.480508 | localhost | changed 2025-10-08 10:44:08.489970 | 2025-10-08 10:44:08.490106 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 10:44:08.903743 | localhost | Identity added: /var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/tmp/ansible.7n1bs5e_ (/var/lib/zuul/builds/ea800577b581487bad3f66dafa4e6d85/work/tmp/ansible.7n1bs5e_) 2025-10-08 10:44:08.903943 | localhost | ok: Runtime: 0:00:00.013656 2025-10-08 10:44:08.908316 | 2025-10-08 10:44:08.908390 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 10:44:09.210419 | localhost | ok: Runtime: 0:00:00.005646 2025-10-08 10:44:09.215905 | 2025-10-08 10:44:09.215981 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 10:44:09.266847 | localhost | changed 2025-10-08 10:44:09.275914 | 2025-10-08 10:44:09.276052 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 10:44:09.696318 | localhost | changed 2025-10-08 10:44:09.722119 | 2025-10-08 10:44:09.722240 | PLAY [localhost] 2025-10-08 10:44:09.738948 | 2025-10-08 10:44:09.739106 | TASK [Generate bulk log download script] 2025-10-08 10:44:09.760965 | localhost | ok 2025-10-08 10:44:09.778343 | 2025-10-08 10:44:09.778436 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 10:44:09.821973 | localhost | ok: All assertions passed 2025-10-08 10:44:09.831144 | 2025-10-08 10:44:09.831252 | TASK [local-log-download : Create download script] 2025-10-08 10:44:10.253610 | localhost -> localhost | changed 2025-10-08 10:44:10.262404 | 2025-10-08 10:44:10.262470 | TASK [Register quick-download link] 2025-10-08 10:44:10.289999 | localhost | ok 2025-10-08 10:44:10.332109 | 2025-10-08 10:44:10.332213 | PLAY [logserver.rdoproject.org] 2025-10-08 10:44:10.342245 | 2025-10-08 10:44:10.342305 | TASK [Set zuul-log-path fact] 2025-10-08 10:44:10.358607 | logserver.rdoproject.org | ok 2025-10-08 10:44:10.379190 | 2025-10-08 10:44:10.379409 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 10:44:10.413176 | logserver.rdoproject.org | ok 2025-10-08 10:44:10.426432 | 2025-10-08 10:44:10.426586 | TASK [upload-logs : Create log directories] 2025-10-08 10:44:11.181287 | logserver.rdoproject.org | changed 2025-10-08 10:44:11.184567 | 2025-10-08 10:44:11.184635 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 10:44:11.476757 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009078 2025-10-08 10:44:11.483548 | 2025-10-08 10:44:11.483698 | TASK [upload-logs : Upload logs to log server] 2025-10-08 10:44:12.244370 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 10:44:12.247642 | 2025-10-08 10:44:12.247734 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 10:44:12.315041 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 10:44:12.327875 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 10:44:12.336816 | 2025-10-08 10:44:12.336891 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 10:44:12.387294 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 10:44:12.387735 | 2025-10-08 10:44:12.390740 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 10:44:12.399455 | 2025-10-08 10:44:12.399602 | LOOP [upload-logs : Upload console log and json output]