2025-10-08 05:36:40.357132 | Job console starting... 2025-10-08 05:36:40.368895 | Updating repositories 2025-10-08 05:36:40.392642 | Preparing job workspace 2025-10-08 05:36:44.309972 | Running Ansible setup... 2025-10-08 05:36:48.166846 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 05:36:48.757709 | 2025-10-08 05:36:48.757842 | PLAY [localhost] 2025-10-08 05:36:48.766622 | 2025-10-08 05:36:48.766717 | TASK [Gathering Facts] 2025-10-08 05:36:49.733221 | localhost | ok 2025-10-08 05:36:49.754694 | 2025-10-08 05:36:49.754809 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 05:36:50.177081 | localhost -> localhost | changed 2025-10-08 05:36:50.182894 | 2025-10-08 05:36:50.182962 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 05:36:50.983987 | localhost -> localhost | changed 2025-10-08 05:36:50.992765 | 2025-10-08 05:36:50.992834 | TASK [Setup log path fact] 2025-10-08 05:36:51.010157 | localhost | ok 2025-10-08 05:36:51.021278 | 2025-10-08 05:36:51.021344 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 05:36:51.048143 | localhost | ok 2025-10-08 05:36:51.055759 | 2025-10-08 05:36:51.055823 | TASK [emit-job-header : Print job information] 2025-10-08 05:36:51.082302 | # Job Information 2025-10-08 05:36:51.082463 | Ansible Version: 2.15.12 2025-10-08 05:36:51.082493 | Job: cifmw-molecule-switch_config 2025-10-08 05:36:51.082515 | Pipeline: github-check 2025-10-08 05:36:51.082534 | Executor: ze02.softwarefactory-project.io 2025-10-08 05:36:51.082552 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-08 05:36:51.082572 | Log URL (when completed): https://logserver.rdoproject.org/f6f/rdoproject.org/f6f831b641c4403ba5a4cfd290be6986/ 2025-10-08 05:36:51.082592 | Event ID: 920c7930-a408-11f0-96e0-244f77bacc6d 2025-10-08 05:36:51.086416 | 2025-10-08 05:36:51.086480 | LOOP [emit-job-header : Print node information] 2025-10-08 05:36:51.176317 | localhost | ok: 2025-10-08 05:36:51.176516 | localhost | # Node Information 2025-10-08 05:36:51.176543 | localhost | Inventory Hostname: controller 2025-10-08 05:36:51.176566 | localhost | Hostname: np0005475252 2025-10-08 05:36:51.176586 | localhost | Username: zuul 2025-10-08 05:36:51.176607 | localhost | Distro: CentOS 9 2025-10-08 05:36:51.176625 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 05:36:51.176642 | localhost | Region: RegionOne 2025-10-08 05:36:51.176659 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 05:36:51.176697 | localhost | Product Name: OpenStack Nova 2025-10-08 05:36:51.176715 | localhost | Interface IP: 38.102.83.70 2025-10-08 05:36:51.202220 | 2025-10-08 05:36:51.202290 | PLAY [all] 2025-10-08 05:36:51.208733 | 2025-10-08 05:36:51.208797 | TASK [Gather network facts] 2025-10-08 05:36:51.733485 | controller | ok 2025-10-08 05:36:51.771011 | 2025-10-08 05:36:51.771164 | TASK [include_role : start-zuul-console] 2025-10-08 05:36:51.793250 | controller | ok 2025-10-08 05:36:51.812727 | 2025-10-08 05:36:51.812832 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 05:36:52.259190 | controller | ok 2025-10-08 05:36:52.268626 | 2025-10-08 05:36:52.268792 | TASK [include_role : add-build-sshkey] 2025-10-08 05:36:52.303171 | controller | ok 2025-10-08 05:36:52.335418 | 2025-10-08 05:36:52.335547 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 05:36:52.679905 | controller -> localhost | ok 2025-10-08 05:36:52.685462 | 2025-10-08 05:36:52.685523 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 05:36:52.741876 | controller | ok 2025-10-08 05:36:52.767195 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 05:36:52.772902 | 2025-10-08 05:36:52.772965 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 05:36:54.074508 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 05:36:54.075026 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/f6f831b641c4403ba5a4cfd290be6986_id_rsa. 2025-10-08 05:36:54.075098 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/f6f831b641c4403ba5a4cfd290be6986_id_rsa.pub. 2025-10-08 05:36:54.075148 | controller -> localhost | The key fingerprint is: 2025-10-08 05:36:54.075194 | controller -> localhost | SHA256:bD1H01zzKpuVxwYiJpDx/uRSCXOYHifPQf62SoTK+oY zuul-build-sshkey 2025-10-08 05:36:54.075235 | controller -> localhost | The key's randomart image is: 2025-10-08 05:36:54.075276 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 05:36:54.075315 | controller -> localhost | | oo . ..| 2025-10-08 05:36:54.075355 | controller -> localhost | | .o = o .o| 2025-10-08 05:36:54.075395 | controller -> localhost | | X B + + .| 2025-10-08 05:36:54.075436 | controller -> localhost | | + # * o = | 2025-10-08 05:36:54.075475 | controller -> localhost | | S X = + +| 2025-10-08 05:36:54.075513 | controller -> localhost | | . o * + * o | 2025-10-08 05:36:54.075552 | controller -> localhost | | .o . + + | 2025-10-08 05:36:54.075591 | controller -> localhost | | E.. o . | 2025-10-08 05:36:54.075628 | controller -> localhost | | .o. . | 2025-10-08 05:36:54.075702 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 05:36:54.075808 | controller -> localhost | ok: Runtime: 0:00:00.609635 2025-10-08 05:36:54.084808 | 2025-10-08 05:36:54.084896 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 05:36:54.116408 | controller | ok 2025-10-08 05:36:54.130375 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 05:36:54.142076 | 2025-10-08 05:36:54.142162 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 05:36:54.167766 | controller | skipping: Conditional result was False 2025-10-08 05:36:54.176368 | 2025-10-08 05:36:54.176459 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 05:36:54.653244 | controller | changed 2025-10-08 05:36:54.662319 | 2025-10-08 05:36:54.662404 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 05:36:54.961153 | controller | ok 2025-10-08 05:36:54.966400 | 2025-10-08 05:36:54.966466 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 05:36:55.929629 | controller | changed 2025-10-08 05:36:55.935801 | 2025-10-08 05:36:55.935868 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 05:36:56.832090 | controller | changed 2025-10-08 05:36:56.845450 | 2025-10-08 05:36:56.845581 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 05:36:56.868091 | controller | skipping: Conditional result was False 2025-10-08 05:36:56.874062 | 2025-10-08 05:36:56.874129 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 05:36:57.258380 | controller -> localhost | changed 2025-10-08 05:36:57.268947 | 2025-10-08 05:36:57.269099 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 05:36:57.546349 | controller -> localhost | Identity added: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/f6f831b641c4403ba5a4cfd290be6986_id_rsa (zuul-build-sshkey) 2025-10-08 05:36:57.546835 | controller -> localhost | ok: Runtime: 0:00:00.008685 2025-10-08 05:36:57.561205 | 2025-10-08 05:36:57.561339 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 05:36:57.967627 | controller | ok 2025-10-08 05:36:57.977972 | 2025-10-08 05:36:57.978109 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 05:36:58.026623 | controller | skipping: Conditional result was False 2025-10-08 05:36:58.047271 | 2025-10-08 05:36:58.047361 | TASK [include_role : validate-host] 2025-10-08 05:36:58.090007 | controller | ok 2025-10-08 05:36:58.119264 | 2025-10-08 05:36:58.119372 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 05:36:58.148299 | controller | ok 2025-10-08 05:36:58.152877 | 2025-10-08 05:36:58.152939 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 05:36:58.369630 | controller -> localhost | ok 2025-10-08 05:36:58.377219 | 2025-10-08 05:36:58.377304 | TASK [validate-host : Collect information about the host] 2025-10-08 05:36:59.232832 | controller | ok 2025-10-08 05:36:59.256126 | 2025-10-08 05:36:59.256262 | TASK [validate-host : Sanitize hostname] 2025-10-08 05:36:59.326022 | controller | ok 2025-10-08 05:36:59.332763 | 2025-10-08 05:36:59.332975 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 05:36:59.866283 | controller -> localhost | changed 2025-10-08 05:36:59.873609 | 2025-10-08 05:36:59.873738 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 05:37:00.331323 | controller | ok 2025-10-08 05:37:00.338348 | 2025-10-08 05:37:00.338417 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 05:37:00.832228 | controller -> localhost | changed 2025-10-08 05:37:00.842211 | 2025-10-08 05:37:00.842282 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 05:37:00.857408 | controller | skipping: Conditional result was False 2025-10-08 05:37:00.863582 | 2025-10-08 05:37:00.863661 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 05:37:00.880080 | controller | skipping: Conditional result was False 2025-10-08 05:37:00.886885 | 2025-10-08 05:37:00.886974 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 05:37:01.154082 | controller | ok: "logs" 2025-10-08 05:37:01.154498 | controller | ok: All items complete 2025-10-08 05:37:01.154559 | 2025-10-08 05:37:01.395570 | controller | ok: "artifacts" 2025-10-08 05:37:01.663345 | controller | ok: "docs" 2025-10-08 05:37:01.671769 | 2025-10-08 05:37:01.671901 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 05:37:01.917332 | controller | changed: "logs" 2025-10-08 05:37:02.172187 | controller | changed: "artifacts" 2025-10-08 05:37:02.420912 | controller | changed: "docs" 2025-10-08 05:37:02.465852 | 2025-10-08 05:37:02.465993 | PLAY RECAP 2025-10-08 05:37:02.466044 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 05:37:02.466069 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 05:37:02.466087 | 2025-10-08 05:37:02.600391 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 05:37:02.601386 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 05:37:03.451268 | 2025-10-08 05:37:03.451426 | PLAY [localhost] 2025-10-08 05:37:03.475393 | 2025-10-08 05:37:03.475509 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 05:37:03.925551 | localhost | ok 2025-10-08 05:37:03.930836 | 2025-10-08 05:37:03.930913 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 05:37:04.618997 | localhost | changed 2025-10-08 05:37:04.659493 | 2025-10-08 05:37:04.659617 | PLAY [all] 2025-10-08 05:37:04.692815 | 2025-10-08 05:37:04.693125 | TASK [include_role : prepare-workspace] 2025-10-08 05:37:04.727279 | controller | ok 2025-10-08 05:37:04.746581 | 2025-10-08 05:37:04.746674 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 05:37:05.200572 | controller | ok 2025-10-08 05:37:05.207595 | 2025-10-08 05:37:05.207677 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 05:37:06.810745 | controller | Output suppressed because no_log was given 2025-10-08 05:37:06.825724 | 2025-10-08 05:37:06.826042 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 05:37:07.116363 | controller | changed: "logs" 2025-10-08 05:37:07.341183 | controller | changed: "artifacts" 2025-10-08 05:37:07.630804 | controller | changed: "docs" 2025-10-08 05:37:07.646651 | 2025-10-08 05:37:07.646773 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 05:37:07.962405 | controller | changed: "logs" 2025-10-08 05:37:07.962734 | controller | changed: All items complete 2025-10-08 05:37:07.962768 | 2025-10-08 05:37:08.207336 | controller | changed: "artifacts" 2025-10-08 05:37:08.442121 | controller | changed: "docs" 2025-10-08 05:37:08.455584 | 2025-10-08 05:37:08.455654 | TASK [Check if worker can sudo] 2025-10-08 05:37:09.527433 | controller | ok: Runtime: 0:00:00.058112 2025-10-08 05:37:09.533384 | 2025-10-08 05:37:09.533458 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 05:37:09.598567 | controller | skipping: Conditional result was False 2025-10-08 05:37:09.605061 | 2025-10-08 05:37:09.605141 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 05:37:09.710009 | controller | ok 2025-10-08 05:37:09.717608 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 05:37:09.738354 | 2025-10-08 05:37:09.738447 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 05:37:10.173122 | controller | ok 2025-10-08 05:37:10.181991 | 2025-10-08 05:37:10.182081 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 05:37:10.275707 | controller | ok: "/var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 05:37:10.283408 | 2025-10-08 05:37:10.283474 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 05:37:11.380722 | controller | changed 2025-10-08 05:37:11.389092 | 2025-10-08 05:37:11.389262 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 05:37:11.457228 | controller | ok: "/var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 05:37:11.457454 | controller | ok: All items complete 2025-10-08 05:37:11.457480 | 2025-10-08 05:37:11.513508 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 05:37:11.520630 | 2025-10-08 05:37:11.520733 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 05:37:12.543944 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 05:37:13.475280 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 05:37:13.491795 | 2025-10-08 05:37:13.492084 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 05:37:13.991814 | controller | changed: section and option added 2025-10-08 05:37:14.025973 | 2025-10-08 05:37:14.026212 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 05:37:14.825360 | controller | 29 files removed 2025-10-08 05:37:14.825605 | controller | ok: Item: dnf clean all Runtime: 0:00:00.445106 2025-10-08 05:37:14.825643 | controller | changed: All items complete 2025-10-08 05:37:14.825663 | 2025-10-08 05:37:25.145233 | 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 05:37:25.145362 | controller | DNF version: 4.14.0 2025-10-08 05:37:25.145385 | controller | cachedir: /var/cache/dnf 2025-10-08 05:37:25.145404 | controller | Making cache files for all metadata files. 2025-10-08 05:37:25.145421 | controller | baseos: has expired and will be refreshed. 2025-10-08 05:37:25.145437 | controller | appstream: has expired and will be refreshed. 2025-10-08 05:37:25.145454 | controller | crb: has expired and will be refreshed. 2025-10-08 05:37:25.145480 | controller | extras-common: has expired and will be refreshed. 2025-10-08 05:37:25.145498 | controller | repo: downloading from remote: baseos 2025-10-08 05:37:25.145514 | controller | CentOS Stream 9 - BaseOS 72 MB/s | 8.8 MB 00:00 2025-10-08 05:37:25.145530 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 05:37:25.145546 | controller | repo: downloading from remote: appstream 2025-10-08 05:37:25.145561 | controller | CentOS Stream 9 - AppStream 105 MB/s | 25 MB 00:00 2025-10-08 05:37:25.145577 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 05:37:25.145592 | controller | repo: downloading from remote: crb 2025-10-08 05:37:25.145608 | controller | CentOS Stream 9 - CRB 79 MB/s | 7.1 MB 00:00 2025-10-08 05:37:25.145624 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 05:37:25.145640 | controller | repo: downloading from remote: extras-common 2025-10-08 05:37:25.145656 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-08 05:37:25.145699 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 05:37:25.145718 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 05:37:25.145734 | controller | Completion plugin: Generating completion cache... 2025-10-08 05:37:25.145750 | controller | Metadata cache created. 2025-10-08 05:37:25.145774 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.077662 2025-10-08 05:37:25.163472 | 2025-10-08 05:37:25.163757 | PLAY RECAP 2025-10-08 05:37:25.163865 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 05:37:25.163927 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 05:37:25.163965 | 2025-10-08 05:37:25.315153 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 05:37:25.316050 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 05:37:25.884879 | 2025-10-08 05:37:25.885061 | PLAY [all] 2025-10-08 05:37:25.906346 | 2025-10-08 05:37:25.906477 | TASK [Install binary dependencies] 2025-10-08 05:37:25.957368 | controller | ok 2025-10-08 05:37:25.979970 | 2025-10-08 05:37:25.980073 | TASK [bindep : Include find tasks] 2025-10-08 05:37:26.009425 | controller | ok 2025-10-08 05:37:26.016702 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 05:37:26.022576 | 2025-10-08 05:37:26.022638 | TASK [bindep : Look for bindep.txt] 2025-10-08 05:37:26.428704 | controller | ok 2025-10-08 05:37:26.443933 | 2025-10-08 05:37:26.444030 | TASK [bindep : Define bindep_file fact] 2025-10-08 05:37:26.488967 | controller | ok 2025-10-08 05:37:26.496851 | 2025-10-08 05:37:26.496945 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 05:37:26.522775 | controller | skipping: Conditional result was False 2025-10-08 05:37:26.531735 | 2025-10-08 05:37:26.531838 | TASK [bindep : Define bindep_file fact] 2025-10-08 05:37:26.568171 | controller | skipping: Conditional result was False 2025-10-08 05:37:26.578255 | 2025-10-08 05:37:26.578360 | TASK [bindep : Look for bindep fallback file] 2025-10-08 05:37:26.615632 | controller | skipping: Conditional result was False 2025-10-08 05:37:26.625398 | 2025-10-08 05:37:26.625496 | TASK [bindep : Define bindep_file fact] 2025-10-08 05:37:26.657624 | controller | skipping: Conditional result was False 2025-10-08 05:37:26.667754 | 2025-10-08 05:37:26.667841 | TASK [bindep : Include bindep tasks] 2025-10-08 05:37:26.711406 | controller | ok 2025-10-08 05:37:26.725393 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 05:37:26.734925 | 2025-10-08 05:37:26.734991 | TASK [bindep : Look for bindep command] 2025-10-08 05:37:26.769277 | controller | skipping: Conditional result was False 2025-10-08 05:37:26.775995 | 2025-10-08 05:37:26.776055 | TASK [bindep : Check for system bindep] 2025-10-08 05:37:27.305222 | controller | ok: Runtime: 0:00:00.004756 2025-10-08 05:37:27.310592 | 2025-10-08 05:37:27.310652 | TASK [bindep : Define bindep_command fact] 2025-10-08 05:37:27.344844 | controller | skipping: Conditional result was False 2025-10-08 05:37:27.350923 | 2025-10-08 05:37:27.350986 | TASK [bindep : Include install tasks] 2025-10-08 05:37:27.401610 | controller | ok 2025-10-08 05:37:27.413169 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 05:37:27.432376 | 2025-10-08 05:37:27.432597 | TASK [bindep : Create temp dir for bindep] 2025-10-08 05:37:27.772391 | controller | changed 2025-10-08 05:37:27.783098 | 2025-10-08 05:37:27.783185 | TASK [Ensure we have pip dependencies] 2025-10-08 05:37:27.805601 | controller | ok 2025-10-08 05:37:27.838654 | 2025-10-08 05:37:27.838797 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 01:37:28.107815 | controller | /usr/bin/pip3 2025-10-08 01:37:28.134004 | controller | /usr/bin/python3: No module named wheel 2025-10-08 05:37:28.375708 | controller | ok: Runtime: 0:00:00.036606 2025-10-08 05:37:28.382074 | 2025-10-08 05:37:28.382139 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 05:37:28.408119 | controller | ok: "/var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 05:37:28.425316 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 05:37:28.437489 | 2025-10-08 05:37:28.437566 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 05:37:30.786848 | controller | changed 2025-10-08 05:37:30.795575 | 2025-10-08 05:37:30.795694 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 05:37:30.854885 | controller | skipping: Conditional result was False 2025-10-08 05:37:30.861499 | 2025-10-08 05:37:30.861576 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 05:37:30.937038 | controller | skipping: Conditional result was False 2025-10-08 05:37:30.944345 | 2025-10-08 05:37:30.944440 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 05:37:30.999724 | controller | skipping: Conditional result was False 2025-10-08 05:37:31.007049 | 2025-10-08 05:37:31.007124 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 05:37:31.030925 | controller | skipping: Conditional result was False 2025-10-08 05:37:31.038640 | 2025-10-08 05:37:31.038733 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 05:37:31.591109 | controller | skipping: Conditional result was False 2025-10-08 05:37:31.597773 | 2025-10-08 05:37:31.597870 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 05:37:31.633165 | controller | skipping: Conditional result was False 2025-10-08 05:37:31.641115 | 2025-10-08 05:37:31.641187 | TASK [ensure-pip : Install pip from source] 2025-10-08 05:37:31.683205 | controller | skipping: Conditional result was False 2025-10-08 05:37:31.689055 | 2025-10-08 05:37:31.689155 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 01:37:31.979735 | controller | /usr/bin/python3 2025-10-08 05:37:32.239131 | controller | ok: Runtime: 0:00:00.005533 2025-10-08 05:37:32.245118 | 2025-10-08 05:37:32.245189 | TASK [ensure-pip : Set host default] 2025-10-08 05:37:32.325817 | controller | ok 2025-10-08 05:37:32.331239 | 2025-10-08 05:37:32.331305 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 05:37:32.405516 | controller | ok 2025-10-08 05:37:32.421531 | 2025-10-08 05:37:32.421638 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 05:37:36.982639 | controller | changed 2025-10-08 05:37:36.995062 | 2025-10-08 05:37:36.995192 | TASK [bindep : Define bindep_command] 2025-10-08 05:37:37.045904 | controller | ok 2025-10-08 05:37:37.053322 | 2025-10-08 05:37:37.053407 | LOOP [bindep : Include package tasks] 2025-10-08 05:37:37.113157 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 05:37:37.113370 | controller | ok: All items complete 2025-10-08 05:37:37.113411 | 2025-10-08 05:37:37.128540 | controller | included: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 05:37:37.138651 | 2025-10-08 05:37:37.138728 | TASK [bindep : Define bindep_run fact] 2025-10-08 05:37:37.167369 | controller | ok 2025-10-08 05:37:37.172297 | 2025-10-08 05:37:37.172357 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 01:37:38.526905 | controller | podman 2025-10-08 01:37:38.573120 | controller | python3-jmespath 2025-10-08 01:37:38.573185 | controller | python3-libvirt 2025-10-08 01:37:38.573193 | controller | python3-lxml 2025-10-08 01:37:38.573200 | controller | python3-netaddr 2025-10-08 05:37:38.703810 | controller | ok: Runtime: 0:00:01.136940 2025-10-08 05:37:38.711564 | 2025-10-08 05:37:38.711649 | TASK [bindep : Install distro packages from bindep] 2025-10-08 05:38:39.708777 | controller | changed 2025-10-08 05:38:39.714267 | 2025-10-08 05:38:39.714332 | TASK [bindep : Check that packages are installed] 2025-10-08 05:38:41.743735 | controller | ok: Runtime: 0:00:01.261784 2025-10-08 05:38:41.756452 | 2025-10-08 05:38:41.756616 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 05:38:41.794319 | controller | skipping: Conditional result was False 2025-10-08 05:38:41.817889 | 2025-10-08 05:38:41.818047 | TASK [Run test-setup role] 2025-10-08 05:38:41.849340 | controller | ok 2025-10-08 05:38:41.873012 | 2025-10-08 05:38:41.873135 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 05:38:42.165281 | controller | ok 2025-10-08 05:38:42.178489 | 2025-10-08 05:38:42.178772 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 05:38:42.727513 | controller | skipping: Conditional result was False 2025-10-08 05:38:42.767515 | 2025-10-08 05:38:42.767636 | TASK [bindep : Remove bindep temp dir] 2025-10-08 05:38:43.170590 | controller | ok 2025-10-08 05:38:43.196450 | 2025-10-08 05:38:43.196625 | PLAY RECAP 2025-10-08 05:38:43.196744 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 05:38:43.196792 | 2025-10-08 05:38:43.321503 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 05:38:43.323958 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 05:38:43.920890 | 2025-10-08 05:38:43.921068 | PLAY [all] 2025-10-08 05:38:43.940070 | 2025-10-08 05:38:43.940147 | TASK [Abort when test_command variable is undefined] 2025-10-08 05:38:43.974577 | controller | skipping: Conditional result was False 2025-10-08 05:38:43.980379 | 2025-10-08 05:38:43.980451 | TASK [Convert test_command to list] 2025-10-08 05:38:44.035181 | controller | skipping: Conditional result was False 2025-10-08 05:38:44.049290 | 2025-10-08 05:38:44.049424 | TASK [Use test_command list] 2025-10-08 05:38:44.118788 | controller | ok 2025-10-08 05:38:44.130006 | 2025-10-08 05:38:44.130130 | LOOP [Run test_command] 2025-10-08 05:38:44.570149 | controller | no check to run 2025-10-08 05:38:44.570586 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008247 2025-10-08 05:38:44.619861 | 2025-10-08 05:38:44.620005 | PLAY RECAP 2025-10-08 05:38:44.620062 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 05:38:44.620092 | 2025-10-08 05:38:44.735992 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 05:38:44.737722 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 05:38:45.396573 | 2025-10-08 05:38:45.396748 | PLAY [all] 2025-10-08 05:38:45.421387 | 2025-10-08 05:38:45.421554 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 05:38:45.913856 | controller | changed: non-zero return code 2025-10-08 05:38:45.920167 | 2025-10-08 05:38:45.920244 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 05:38:45.935529 | controller | skipping: Conditional result was False 2025-10-08 05:38:45.942046 | 2025-10-08 05:38:45.942130 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 05:38:45.963209 | 2025-10-08 05:38:45.963422 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 05:38:45.986013 | 2025-10-08 05:38:45.986181 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 05:38:46.000314 | controller | skipping: Conditional result was False 2025-10-08 05:38:46.006526 | 2025-10-08 05:38:46.006598 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 05:38:46.038554 | 2025-10-08 05:38:46.038780 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 05:38:46.063417 | controller | skipping: Conditional result was False 2025-10-08 05:38:46.069388 | 2025-10-08 05:38:46.069460 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 05:38:46.093434 | controller | skipping: Conditional result was False 2025-10-08 05:38:46.099110 | 2025-10-08 05:38:46.099182 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 05:38:46.123494 | controller | skipping: Conditional result was False 2025-10-08 05:38:46.149072 | 2025-10-08 05:38:46.149215 | PLAY RECAP 2025-10-08 05:38:46.149274 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 05:38:46.149305 | 2025-10-08 05:38:46.257102 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 05:38:46.258058 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 05:38:46.846147 | 2025-10-08 05:38:46.846301 | PLAY [all] 2025-10-08 05:38:46.868004 | 2025-10-08 05:38:46.868120 | TASK [include_role : fetch-output] 2025-10-08 05:38:46.897089 | controller | ok 2025-10-08 05:38:46.914305 | 2025-10-08 05:38:46.914422 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 05:38:46.959350 | controller | skipping: Conditional result was False 2025-10-08 05:38:46.965242 | 2025-10-08 05:38:46.965318 | TASK [fetch-output : Set log path for single node] 2025-10-08 05:38:47.004443 | controller | ok 2025-10-08 05:38:47.009471 | 2025-10-08 05:38:47.009539 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 05:38:47.424649 | controller -> localhost | ok: "/var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/logs" 2025-10-08 05:38:47.627446 | controller -> localhost | changed: "/var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/artifacts" 2025-10-08 05:38:47.838595 | controller -> localhost | changed: "/var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/docs" 2025-10-08 05:38:47.848906 | 2025-10-08 05:38:47.849011 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 05:38:48.521212 | controller | changed: .d..t...... ./ 2025-10-08 05:38:48.521660 | controller | changed: All items complete 2025-10-08 05:38:48.521732 | 2025-10-08 05:38:49.026277 | controller | changed: .d..t...... ./ 2025-10-08 05:38:49.521087 | controller | changed: .d..t...... ./ 2025-10-08 05:38:49.538360 | 2025-10-08 05:38:49.538498 | TASK [include_role : fetch-output-openshift] 2025-10-08 05:38:49.568900 | controller | skipping: Conditional result was False 2025-10-08 05:38:49.575475 | 2025-10-08 05:38:49.575543 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 05:38:49.973710 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007814 2025-10-08 05:38:50.301709 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012419 2025-10-08 05:38:50.335616 | 2025-10-08 05:38:50.335825 | PLAY [all] 2025-10-08 05:38:50.350188 | 2025-10-08 05:38:50.350259 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 05:38:50.827896 | controller | changed 2025-10-08 05:38:50.878073 | 2025-10-08 05:38:50.878198 | PLAY RECAP 2025-10-08 05:38:50.878242 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 05:38:50.878263 | 2025-10-08 05:38:51.014732 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 05:38:51.015533 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 05:38:51.651778 | 2025-10-08 05:38:51.651905 | PLAY [localhost] 2025-10-08 05:38:51.674361 | 2025-10-08 05:38:51.674466 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 05:38:52.164908 | localhost | changed 2025-10-08 05:38:52.169699 | 2025-10-08 05:38:52.169789 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 05:38:52.197598 | localhost | ok 2025-10-08 05:38:52.205821 | 2025-10-08 05:38:52.205896 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 05:38:52.750460 | localhost | changed 2025-10-08 05:38:52.761012 | 2025-10-08 05:38:52.761114 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 05:38:53.405106 | localhost | changed 2025-10-08 05:38:53.410250 | 2025-10-08 05:38:53.410312 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 05:38:53.869591 | localhost | Identity added: /var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/tmp/ansible.ud0z8vpx (/var/lib/zuul/builds/f6f831b641c4403ba5a4cfd290be6986/work/tmp/ansible.ud0z8vpx) 2025-10-08 05:38:53.869811 | localhost | ok: Runtime: 0:00:00.010410 2025-10-08 05:38:53.874469 | 2025-10-08 05:38:53.874539 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 05:38:54.211386 | localhost | ok: Runtime: 0:00:00.020355 2025-10-08 05:38:54.218828 | 2025-10-08 05:38:54.218923 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 05:38:54.348408 | localhost | changed 2025-10-08 05:38:54.353108 | 2025-10-08 05:38:54.353177 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 05:38:54.789747 | localhost | changed 2025-10-08 05:38:54.830252 | 2025-10-08 05:38:54.830345 | PLAY [localhost] 2025-10-08 05:38:54.852789 | 2025-10-08 05:38:54.852885 | TASK [Generate bulk log download script] 2025-10-08 05:38:54.882434 | localhost | ok 2025-10-08 05:38:54.896394 | 2025-10-08 05:38:54.896473 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 05:38:54.944537 | localhost | ok: All assertions passed 2025-10-08 05:38:54.949409 | 2025-10-08 05:38:54.949472 | TASK [local-log-download : Create download script] 2025-10-08 05:38:55.521207 | localhost -> localhost | changed 2025-10-08 05:38:55.530364 | 2025-10-08 05:38:55.530429 | TASK [Register quick-download link] 2025-10-08 05:38:55.560309 | localhost | ok 2025-10-08 05:38:55.667414 | 2025-10-08 05:38:55.667525 | PLAY [logserver.rdoproject.org] 2025-10-08 05:38:55.682089 | 2025-10-08 05:38:55.682207 | TASK [Set zuul-log-path fact] 2025-10-08 05:38:55.708848 | logserver.rdoproject.org | ok 2025-10-08 05:38:55.725102 | 2025-10-08 05:38:55.725220 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 05:38:55.752113 | logserver.rdoproject.org | ok 2025-10-08 05:38:55.757590 | 2025-10-08 05:38:55.757652 | TASK [upload-logs : Create log directories] 2025-10-08 05:38:56.566919 | logserver.rdoproject.org | changed 2025-10-08 05:38:56.572388 | 2025-10-08 05:38:56.572475 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 05:38:56.853263 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005906 2025-10-08 05:38:56.860465 | 2025-10-08 05:38:56.860533 | TASK [upload-logs : Upload logs to log server] 2025-10-08 05:38:57.525800 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 05:38:57.528737 | 2025-10-08 05:38:57.528798 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 05:38:57.621535 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:38:57.623464 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:38:57.629904 | 2025-10-08 05:38:57.630027 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 05:38:57.678246 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:38:57.678506 | 2025-10-08 05:38:57.679054 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 05:38:57.688933 | 2025-10-08 05:38:57.689065 | LOOP [upload-logs : Upload console log and json output]