2025-11-25 14:02:11.242021 | Job console starting... 2025-11-25 14:02:11.260709 | Updating repositories 2025-11-25 14:02:11.286756 | Preparing job workspace 2025-11-25 14:02:15.797882 | Running Ansible setup... 2025-11-25 14:02:20.105103 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-25 14:02:20.718114 | 2025-11-25 14:02:20.718251 | PLAY [localhost] 2025-11-25 14:02:20.726712 | 2025-11-25 14:02:20.726780 | TASK [Gathering Facts] 2025-11-25 14:02:21.816208 | localhost | ok 2025-11-25 14:02:21.853167 | 2025-11-25 14:02:21.853303 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-25 14:02:22.374740 | localhost -> localhost | changed 2025-11-25 14:02:22.380226 | 2025-11-25 14:02:22.380294 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-25 14:02:23.289034 | localhost -> localhost | changed 2025-11-25 14:02:23.298003 | 2025-11-25 14:02:23.298088 | TASK [Setup log path fact] 2025-11-25 14:02:23.315708 | localhost | ok 2025-11-25 14:02:23.327306 | 2025-11-25 14:02:23.327376 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-25 14:02:23.355290 | localhost | ok 2025-11-25 14:02:23.363251 | 2025-11-25 14:02:23.363319 | TASK [emit-job-header : Print job information] 2025-11-25 14:02:23.391003 | # Job Information 2025-11-25 14:02:23.391183 | Ansible Version: 2.15.12 2025-11-25 14:02:23.391210 | Job: cifmw-molecule-switch_config 2025-11-25 14:02:23.391230 | Pipeline: github-check 2025-11-25 14:02:23.391248 | Executor: ze02.softwarefactory-project.io 2025-11-25 14:02:23.391269 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3505 2025-11-25 14:02:23.391289 | Log URL (when completed): https://logserver.rdoproject.org/e8e/rdoproject.org/e8ecf86c9e33403cbb4305ff8cdedb90/ 2025-11-25 14:02:23.391307 | Event ID: 1ddbeee0-ca07-11f0-9bf4-54479d946bd8 2025-11-25 14:02:23.395258 | 2025-11-25 14:02:23.395319 | LOOP [emit-job-header : Print node information] 2025-11-25 14:02:23.499951 | localhost | ok: 2025-11-25 14:02:23.500116 | localhost | # Node Information 2025-11-25 14:02:23.500142 | localhost | Inventory Hostname: controller 2025-11-25 14:02:23.500165 | localhost | Hostname: np0005535260 2025-11-25 14:02:23.500184 | localhost | Username: zuul 2025-11-25 14:02:23.500204 | localhost | Distro: CentOS 9 2025-11-25 14:02:23.500226 | localhost | Provider: vexxhost-nodepool-tripleo 2025-11-25 14:02:23.500319 | localhost | Region: RegionOne 2025-11-25 14:02:23.500344 | localhost | Label: cloud-centos-9-stream-tripleo 2025-11-25 14:02:23.500362 | localhost | Product Name: OpenStack Nova 2025-11-25 14:02:23.500379 | localhost | Interface IP: 38.102.83.130 2025-11-25 14:02:23.548782 | 2025-11-25 14:02:23.548872 | PLAY [all] 2025-11-25 14:02:23.559960 | 2025-11-25 14:02:23.560068 | TASK [Gather network facts] 2025-11-25 14:02:24.026565 | controller | ok 2025-11-25 14:02:24.040873 | 2025-11-25 14:02:24.040946 | TASK [include_role : start-zuul-console] 2025-11-25 14:02:24.059366 | controller | ok 2025-11-25 14:02:24.071613 | 2025-11-25 14:02:24.071737 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-25 14:02:25.955935 | controller | ok 2025-11-25 14:02:25.974827 | 2025-11-25 14:02:25.974912 | TASK [include_role : add-build-sshkey] 2025-11-25 14:02:25.994060 | controller | ok 2025-11-25 14:02:26.007373 | 2025-11-25 14:02:26.007439 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-25 14:02:26.274975 | controller -> localhost | ok 2025-11-25 14:02:26.280693 | 2025-11-25 14:02:26.280755 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-25 14:02:26.299597 | controller | ok 2025-11-25 14:02:26.314208 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-25 14:02:26.323568 | 2025-11-25 14:02:26.323648 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-25 14:02:27.607007 | controller -> localhost | Generating public/private rsa key pair. 2025-11-25 14:02:27.607248 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/e8ecf86c9e33403cbb4305ff8cdedb90_id_rsa. 2025-11-25 14:02:27.607280 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/e8ecf86c9e33403cbb4305ff8cdedb90_id_rsa.pub. 2025-11-25 14:02:27.607302 | controller -> localhost | The key fingerprint is: 2025-11-25 14:02:27.607321 | controller -> localhost | SHA256:doyWCI9W0LnQl0qZmD2T7QnTf3BcXky3Drqd9NouGzM zuul-build-sshkey 2025-11-25 14:02:27.607339 | controller -> localhost | The key's randomart image is: 2025-11-25 14:02:27.607358 | controller -> localhost | +---[RSA 3072]----+ 2025-11-25 14:02:27.607374 | controller -> localhost | | .* B . . ..o+| 2025-11-25 14:02:27.607393 | controller -> localhost | | +.# = . o. .+| 2025-11-25 14:02:27.607411 | controller -> localhost | | .o.X o o ... | 2025-11-25 14:02:27.607428 | controller -> localhost | | =o.o+. o o | 2025-11-25 14:02:27.607446 | controller -> localhost | | o o S oo . . | 2025-11-25 14:02:27.607462 | controller -> localhost | | . o . + o | 2025-11-25 14:02:27.607479 | controller -> localhost | | . E . | 2025-11-25 14:02:27.607498 | controller -> localhost | | .* | 2025-11-25 14:02:27.607516 | controller -> localhost | | o+o | 2025-11-25 14:02:27.607532 | controller -> localhost | +----[SHA256]-----+ 2025-11-25 14:02:27.607578 | controller -> localhost | ok: Runtime: 0:00:00.870946 2025-11-25 14:02:27.613828 | 2025-11-25 14:02:27.613889 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-25 14:02:27.644598 | controller | ok 2025-11-25 14:02:27.662754 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-25 14:02:27.695780 | 2025-11-25 14:02:27.695892 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-25 14:02:27.726555 | controller | skipping: Conditional result was False 2025-11-25 14:02:27.733145 | 2025-11-25 14:02:27.733215 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-25 14:02:28.241179 | controller | changed 2025-11-25 14:02:28.246325 | 2025-11-25 14:02:28.246385 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-25 14:02:28.530118 | controller | ok 2025-11-25 14:02:28.534967 | 2025-11-25 14:02:28.535027 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-25 14:02:29.408717 | controller | changed 2025-11-25 14:02:29.425353 | 2025-11-25 14:02:29.425476 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-25 14:02:30.218623 | controller | changed 2025-11-25 14:02:30.223968 | 2025-11-25 14:02:30.224032 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-25 14:02:30.249314 | controller | skipping: Conditional result was False 2025-11-25 14:02:30.258526 | 2025-11-25 14:02:30.258633 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-25 14:02:30.687710 | controller -> localhost | changed 2025-11-25 14:02:30.697551 | 2025-11-25 14:02:30.697618 | TASK [add-build-sshkey : Add back temp key] 2025-11-25 14:02:30.976151 | controller -> localhost | Identity added: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/e8ecf86c9e33403cbb4305ff8cdedb90_id_rsa (zuul-build-sshkey) 2025-11-25 14:02:30.976339 | controller -> localhost | ok: Runtime: 0:00:00.018399 2025-11-25 14:02:30.982312 | 2025-11-25 14:02:30.982373 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-25 14:02:31.361509 | controller | ok 2025-11-25 14:02:31.373253 | 2025-11-25 14:02:31.373318 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-25 14:02:31.424916 | controller | skipping: Conditional result was False 2025-11-25 14:02:31.434788 | 2025-11-25 14:02:31.434856 | TASK [include_role : validate-host] 2025-11-25 14:02:31.474726 | controller | ok 2025-11-25 14:02:31.531386 | 2025-11-25 14:02:31.531567 | TASK [validate-host : Define zuul_info_dir fact] 2025-11-25 14:02:31.562251 | controller | ok 2025-11-25 14:02:31.567050 | 2025-11-25 14:02:31.567117 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-11-25 14:02:31.807712 | controller -> localhost | ok 2025-11-25 14:02:31.813656 | 2025-11-25 14:02:31.813741 | TASK [validate-host : Collect information about the host] 2025-11-25 14:02:32.571637 | controller | ok 2025-11-25 14:02:32.582023 | 2025-11-25 14:02:32.582084 | TASK [validate-host : Sanitize hostname] 2025-11-25 14:02:32.642408 | controller | ok 2025-11-25 14:02:32.651155 | 2025-11-25 14:02:32.651236 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-11-25 14:02:33.108776 | controller -> localhost | changed 2025-11-25 14:02:33.116758 | 2025-11-25 14:02:33.116826 | TASK [validate-host : Collect information about zuul worker] 2025-11-25 14:02:33.623303 | controller | ok 2025-11-25 14:02:33.628419 | 2025-11-25 14:02:33.628486 | TASK [validate-host : Write out all zuul information for each host] 2025-11-25 14:02:34.121494 | controller -> localhost | changed 2025-11-25 14:02:34.131087 | 2025-11-25 14:02:34.131147 | TASK [include_role : prepare-workspace-openshift] 2025-11-25 14:02:34.149600 | controller | skipping: Conditional result was False 2025-11-25 14:02:34.154457 | 2025-11-25 14:02:34.154518 | TASK [include_role : remove-zuul-sshkey] 2025-11-25 14:02:34.188586 | controller | skipping: Conditional result was False 2025-11-25 14:02:34.194659 | 2025-11-25 14:02:34.194795 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-25 14:02:34.437736 | controller | ok: "logs" 2025-11-25 14:02:34.438114 | controller | ok: All items complete 2025-11-25 14:02:34.438148 | 2025-11-25 14:02:34.658085 | controller | ok: "artifacts" 2025-11-25 14:02:34.895524 | controller | ok: "docs" 2025-11-25 14:02:34.915930 | 2025-11-25 14:02:34.916139 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-25 14:02:35.195751 | controller | changed: "logs" 2025-11-25 14:02:35.395695 | controller | changed: "artifacts" 2025-11-25 14:02:35.628180 | controller | changed: "docs" 2025-11-25 14:02:35.660966 | 2025-11-25 14:02:35.661067 | PLAY RECAP 2025-11-25 14:02:35.661124 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-11-25 14:02:35.661150 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-25 14:02:35.661168 | 2025-11-25 14:02:35.770553 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-25 14:02:35.771375 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-25 14:02:36.359257 | 2025-11-25 14:02:36.359363 | PLAY [localhost] 2025-11-25 14:02:36.383072 | 2025-11-25 14:02:36.383147 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-11-25 14:02:36.803100 | localhost | ok 2025-11-25 14:02:36.819442 | 2025-11-25 14:02:36.819573 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-11-25 14:02:37.471905 | localhost | changed 2025-11-25 14:02:37.492332 | 2025-11-25 14:02:37.492395 | PLAY [all] 2025-11-25 14:02:37.507556 | 2025-11-25 14:02:37.507616 | TASK [include_role : prepare-workspace] 2025-11-25 14:02:37.526769 | controller | ok 2025-11-25 14:02:37.540612 | 2025-11-25 14:02:37.540698 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-25 14:02:37.942254 | controller | ok 2025-11-25 14:02:37.948178 | 2025-11-25 14:02:37.948241 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-25 14:02:39.514658 | controller | Output suppressed because no_log was given 2025-11-25 14:02:39.525161 | 2025-11-25 14:02:39.525232 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-25 14:02:39.762289 | controller | changed: "logs" 2025-11-25 14:02:39.971120 | controller | changed: "artifacts" 2025-11-25 14:02:40.189962 | controller | changed: "docs" 2025-11-25 14:02:40.203461 | 2025-11-25 14:02:40.203620 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-25 14:02:40.453415 | controller | changed: "logs" 2025-11-25 14:02:40.453888 | controller | changed: All items complete 2025-11-25 14:02:40.453948 | 2025-11-25 14:02:40.686989 | controller | changed: "artifacts" 2025-11-25 14:02:40.905357 | controller | changed: "docs" 2025-11-25 14:02:40.945567 | 2025-11-25 14:02:40.945809 | TASK [Check if worker can sudo] 2025-11-25 14:02:41.994293 | controller | ok: Runtime: 0:00:00.078346 2025-11-25 14:02:42.007606 | 2025-11-25 14:02:42.007783 | TASK [configure-mirrors : Gather needed facts] 2025-11-25 14:02:42.106919 | controller | skipping: Conditional result was False 2025-11-25 14:02:42.119563 | 2025-11-25 14:02:42.120124 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-11-25 14:02:42.210452 | controller | ok 2025-11-25 14:02:42.222106 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-11-25 14:02:42.236453 | 2025-11-25 14:02:42.236600 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-11-25 14:02:42.563917 | controller | ok 2025-11-25 14:02:42.572204 | 2025-11-25 14:02:42.572287 | LOOP [configure-mirrors : Include OS-specific variables] 2025-11-25 14:02:42.655263 | controller | ok: "/var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-11-25 14:02:42.671177 | 2025-11-25 14:02:42.671241 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-11-25 14:02:43.510149 | controller | changed 2025-11-25 14:02:43.521011 | 2025-11-25 14:02:43.521089 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-11-25 14:02:43.577234 | controller | ok: "/var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-11-25 14:02:43.577449 | controller | ok: All items complete 2025-11-25 14:02:43.577480 | 2025-11-25 14:02:43.634710 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-11-25 14:02:43.646731 | 2025-11-25 14:02:43.646846 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-11-25 14:02:44.603312 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-11-25 14:02:45.428085 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-11-25 14:02:45.438154 | 2025-11-25 14:02:45.438266 | TASK [configure-mirrors : Disable deltrarpm] 2025-11-25 14:02:45.921009 | controller | changed: section and option added 2025-11-25 14:02:45.940760 | 2025-11-25 14:02:45.940821 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-11-25 14:02:46.911376 | controller | 29 files removed 2025-11-25 14:02:46.911596 | controller | ok: Item: dnf clean all Runtime: 0:00:00.655998 2025-11-25 14:02:46.911637 | controller | changed: All items complete 2025-11-25 14:02:46.911659 | 2025-11-25 14:03:02.141049 | 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-11-25 14:03:02.141156 | controller | DNF version: 4.14.0 2025-11-25 14:03:02.141182 | controller | cachedir: /var/cache/dnf 2025-11-25 14:03:02.141202 | controller | Making cache files for all metadata files. 2025-11-25 14:03:02.141220 | controller | baseos: has expired and will be refreshed. 2025-11-25 14:03:02.141238 | controller | appstream: has expired and will be refreshed. 2025-11-25 14:03:02.141255 | controller | crb: has expired and will be refreshed. 2025-11-25 14:03:02.141281 | controller | extras-common: has expired and will be refreshed. 2025-11-25 14:03:02.141299 | controller | repo: downloading from remote: baseos 2025-11-25 14:03:02.141316 | controller | CentOS Stream 9 - BaseOS 8.1 MB/s | 8.8 MB 00:01 2025-11-25 14:03:02.141333 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST. 2025-11-25 14:03:02.141351 | controller | repo: downloading from remote: appstream 2025-11-25 14:03:02.141368 | controller | CentOS Stream 9 - AppStream 9.1 MB/s | 25 MB 00:02 2025-11-25 14:03:02.141386 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST. 2025-11-25 14:03:02.141403 | controller | repo: downloading from remote: crb 2025-11-25 14:03:02.141421 | controller | CentOS Stream 9 - CRB 15 MB/s | 7.3 MB 00:00 2025-11-25 14:03:02.141438 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST. 2025-11-25 14:03:02.141456 | controller | repo: downloading from remote: extras-common 2025-11-25 14:03:02.141473 | controller | CentOS Stream 9 - Extras packages 309 kB/s | 20 kB 00:00 2025-11-25 14:03:02.141491 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-11-25 14:03:02.141507 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-11-25 14:03:02.141524 | controller | Completion plugin: Generating completion cache... 2025-11-25 14:03:02.141541 | controller | Metadata cache created. 2025-11-25 14:03:02.141566 | controller | ok: Item: dnf makecache -v Runtime: 0:00:14.938900 2025-11-25 14:03:02.158258 | 2025-11-25 14:03:02.158345 | PLAY RECAP 2025-11-25 14:03:02.158384 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-11-25 14:03:02.158408 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-25 14:03:02.158425 | 2025-11-25 14:03:02.290513 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-25 14:03:02.291338 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-25 14:03:02.886582 | 2025-11-25 14:03:02.886828 | PLAY [all] 2025-11-25 14:03:02.910021 | 2025-11-25 14:03:02.910160 | TASK [Install binary dependencies] 2025-11-25 14:03:02.949778 | controller | ok 2025-11-25 14:03:02.969603 | 2025-11-25 14:03:02.969732 | TASK [bindep : Include find tasks] 2025-11-25 14:03:02.998981 | controller | ok 2025-11-25 14:03:03.006513 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-25 14:03:03.012901 | 2025-11-25 14:03:03.012968 | TASK [bindep : Look for bindep.txt] 2025-11-25 14:03:03.438730 | controller | ok 2025-11-25 14:03:03.454059 | 2025-11-25 14:03:03.454188 | TASK [bindep : Define bindep_file fact] 2025-11-25 14:03:03.500895 | controller | ok 2025-11-25 14:03:03.506294 | 2025-11-25 14:03:03.506361 | TASK [bindep : Look for other-requirements.txt] 2025-11-25 14:03:03.542129 | controller | skipping: Conditional result was False 2025-11-25 14:03:03.548560 | 2025-11-25 14:03:03.548633 | TASK [bindep : Define bindep_file fact] 2025-11-25 14:03:03.593369 | controller | skipping: Conditional result was False 2025-11-25 14:03:03.599041 | 2025-11-25 14:03:03.599111 | TASK [bindep : Look for bindep fallback file] 2025-11-25 14:03:03.623893 | controller | skipping: Conditional result was False 2025-11-25 14:03:03.629973 | 2025-11-25 14:03:03.630045 | TASK [bindep : Define bindep_file fact] 2025-11-25 14:03:03.654102 | controller | skipping: Conditional result was False 2025-11-25 14:03:03.659883 | 2025-11-25 14:03:03.659949 | TASK [bindep : Include bindep tasks] 2025-11-25 14:03:03.696115 | controller | ok 2025-11-25 14:03:03.703858 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-11-25 14:03:03.714707 | 2025-11-25 14:03:03.714791 | TASK [bindep : Look for bindep command] 2025-11-25 14:03:03.738859 | controller | skipping: Conditional result was False 2025-11-25 14:03:03.747402 | 2025-11-25 14:03:03.747480 | TASK [bindep : Check for system bindep] 2025-11-25 14:03:04.281280 | controller | ok: Runtime: 0:00:00.010126 2025-11-25 14:03:04.287277 | 2025-11-25 14:03:04.287348 | TASK [bindep : Define bindep_command fact] 2025-11-25 14:03:04.311214 | controller | skipping: Conditional result was False 2025-11-25 14:03:04.318051 | 2025-11-25 14:03:04.318124 | TASK [bindep : Include install tasks] 2025-11-25 14:03:04.348486 | controller | ok 2025-11-25 14:03:04.356292 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-11-25 14:03:04.368347 | 2025-11-25 14:03:04.368418 | TASK [bindep : Create temp dir for bindep] 2025-11-25 14:03:04.773573 | controller | changed 2025-11-25 14:03:04.780016 | 2025-11-25 14:03:04.780146 | TASK [Ensure we have pip dependencies] 2025-11-25 14:03:04.807581 | controller | ok 2025-11-25 14:03:04.841799 | 2025-11-25 14:03:04.841913 | TASK [ensure-pip : Check if pip is installed] 2025-11-25 09:03:05.107149 | controller | /usr/bin/pip3 2025-11-25 09:03:05.162942 | controller | /usr/bin/python3: No module named wheel 2025-11-25 14:03:05.370867 | controller | ok: Runtime: 0:00:00.085070 2025-11-25 14:03:05.384181 | 2025-11-25 14:03:05.384463 | LOOP [ensure-pip : Install pip from packages] 2025-11-25 14:03:05.411633 | controller | ok: "/var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-11-25 14:03:05.438437 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-11-25 14:03:05.461133 | 2025-11-25 14:03:05.461231 | TASK [ensure-pip : Install Python 3 pip] 2025-11-25 14:03:09.198523 | controller | changed 2025-11-25 14:03:09.204256 | 2025-11-25 14:03:09.204318 | TASK [ensure-pip : Check for EPEL repository] 2025-11-25 14:03:09.254112 | controller | skipping: Conditional result was False 2025-11-25 14:03:09.262425 | 2025-11-25 14:03:09.262494 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-11-25 14:03:09.310268 | controller | skipping: Conditional result was False 2025-11-25 14:03:09.318438 | 2025-11-25 14:03:09.318509 | TASK [ensure-pip : Install Python 2 pip] 2025-11-25 14:03:09.353108 | controller | skipping: Conditional result was False 2025-11-25 14:03:09.359556 | 2025-11-25 14:03:09.359622 | TASK [ensure-pip : Ensure setuptools] 2025-11-25 14:03:09.383474 | controller | skipping: Conditional result was False 2025-11-25 14:03:09.390040 | 2025-11-25 14:03:09.390106 | TASK [ensure-pip : Check for ensurepip module] 2025-11-25 14:03:09.919095 | controller | skipping: Conditional result was False 2025-11-25 14:03:09.931713 | 2025-11-25 14:03:09.931867 | TASK [ensure-pip : Ensure python3-venv] 2025-11-25 14:03:09.968628 | controller | skipping: Conditional result was False 2025-11-25 14:03:09.983024 | 2025-11-25 14:03:09.983255 | TASK [ensure-pip : Install pip from source] 2025-11-25 14:03:10.012867 | controller | skipping: Conditional result was False 2025-11-25 14:03:10.027836 | 2025-11-25 14:03:10.028145 | TASK [ensure-pip : Probe for venv python full path] 2025-11-25 09:03:10.374582 | controller | /usr/bin/python3 2025-11-25 14:03:10.584178 | controller | ok: Runtime: 0:00:00.009146 2025-11-25 14:03:10.596641 | 2025-11-25 14:03:10.596835 | TASK [ensure-pip : Set host default] 2025-11-25 14:03:10.675773 | controller | ok 2025-11-25 14:03:10.687324 | 2025-11-25 14:03:10.687462 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-11-25 14:03:10.761018 | controller | ok 2025-11-25 14:03:10.782585 | 2025-11-25 14:03:10.782688 | TASK [bindep : Install bindep into temporary venv] 2025-11-25 14:03:16.079657 | controller | changed 2025-11-25 14:03:16.087511 | 2025-11-25 14:03:16.087581 | TASK [bindep : Define bindep_command] 2025-11-25 14:03:16.125152 | controller | ok 2025-11-25 14:03:16.134879 | 2025-11-25 14:03:16.134968 | LOOP [bindep : Include package tasks] 2025-11-25 14:03:16.192255 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-11-25 14:03:16.192486 | controller | ok: All items complete 2025-11-25 14:03:16.192514 | 2025-11-25 14:03:16.207957 | controller | included: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-11-25 14:03:16.218374 | 2025-11-25 14:03:16.218435 | TASK [bindep : Define bindep_run fact] 2025-11-25 14:03:16.246947 | controller | ok 2025-11-25 14:03:16.252730 | 2025-11-25 14:03:16.252793 | TASK [bindep : Get list of packages to install from bindep] 2025-11-25 09:03:18.217803 | controller | podman 2025-11-25 09:03:18.264353 | controller | python3-jmespath 2025-11-25 09:03:18.264563 | controller | python3-libvirt 2025-11-25 09:03:18.264597 | controller | python3-lxml 2025-11-25 09:03:18.264625 | controller | python3-netaddr 2025-11-25 14:03:18.292561 | controller | ok: Runtime: 0:00:01.755118 2025-11-25 14:03:18.298081 | 2025-11-25 14:03:18.298145 | TASK [bindep : Install distro packages from bindep] 2025-11-25 14:04:43.228066 | controller | changed 2025-11-25 14:04:43.241240 | 2025-11-25 14:04:43.241425 | TASK [bindep : Check that packages are installed] 2025-11-25 14:04:44.784077 | controller | ok: Runtime: 0:00:01.089799 2025-11-25 14:04:44.791887 | 2025-11-25 14:04:44.792005 | TASK [bindep : Fail if we cannot install all packages] 2025-11-25 14:04:44.827336 | controller | skipping: Conditional result was False 2025-11-25 14:04:44.841282 | 2025-11-25 14:04:44.841380 | TASK [Run test-setup role] 2025-11-25 14:04:44.863335 | controller | ok 2025-11-25 14:04:44.887131 | 2025-11-25 14:04:44.887243 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-25 14:04:45.170047 | controller | ok 2025-11-25 14:04:45.175356 | 2025-11-25 14:04:45.175428 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-25 14:04:45.708274 | controller | skipping: Conditional result was False 2025-11-25 14:04:45.728064 | 2025-11-25 14:04:45.728139 | TASK [bindep : Remove bindep temp dir] 2025-11-25 14:04:46.165842 | controller | ok 2025-11-25 14:04:46.176296 | 2025-11-25 14:04:46.176356 | PLAY RECAP 2025-11-25 14:04:46.176399 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-11-25 14:04:46.176421 | 2025-11-25 14:04:46.286291 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-25 14:04:46.287177 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-25 14:04:46.908472 | 2025-11-25 14:04:46.908620 | PLAY [all] 2025-11-25 14:04:46.929217 | 2025-11-25 14:04:46.929366 | TASK [Abort when test_command variable is undefined] 2025-11-25 14:04:46.975241 | controller | skipping: Conditional result was False 2025-11-25 14:04:46.981790 | 2025-11-25 14:04:46.981863 | TASK [Convert test_command to list] 2025-11-25 14:04:47.026354 | controller | skipping: Conditional result was False 2025-11-25 14:04:47.033647 | 2025-11-25 14:04:47.033759 | TASK [Use test_command list] 2025-11-25 14:04:47.084230 | controller | ok 2025-11-25 14:04:47.090833 | 2025-11-25 14:04:47.090921 | LOOP [Run test_command] 2025-11-25 14:04:47.500539 | controller | no check to run 2025-11-25 14:04:47.500932 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.003798 2025-11-25 14:04:47.553358 | 2025-11-25 14:04:47.553553 | PLAY RECAP 2025-11-25 14:04:47.553636 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-25 14:04:47.553717 | 2025-11-25 14:04:47.656438 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-25 14:04:47.658216 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-25 14:04:48.244903 | 2025-11-25 14:04:48.245012 | PLAY [all] 2025-11-25 14:04:48.265273 | 2025-11-25 14:04:48.265352 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-25 14:04:48.639741 | controller | changed: non-zero return code 2025-11-25 14:04:48.652343 | 2025-11-25 14:04:48.652511 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-25 14:04:48.680329 | controller | skipping: Conditional result was False 2025-11-25 14:04:48.693391 | 2025-11-25 14:04:48.693545 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-25 14:04:48.733861 | 2025-11-25 14:04:48.734112 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-25 14:04:48.774029 | 2025-11-25 14:04:48.774266 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-25 14:04:48.801162 | controller | skipping: Conditional result was False 2025-11-25 14:04:48.813392 | 2025-11-25 14:04:48.813526 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-25 14:04:48.851467 | 2025-11-25 14:04:48.851733 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-25 14:04:48.881220 | controller | skipping: Conditional result was False 2025-11-25 14:04:48.893373 | 2025-11-25 14:04:48.893508 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-25 14:04:48.920115 | controller | skipping: Conditional result was False 2025-11-25 14:04:48.932076 | 2025-11-25 14:04:48.932212 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-25 14:04:48.958490 | controller | skipping: Conditional result was False 2025-11-25 14:04:49.001998 | 2025-11-25 14:04:49.002071 | PLAY RECAP 2025-11-25 14:04:49.002124 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-25 14:04:49.002151 | 2025-11-25 14:04:49.099362 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-25 14:04:49.101165 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-25 14:04:49.676966 | 2025-11-25 14:04:49.677074 | PLAY [all] 2025-11-25 14:04:49.696008 | 2025-11-25 14:04:49.696129 | TASK [include_role : fetch-output] 2025-11-25 14:04:49.735952 | controller | ok 2025-11-25 14:04:49.753299 | 2025-11-25 14:04:49.753381 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-25 14:04:49.828064 | controller | skipping: Conditional result was False 2025-11-25 14:04:49.833814 | 2025-11-25 14:04:49.833885 | TASK [fetch-output : Set log path for single node] 2025-11-25 14:04:49.889411 | controller | ok 2025-11-25 14:04:49.901656 | 2025-11-25 14:04:49.901905 | LOOP [fetch-output : Ensure local output dirs] 2025-11-25 14:04:50.404141 | controller -> localhost | ok: "/var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/logs" 2025-11-25 14:04:50.611132 | controller -> localhost | changed: "/var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/artifacts" 2025-11-25 14:04:50.815132 | controller -> localhost | changed: "/var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/docs" 2025-11-25 14:04:50.832193 | 2025-11-25 14:04:50.832330 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-25 14:04:51.507394 | controller | changed: .d..t...... ./ 2025-11-25 14:04:51.507766 | controller | changed: All items complete 2025-11-25 14:04:51.507828 | 2025-11-25 14:04:52.025743 | controller | changed: .d..t...... ./ 2025-11-25 14:04:52.510923 | controller | changed: .d..t...... ./ 2025-11-25 14:04:52.553069 | 2025-11-25 14:04:52.553362 | TASK [include_role : fetch-output-openshift] 2025-11-25 14:04:52.583817 | controller | skipping: Conditional result was False 2025-11-25 14:04:52.604466 | 2025-11-25 14:04:52.605044 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-25 14:04:53.065177 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013135 2025-11-25 14:04:53.293577 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.016301 2025-11-25 14:04:53.327844 | 2025-11-25 14:04:53.328048 | PLAY [all] 2025-11-25 14:04:53.343987 | 2025-11-25 14:04:53.344103 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-11-25 14:04:53.798521 | controller | changed 2025-11-25 14:04:53.852418 | 2025-11-25 14:04:53.852518 | PLAY RECAP 2025-11-25 14:04:53.852570 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-25 14:04:53.852599 | 2025-11-25 14:04:53.946447 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-25 14:04:53.947276 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-11-25 14:04:54.521954 | 2025-11-25 14:04:54.522063 | PLAY [localhost] 2025-11-25 14:04:54.540152 | 2025-11-25 14:04:54.540236 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-25 14:04:54.950060 | localhost | changed 2025-11-25 14:04:54.960952 | 2025-11-25 14:04:54.961060 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-25 14:04:55.003729 | localhost | ok 2025-11-25 14:04:55.022911 | 2025-11-25 14:04:55.023022 | TASK [add-fileserver : Create SSH private key tempfile] 2025-11-25 14:04:55.385882 | localhost | changed 2025-11-25 14:04:55.391635 | 2025-11-25 14:04:55.391720 | TASK [add-fileserver : Create SSH private key from secret] 2025-11-25 14:04:56.152187 | localhost | changed 2025-11-25 14:04:56.157293 | 2025-11-25 14:04:56.157360 | TASK [add-fileserver : Add fileserver ssh key] 2025-11-25 14:04:56.542763 | localhost | Identity added: /var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/tmp/ansible.xuh_5k4x (/var/lib/zuul/builds/e8ecf86c9e33403cbb4305ff8cdedb90/work/tmp/ansible.xuh_5k4x) 2025-11-25 14:04:56.542938 | localhost | ok: Runtime: 0:00:00.007249 2025-11-25 14:04:56.548154 | 2025-11-25 14:04:56.548221 | TASK [add-fileserver : Remove SSH private key from disk] 2025-11-25 14:04:56.826077 | localhost | ok: Runtime: 0:00:00.008291 2025-11-25 14:04:56.837223 | 2025-11-25 14:04:56.837399 | TASK [add-fileserver : Add fileserver to inventory] 2025-11-25 14:04:56.907554 | localhost | changed 2025-11-25 14:04:56.917571 | 2025-11-25 14:04:56.917748 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-11-25 14:04:57.317786 | localhost | changed 2025-11-25 14:04:57.341293 | 2025-11-25 14:04:57.341465 | PLAY [localhost] 2025-11-25 14:04:57.355023 | 2025-11-25 14:04:57.355108 | TASK [Generate bulk log download script] 2025-11-25 14:04:57.384109 | localhost | ok 2025-11-25 14:04:57.396329 | 2025-11-25 14:04:57.396399 | TASK [local-log-download : Check API endpoint is defined] 2025-11-25 14:04:57.425097 | localhost | ok: All assertions passed 2025-11-25 14:04:57.429785 | 2025-11-25 14:04:57.429850 | TASK [local-log-download : Create download script] 2025-11-25 14:04:57.978927 | localhost -> localhost | changed 2025-11-25 14:04:58.003381 | 2025-11-25 14:04:58.003600 | TASK [Register quick-download link] 2025-11-25 14:04:58.030323 | localhost | ok 2025-11-25 14:04:58.089798 | 2025-11-25 14:04:58.090035 | PLAY [logserver.rdoproject.org] 2025-11-25 14:04:58.099882 | 2025-11-25 14:04:58.099941 | TASK [Set zuul-log-path fact] 2025-11-25 14:04:58.117606 | logserver.rdoproject.org | ok 2025-11-25 14:04:58.127159 | 2025-11-25 14:04:58.127225 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-25 14:04:58.154929 | logserver.rdoproject.org | ok 2025-11-25 14:04:58.161113 | 2025-11-25 14:04:58.161193 | TASK [upload-logs : Create log directories] 2025-11-25 14:04:58.871137 | logserver.rdoproject.org | changed 2025-11-25 14:04:58.878835 | 2025-11-25 14:04:58.878972 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-11-25 14:04:59.210145 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.013766 2025-11-25 14:04:59.218796 | 2025-11-25 14:04:59.218902 | TASK [upload-logs : Upload logs to log server] 2025-11-25 14:04:59.905195 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-11-25 14:04:59.909562 | 2025-11-25 14:04:59.909651 | LOOP [upload-logs : Compress console log and json output] 2025-11-25 14:04:59.952048 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 14:04:59.961946 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 14:04:59.972035 | 2025-11-25 14:04:59.972159 | LOOP [upload-logs : Upload compressed console log and json output] 2025-11-25 14:05:00.008825 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 14:05:00.009092 | 2025-11-25 14:05:00.013436 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-25 14:05:00.022221 | 2025-11-25 14:05:00.022340 | LOOP [upload-logs : Upload console log and json output]