2025-09-30 05:14:06.453373 | Job console starting...
2025-09-30 05:14:06.462690 | Updating repositories
2025-09-30 05:14:06.493842 | Preparing job workspace
2025-09-30 05:14:10.999926 | Running Ansible setup...
2025-09-30 05:14:14.997938 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 05:14:15.658467 | 
2025-09-30 05:14:15.658595 | PLAY [localhost]
2025-09-30 05:14:15.667286 | 
2025-09-30 05:14:15.667362 | TASK [Gathering Facts]
2025-09-30 05:14:16.586374 | localhost | ok
2025-09-30 05:14:16.623323 | 
2025-09-30 05:14:16.623586 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-09-30 05:14:17.049471 | localhost -> localhost | changed
2025-09-30 05:14:17.060856 | 
2025-09-30 05:14:17.061072 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-09-30 05:14:17.909716 | localhost -> localhost | changed
2025-09-30 05:14:17.917919 | 
2025-09-30 05:14:17.918010 | TASK [Setup log path fact]
2025-09-30 05:14:17.935584 | localhost | ok
2025-09-30 05:14:17.947499 | 
2025-09-30 05:14:17.947568 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 05:14:17.986908 | localhost | ok
2025-09-30 05:14:18.027545 | 
2025-09-30 05:14:18.027699 | TASK [emit-job-header : Print job information]
2025-09-30 05:14:18.075701 | # Job Information
2025-09-30 05:14:18.075869 | Ansible Version: 2.15.12
2025-09-30 05:14:18.075894 | Job: cifmw-molecule-switch_config
2025-09-30 05:14:18.075914 | Pipeline: github-check
2025-09-30 05:14:18.075932 | Executor: ze01.softwarefactory-project.io
2025-09-30 05:14:18.075954 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3333
2025-09-30 05:14:18.075973 | Log URL (when completed): https://logserver.rdoproject.org/d09/rdoproject.org/d09d51739d19495396bda4d4416d81bb/
2025-09-30 05:14:18.075990 | Event ID: 3089cae0-9dba-11f0-9d66-59f03df1d747
2025-09-30 05:14:18.079921 | 
2025-09-30 05:14:18.079984 | LOOP [emit-job-header : Print node information]
2025-09-30 05:14:18.197125 | localhost | ok:
2025-09-30 05:14:18.197389 | localhost | # Node Information
2025-09-30 05:14:18.197419 | localhost | Inventory Hostname: controller
2025-09-30 05:14:18.197445 | localhost | Hostname: np0005461576
2025-09-30 05:14:18.197465 | localhost | Username: zuul
2025-09-30 05:14:18.197486 | localhost | Distro: CentOS 9
2025-09-30 05:14:18.197503 | localhost | Provider: vexxhost-nodepool-tripleo
2025-09-30 05:14:18.197520 | localhost | Region: RegionOne
2025-09-30 05:14:18.197537 | localhost | Label: cloud-centos-9-stream-tripleo
2025-09-30 05:14:18.197553 | localhost | Product Name: OpenStack Nova
2025-09-30 05:14:18.197569 | localhost | Interface IP: 38.102.83.64
2025-09-30 05:14:18.252750 | 
2025-09-30 05:14:18.252930 | PLAY [all]
2025-09-30 05:14:18.262956 | 
2025-09-30 05:14:18.263207 | TASK [Gather network facts]
2025-09-30 05:14:18.777197 | controller | ok
2025-09-30 05:14:18.813335 | 
2025-09-30 05:14:18.813535 | TASK [include_role : start-zuul-console]
2025-09-30 05:14:18.840851 | controller | ok
2025-09-30 05:14:18.858974 | 
2025-09-30 05:14:18.859874 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-09-30 05:14:19.319109 | controller | ok
2025-09-30 05:14:19.338622 | 
2025-09-30 05:14:19.338756 | TASK [include_role : add-build-sshkey]
2025-09-30 05:14:19.375963 | controller | ok
2025-09-30 05:14:19.404039 | 
2025-09-30 05:14:19.404219 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-30 05:14:19.738500 | controller -> localhost | ok
2025-09-30 05:14:19.751922 | 
2025-09-30 05:14:19.752095 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-30 05:14:19.788760 | controller | ok
2025-09-30 05:14:19.815126 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-30 05:14:19.822693 | 
2025-09-30 05:14:19.822774 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-30 05:14:20.766733 | controller -> localhost | Generating public/private rsa key pair.
2025-09-30 05:14:20.767045 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/d09d51739d19495396bda4d4416d81bb_id_rsa.
2025-09-30 05:14:20.767086 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/d09d51739d19495396bda4d4416d81bb_id_rsa.pub.
2025-09-30 05:14:20.767109 | controller -> localhost | The key fingerprint is:
2025-09-30 05:14:20.767129 | controller -> localhost | SHA256:/6FB4jcVQQV4V5Eaf4NMqqCuA9WOAiRSN5YtVxKMkL4 zuul-build-sshkey
2025-09-30 05:14:20.767149 | controller -> localhost | The key's randomart image is:
2025-09-30 05:14:20.767168 | controller -> localhost | +---[RSA 3072]----+
2025-09-30 05:14:20.767186 | controller -> localhost | | .oo+=oo.  o+o.o+|
2025-09-30 05:14:20.767205 | controller -> localhost | |o..o+.+.  . .+.. |
2025-09-30 05:14:20.767222 | controller -> localhost | |+.  .o     .=.=  |
2025-09-30 05:14:20.767240 | controller -> localhost | |. .. . .   . = o.|
2025-09-30 05:14:20.767258 | controller -> localhost | |. ..o . S o .   o|
2025-09-30 05:14:20.767275 | controller -> localhost | | oE. o . = .     |
2025-09-30 05:14:20.767292 | controller -> localhost | |  o .   . = .    |
2025-09-30 05:14:20.767308 | controller -> localhost | |   . .   . = .   |
2025-09-30 05:14:20.767325 | controller -> localhost | |   .o     . .    |
2025-09-30 05:14:20.767342 | controller -> localhost | +----[SHA256]-----+
2025-09-30 05:14:20.767394 | controller -> localhost | ok: Runtime: 0:00:00.409176
2025-09-30 05:14:20.774065 | 
2025-09-30 05:14:20.774155 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-30 05:14:20.796850 | controller | ok
2025-09-30 05:14:20.808034 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-30 05:14:20.818136 | 
2025-09-30 05:14:20.818237 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-30 05:14:20.844160 | controller | skipping: Conditional result was False
2025-09-30 05:14:20.853497 | 
2025-09-30 05:14:20.853620 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-30 05:14:21.412433 | controller | changed
2025-09-30 05:14:21.424231 | 
2025-09-30 05:14:21.424370 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-30 05:14:21.743785 | controller | ok
2025-09-30 05:14:21.751142 | 
2025-09-30 05:14:21.751228 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-30 05:14:22.792856 | controller | changed
2025-09-30 05:14:22.806219 | 
2025-09-30 05:14:22.806470 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-30 05:14:23.807259 | controller | changed
2025-09-30 05:14:23.812637 | 
2025-09-30 05:14:23.812783 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-30 05:14:23.847611 | controller | skipping: Conditional result was False
2025-09-30 05:14:23.854080 | 
2025-09-30 05:14:23.854236 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-30 05:14:24.288698 | controller -> localhost | changed
2025-09-30 05:14:24.310192 | 
2025-09-30 05:14:24.310365 | TASK [add-build-sshkey : Add back temp key]
2025-09-30 05:14:24.623997 | controller -> localhost | Identity added: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/d09d51739d19495396bda4d4416d81bb_id_rsa (zuul-build-sshkey)
2025-09-30 05:14:24.624495 | controller -> localhost | ok: Runtime: 0:00:00.016349
2025-09-30 05:14:24.638532 | 
2025-09-30 05:14:24.638758 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-30 05:14:25.033752 | controller | ok
2025-09-30 05:14:25.044573 | 
2025-09-30 05:14:25.044744 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-30 05:14:25.071606 | controller | skipping: Conditional result was False
2025-09-30 05:14:25.094197 | 
2025-09-30 05:14:25.094392 | TASK [include_role : validate-host]
2025-09-30 05:14:25.122870 | controller | ok
2025-09-30 05:14:25.166671 | 
2025-09-30 05:14:25.166879 | TASK [validate-host : Define zuul_info_dir fact]
2025-09-30 05:14:25.214709 | controller | ok
2025-09-30 05:14:25.223330 | 
2025-09-30 05:14:25.223425 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-09-30 05:14:25.484089 | controller -> localhost | ok
2025-09-30 05:14:25.522240 | 
2025-09-30 05:14:25.522401 | TASK [validate-host : Collect information about the host]
2025-09-30 05:14:26.364472 | controller | ok
2025-09-30 05:14:26.382829 | 
2025-09-30 05:14:26.382993 | TASK [validate-host : Sanitize hostname]
2025-09-30 05:14:26.450010 | controller | ok
2025-09-30 05:14:26.460876 | 
2025-09-30 05:14:26.461098 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-09-30 05:14:26.978893 | controller -> localhost | changed
2025-09-30 05:14:26.991332 | 
2025-09-30 05:14:26.991471 | TASK [validate-host : Collect information about zuul worker]
2025-09-30 05:14:27.489196 | controller | ok
2025-09-30 05:14:27.499268 | 
2025-09-30 05:14:27.499398 | TASK [validate-host : Write out all zuul information for each host]
2025-09-30 05:14:28.067768 | controller -> localhost | changed
2025-09-30 05:14:28.078555 | 
2025-09-30 05:14:28.078706 | TASK [include_role : prepare-workspace-openshift]
2025-09-30 05:14:28.095431 | controller | skipping: Conditional result was False
2025-09-30 05:14:28.107092 | 
2025-09-30 05:14:28.107238 | TASK [include_role : remove-zuul-sshkey]
2025-09-30 05:14:28.134475 | controller | skipping: Conditional result was False
2025-09-30 05:14:28.146913 | 
2025-09-30 05:14:28.147053 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-30 05:14:28.438307 | controller | ok: "logs"
2025-09-30 05:14:28.438735 | controller | ok: All items complete
2025-09-30 05:14:28.438805 | 
2025-09-30 05:14:28.702820 | controller | ok: "artifacts"
2025-09-30 05:14:28.975727 | controller | ok: "docs"
2025-09-30 05:14:28.989884 | 
2025-09-30 05:14:28.990143 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-30 05:14:29.326313 | controller | changed: "logs"
2025-09-30 05:14:29.595732 | controller | changed: "artifacts"
2025-09-30 05:14:29.872371 | controller | changed: "docs"
2025-09-30 05:14:29.922676 | 
2025-09-30 05:14:29.922810 | PLAY RECAP
2025-09-30 05:14:29.922865 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-30 05:14:29.922900 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 05:14:29.922925 | 
2025-09-30 05:14:30.029346 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 05:14:30.030193 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-09-30 05:14:30.617371 | 
2025-09-30 05:14:30.617494 | PLAY [localhost]
2025-09-30 05:14:30.633452 | 
2025-09-30 05:14:30.633546 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-09-30 05:14:31.054625 | localhost | ok
2025-09-30 05:14:31.065720 | 
2025-09-30 05:14:31.065881 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-09-30 05:14:31.816856 | localhost | changed
2025-09-30 05:14:31.858173 | 
2025-09-30 05:14:31.858291 | PLAY [all]
2025-09-30 05:14:31.881128 | 
2025-09-30 05:14:31.881227 | TASK [include_role : prepare-workspace]
2025-09-30 05:14:31.913273 | controller | ok
2025-09-30 05:14:31.933001 | 
2025-09-30 05:14:31.933167 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-09-30 05:14:32.370257 | controller | ok
2025-09-30 05:14:32.379130 | 
2025-09-30 05:14:32.379217 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-09-30 05:14:34.150836 | controller | Output suppressed because no_log was given
2025-09-30 05:14:34.182481 | 
2025-09-30 05:14:34.182774 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-30 05:14:34.488984 | controller | changed: "logs"
2025-09-30 05:14:34.745526 | controller | changed: "artifacts"
2025-09-30 05:14:35.005545 | controller | changed: "docs"
2025-09-30 05:14:35.024500 | 
2025-09-30 05:14:35.024695 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-30 05:14:35.280081 | controller | changed: "logs"
2025-09-30 05:14:35.280318 | controller | changed: All items complete
2025-09-30 05:14:35.280344 | 
2025-09-30 05:14:35.546443 | controller | changed: "artifacts"
2025-09-30 05:14:35.792180 | controller | changed: "docs"
2025-09-30 05:14:35.826744 | 
2025-09-30 05:14:35.827102 | TASK [Check if worker can sudo]
2025-09-30 05:14:36.876457 | controller | ok: Runtime: 0:00:00.058442
2025-09-30 05:14:36.889158 | 
2025-09-30 05:14:36.889356 | TASK [configure-mirrors : Gather needed facts]
2025-09-30 05:14:36.946227 | controller | skipping: Conditional result was False
2025-09-30 05:14:36.958170 | 
2025-09-30 05:14:36.958302 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-09-30 05:14:37.025194 | controller | ok
2025-09-30 05:14:37.040961 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-09-30 05:14:37.080261 | 
2025-09-30 05:14:37.080408 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-09-30 05:14:37.384290 | controller | ok
2025-09-30 05:14:37.389809 | 
2025-09-30 05:14:37.389874 | LOOP [configure-mirrors : Include OS-specific variables]
2025-09-30 05:14:37.453170 | controller | ok: "/var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-09-30 05:14:37.471085 | 
2025-09-30 05:14:37.471272 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-09-30 05:14:38.443390 | controller | changed
2025-09-30 05:14:38.451293 | 
2025-09-30 05:14:38.451420 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-09-30 05:14:38.551600 | controller | ok: "/var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-09-30 05:14:38.551808 | controller | ok: All items complete
2025-09-30 05:14:38.551849 | 
2025-09-30 05:14:38.638828 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-09-30 05:14:38.645945 | 
2025-09-30 05:14:38.646042 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-09-30 05:14:39.715871 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-09-30 05:14:40.643183 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-09-30 05:14:40.663652 | 
2025-09-30 05:14:40.663949 | TASK [configure-mirrors : Disable deltrarpm]
2025-09-30 05:14:41.189852 | controller | changed: section and option added
2025-09-30 05:14:41.229535 | 
2025-09-30 05:14:41.229644 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-09-30 05:14:42.105853 | controller | 29 files removed
2025-09-30 05:14:42.106086 | controller | ok: Item: dnf clean all Runtime: 0:00:00.543303
2025-09-30 05:14:42.106124 | controller | changed: All items complete
2025-09-30 05:14:42.106147 | 
2025-09-30 05:14:52.775775 | 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-09-30 05:14:52.776043 | controller | DNF version: 4.14.0
2025-09-30 05:14:52.776144 | controller | cachedir: /var/cache/dnf
2025-09-30 05:14:52.776218 | controller | Making cache files for all metadata files.
2025-09-30 05:14:52.776281 | controller | baseos: has expired and will be refreshed.
2025-09-30 05:14:52.776340 | controller | appstream: has expired and will be refreshed.
2025-09-30 05:14:52.776409 | controller | crb: has expired and will be refreshed.
2025-09-30 05:14:52.776642 | controller | extras-common: has expired and will be refreshed.
2025-09-30 05:14:52.776714 | controller | repo: downloading from remote: baseos
2025-09-30 05:14:52.776765 | controller | CentOS Stream 9 - BaseOS                         72 MB/s | 8.8 MB     00:00
2025-09-30 05:14:52.776816 | controller | baseos: using metadata from Mon 22 Sep 2025 10:29:43 AM EDT.
2025-09-30 05:14:52.776869 | controller | repo: downloading from remote: appstream
2025-09-30 05:14:52.776919 | controller | CentOS Stream 9 - AppStream                      85 MB/s |  25 MB     00:00
2025-09-30 05:14:52.776972 | controller | appstream: using metadata from Mon 22 Sep 2025 10:33:24 AM EDT.
2025-09-30 05:14:52.777082 | controller | repo: downloading from remote: crb
2025-09-30 05:14:52.777147 | controller | CentOS Stream 9 - CRB                            81 MB/s | 7.1 MB     00:00
2025-09-30 05:14:52.777204 | controller | crb: using metadata from Mon 22 Sep 2025 10:37:51 AM EDT.
2025-09-30 05:14:52.777259 | controller | repo: downloading from remote: extras-common
2025-09-30 05:14:52.777314 | controller | CentOS Stream 9 - Extras packages               1.5 MB/s |  20 kB     00:00
2025-09-30 05:14:52.777370 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-09-30 05:14:52.777427 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-09-30 05:14:52.777481 | controller | Completion plugin: Generating completion cache...
2025-09-30 05:14:52.777533 | controller | Metadata cache created.
2025-09-30 05:14:52.777608 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.395439
2025-09-30 05:14:52.810507 | 
2025-09-30 05:14:52.810681 | PLAY RECAP
2025-09-30 05:14:52.810767 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-30 05:14:52.810820 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 05:14:52.810858 | 
2025-09-30 05:14:52.932869 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-09-30 05:14:52.934617 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-09-30 05:14:53.493413 | 
2025-09-30 05:14:53.493526 | PLAY [all]
2025-09-30 05:14:53.514184 | 
2025-09-30 05:14:53.514306 | TASK [Install binary dependencies]
2025-09-30 05:14:53.585644 | controller | ok
2025-09-30 05:14:53.608238 | 
2025-09-30 05:14:53.608375 | TASK [bindep : Include find tasks]
2025-09-30 05:14:53.637005 | controller | ok
2025-09-30 05:14:53.644076 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-09-30 05:14:53.649766 | 
2025-09-30 05:14:53.649827 | TASK [bindep : Look for bindep.txt]
2025-09-30 05:14:54.096127 | controller | ok
2025-09-30 05:14:54.109383 | 
2025-09-30 05:14:54.109562 | TASK [bindep : Define bindep_file fact]
2025-09-30 05:14:54.154595 | controller | ok
2025-09-30 05:14:54.181072 | 
2025-09-30 05:14:54.181238 | TASK [bindep : Look for other-requirements.txt]
2025-09-30 05:14:54.196421 | controller | skipping: Conditional result was False
2025-09-30 05:14:54.204705 | 
2025-09-30 05:14:54.204802 | TASK [bindep : Define bindep_file fact]
2025-09-30 05:14:54.230129 | controller | skipping: Conditional result was False
2025-09-30 05:14:54.238536 | 
2025-09-30 05:14:54.238657 | TASK [bindep : Look for bindep fallback file]
2025-09-30 05:14:54.263569 | controller | skipping: Conditional result was False
2025-09-30 05:14:54.271569 | 
2025-09-30 05:14:54.271685 | TASK [bindep : Define bindep_file fact]
2025-09-30 05:14:54.296707 | controller | skipping: Conditional result was False
2025-09-30 05:14:54.304844 | 
2025-09-30 05:14:54.304945 | TASK [bindep : Include bindep tasks]
2025-09-30 05:14:54.338271 | controller | ok
2025-09-30 05:14:54.350058 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-09-30 05:14:54.361037 | 
2025-09-30 05:14:54.361124 | TASK [bindep : Look for bindep command]
2025-09-30 05:14:54.386331 | controller | skipping: Conditional result was False
2025-09-30 05:14:54.394882 | 
2025-09-30 05:14:54.395081 | TASK [bindep : Check for system bindep]
2025-09-30 05:14:54.933733 | controller | ok: Runtime: 0:00:00.009376
2025-09-30 05:14:54.945852 | 
2025-09-30 05:14:54.945996 | TASK [bindep : Define bindep_command fact]
2025-09-30 05:14:54.974873 | controller | skipping: Conditional result was False
2025-09-30 05:14:54.983141 | 
2025-09-30 05:14:54.983229 | TASK [bindep : Include install tasks]
2025-09-30 05:14:55.025032 | controller | ok
2025-09-30 05:14:55.037143 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-09-30 05:14:55.049429 | 
2025-09-30 05:14:55.049512 | TASK [bindep : Create temp dir for bindep]
2025-09-30 05:14:55.443950 | controller | changed
2025-09-30 05:14:55.455608 | 
2025-09-30 05:14:55.455777 | TASK [Ensure we have pip dependencies]
2025-09-30 05:14:55.480268 | controller | ok
2025-09-30 05:14:55.511831 | 
2025-09-30 05:14:55.511969 | TASK [ensure-pip : Check if pip is installed]
2025-09-30 01:14:55.851151 | controller | /usr/bin/pip3
2025-09-30 01:14:55.893425 | controller | /usr/bin/python3: No module named wheel
2025-09-30 05:14:56.045773 | controller | ok: Runtime: 0:00:00.058417
2025-09-30 05:14:56.057779 | 
2025-09-30 05:14:56.057938 | LOOP [ensure-pip : Install pip from packages]
2025-09-30 05:14:56.114895 | controller | ok: "/var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-09-30 05:14:56.136372 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-09-30 05:14:56.158163 | 
2025-09-30 05:14:56.158331 | TASK [ensure-pip : Install Python 3 pip]
2025-09-30 05:14:58.660567 | controller | changed
2025-09-30 05:14:58.682219 | 
2025-09-30 05:14:58.682421 | TASK [ensure-pip : Check for EPEL repository]
2025-09-30 05:14:58.748756 | controller | skipping: Conditional result was False
2025-09-30 05:14:58.762234 | 
2025-09-30 05:14:58.762411 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-09-30 05:14:58.821035 | controller | skipping: Conditional result was False
2025-09-30 05:14:58.833935 | 
2025-09-30 05:14:58.834146 | TASK [ensure-pip : Install Python 2 pip]
2025-09-30 05:14:58.892852 | controller | skipping: Conditional result was False
2025-09-30 05:14:58.908353 | 
2025-09-30 05:14:58.908581 | TASK [ensure-pip : Ensure setuptools]
2025-09-30 05:14:58.927156 | controller | skipping: Conditional result was False
2025-09-30 05:14:58.937112 | 
2025-09-30 05:14:58.937261 | TASK [ensure-pip : Check for ensurepip module]
2025-09-30 05:14:59.479522 | controller | skipping: Conditional result was False
2025-09-30 05:14:59.488603 | 
2025-09-30 05:14:59.488713 | TASK [ensure-pip : Ensure python3-venv]
2025-09-30 05:14:59.513886 | controller | skipping: Conditional result was False
2025-09-30 05:14:59.522309 | 
2025-09-30 05:14:59.522451 | TASK [ensure-pip : Install pip from source]
2025-09-30 05:14:59.548174 | controller | skipping: Conditional result was False
2025-09-30 05:14:59.556430 | 
2025-09-30 05:14:59.556524 | TASK [ensure-pip : Probe for venv python full path]
2025-09-30 01:14:59.890687 | controller | /usr/bin/python3
2025-09-30 05:15:00.094377 | controller | ok: Runtime: 0:00:00.009463
2025-09-30 05:15:00.105090 | 
2025-09-30 05:15:00.105249 | TASK [ensure-pip : Set host default]
2025-09-30 05:15:00.182962 | controller | ok
2025-09-30 05:15:00.195391 | 
2025-09-30 05:15:00.195637 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-09-30 05:15:00.278680 | controller | ok
2025-09-30 05:15:00.302558 | 
2025-09-30 05:15:00.302707 | TASK [bindep : Install bindep into temporary venv]
2025-09-30 05:15:04.502373 | controller | changed
2025-09-30 05:15:04.515643 | 
2025-09-30 05:15:04.515804 | TASK [bindep : Define bindep_command]
2025-09-30 05:15:04.555515 | controller | ok
2025-09-30 05:15:04.572198 | 
2025-09-30 05:15:04.572408 | LOOP [bindep : Include package tasks]
2025-09-30 05:15:04.633649 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-09-30 05:15:04.633830 | controller | ok: All items complete
2025-09-30 05:15:04.633864 | 
2025-09-30 05:15:04.645478 | controller | included: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-09-30 05:15:04.660594 | 
2025-09-30 05:15:04.660675 | TASK [bindep : Define bindep_run fact]
2025-09-30 05:15:04.693217 | controller | ok
2025-09-30 05:15:04.700204 | 
2025-09-30 05:15:04.700290 | TASK [bindep : Get list of packages to install from bindep]
2025-09-30 01:15:06.247848 | controller | podman
2025-09-30 01:15:06.300229 | controller | python3-jmespath
2025-09-30 01:15:06.300297 | controller | python3-libvirt
2025-09-30 01:15:06.300313 | controller | python3-lxml
2025-09-30 01:15:06.300328 | controller | python3-netaddr
2025-09-30 05:15:06.743686 | controller | ok: Runtime: 0:00:01.289749
2025-09-30 05:15:06.759250 | 
2025-09-30 05:15:06.759454 | TASK [bindep : Install distro packages from bindep]
2025-09-30 05:16:10.131270 | controller | changed
2025-09-30 05:16:10.142751 | 
2025-09-30 05:16:10.143092 | TASK [bindep : Check that packages are installed]
2025-09-30 05:16:11.692451 | controller | ok: Runtime: 0:00:01.232741
2025-09-30 05:16:11.704117 | 
2025-09-30 05:16:11.704246 | TASK [bindep : Fail if we cannot install all packages]
2025-09-30 05:16:11.731491 | controller | skipping: Conditional result was False
2025-09-30 05:16:11.752822 | 
2025-09-30 05:16:11.752972 | TASK [Run test-setup role]
2025-09-30 05:16:11.779517 | controller | ok
2025-09-30 05:16:11.808590 | 
2025-09-30 05:16:11.808708 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-09-30 05:16:12.084398 | controller | ok
2025-09-30 05:16:12.089439 | 
2025-09-30 05:16:12.089523 | TASK [test-setup : Run tools/test-setup.sh]
2025-09-30 05:16:12.628277 | controller | skipping: Conditional result was False
2025-09-30 05:16:12.673515 | 
2025-09-30 05:16:12.673720 | TASK [bindep : Remove bindep temp dir]
2025-09-30 05:16:13.044129 | controller | ok
2025-09-30 05:16:13.058568 | 
2025-09-30 05:16:13.058658 | PLAY RECAP
2025-09-30 05:16:13.058715 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-09-30 05:16:13.058747 | 
2025-09-30 05:16:13.174983 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-09-30 05:16:13.175971 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-09-30 05:16:13.759691 | 
2025-09-30 05:16:13.759804 | PLAY [all]
2025-09-30 05:16:13.779071 | 
2025-09-30 05:16:13.779143 | TASK [Abort when test_command variable is undefined]
2025-09-30 05:16:13.813407 | controller | skipping: Conditional result was False
2025-09-30 05:16:13.818898 | 
2025-09-30 05:16:13.818971 | TASK [Convert test_command to list]
2025-09-30 05:16:13.883285 | controller | skipping: Conditional result was False
2025-09-30 05:16:13.889409 | 
2025-09-30 05:16:13.889473 | TASK [Use test_command list]
2025-09-30 05:16:13.948197 | controller | ok
2025-09-30 05:16:13.953330 | 
2025-09-30 05:16:13.953387 | LOOP [Run test_command]
2025-09-30 05:16:14.408984 | controller | no check to run
2025-09-30 05:16:14.409364 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007518
2025-09-30 05:16:14.458979 | 
2025-09-30 05:16:14.459165 | PLAY RECAP
2025-09-30 05:16:14.459248 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-30 05:16:14.459293 | 
2025-09-30 05:16:14.562109 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-09-30 05:16:14.563360 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-09-30 05:16:15.102319 | 
2025-09-30 05:16:15.102424 | PLAY [all]
2025-09-30 05:16:15.122293 | 
2025-09-30 05:16:15.122373 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-09-30 05:16:15.527308 | controller | changed: non-zero return code
2025-09-30 05:16:15.539399 | 
2025-09-30 05:16:15.539561 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-09-30 05:16:15.558419 | controller | skipping: Conditional result was False
2025-09-30 05:16:15.571880 | 
2025-09-30 05:16:15.572058 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-09-30 05:16:15.612615 | 
2025-09-30 05:16:15.612911 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-09-30 05:16:15.652571 | 
2025-09-30 05:16:15.652808 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-09-30 05:16:15.671101 | controller | skipping: Conditional result was False
2025-09-30 05:16:15.685591 | 
2025-09-30 05:16:15.685748 | LOOP [fetch-subunit-output : Generate subunit file]
2025-09-30 05:16:15.728932 | 
2025-09-30 05:16:15.729220 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-09-30 05:16:15.747161 | controller | skipping: Conditional result was False
2025-09-30 05:16:15.760375 | 
2025-09-30 05:16:15.760551 | TASK [fetch-subunit-output : Remove the temporary file]
2025-09-30 05:16:15.787277 | controller | skipping: Conditional result was False
2025-09-30 05:16:15.799661 | 
2025-09-30 05:16:15.799794 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-09-30 05:16:15.827094 | controller | skipping: Conditional result was False
2025-09-30 05:16:15.874433 | 
2025-09-30 05:16:15.874562 | PLAY RECAP
2025-09-30 05:16:15.874617 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-09-30 05:16:15.874645 | 
2025-09-30 05:16:15.968696 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-09-30 05:16:15.969750 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 05:16:16.549229 | 
2025-09-30 05:16:16.549346 | PLAY [all]
2025-09-30 05:16:16.567982 | 
2025-09-30 05:16:16.568074 | TASK [include_role : fetch-output]
2025-09-30 05:16:16.619299 | controller | ok
2025-09-30 05:16:16.638931 | 
2025-09-30 05:16:16.639088 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-30 05:16:16.713731 | controller | skipping: Conditional result was False
2025-09-30 05:16:16.722658 | 
2025-09-30 05:16:16.722752 | TASK [fetch-output : Set log path for single node]
2025-09-30 05:16:16.768337 | controller | ok
2025-09-30 05:16:16.779987 | 
2025-09-30 05:16:16.780158 | LOOP [fetch-output : Ensure local output dirs]
2025-09-30 05:16:17.228840 | controller -> localhost | ok: "/var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/logs"
2025-09-30 05:16:17.498894 | controller -> localhost | changed: "/var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/artifacts"
2025-09-30 05:16:17.780550 | controller -> localhost | changed: "/var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/docs"
2025-09-30 05:16:17.800992 | 
2025-09-30 05:16:17.801197 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-30 05:16:18.529095 | controller | changed: .d..t...... ./
2025-09-30 05:16:18.529393 | controller | changed: All items complete
2025-09-30 05:16:18.529444 | 
2025-09-30 05:16:19.067554 | controller | changed: .d..t...... ./
2025-09-30 05:16:19.610621 | controller | changed: .d..t...... ./
2025-09-30 05:16:19.629283 | 
2025-09-30 05:16:19.629394 | TASK [include_role : fetch-output-openshift]
2025-09-30 05:16:19.643360 | controller | skipping: Conditional result was False
2025-09-30 05:16:19.649589 | 
2025-09-30 05:16:19.649657 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-09-30 05:16:20.041095 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012937
2025-09-30 05:16:20.286845 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007950
2025-09-30 05:16:20.319306 | 
2025-09-30 05:16:20.319440 | PLAY [all]
2025-09-30 05:16:20.334127 | 
2025-09-30 05:16:20.334230 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-09-30 05:16:20.829280 | controller | changed
2025-09-30 05:16:20.874456 | 
2025-09-30 05:16:20.874569 | PLAY RECAP
2025-09-30 05:16:20.874626 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-30 05:16:20.874654 | 
2025-09-30 05:16:20.972595 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 05:16:20.974310 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-09-30 05:16:21.618441 | 
2025-09-30 05:16:21.618573 | PLAY [localhost]
2025-09-30 05:16:21.637454 | 
2025-09-30 05:16:21.637600 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-09-30 05:16:22.063981 | localhost | changed
2025-09-30 05:16:22.068576 | 
2025-09-30 05:16:22.068655 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-09-30 05:16:22.101755 | localhost | ok
2025-09-30 05:16:22.119598 | 
2025-09-30 05:16:22.119778 | TASK [add-fileserver : Create SSH private key tempfile]
2025-09-30 05:16:22.592609 | localhost | changed
2025-09-30 05:16:22.603923 | 
2025-09-30 05:16:22.604095 | TASK [add-fileserver : Create SSH private key from secret]
2025-09-30 05:16:23.274758 | localhost | changed
2025-09-30 05:16:23.279873 | 
2025-09-30 05:16:23.279939 | TASK [add-fileserver : Add fileserver ssh key]
2025-09-30 05:16:23.699321 | localhost | Identity added: /var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/tmp/ansible.9710gq8w (/var/lib/zuul/builds/d09d51739d19495396bda4d4416d81bb/work/tmp/ansible.9710gq8w)
2025-09-30 05:16:23.699687 | localhost | ok: Runtime: 0:00:00.009689
2025-09-30 05:16:23.709263 | 
2025-09-30 05:16:23.709406 | TASK [add-fileserver : Remove SSH private key from disk]
2025-09-30 05:16:24.041130 | localhost | ok: Runtime: 0:00:00.008656
2025-09-30 05:16:24.051723 | 
2025-09-30 05:16:24.051865 | TASK [add-fileserver : Add fileserver to inventory]
2025-09-30 05:16:24.140398 | localhost | changed
2025-09-30 05:16:24.149911 | 
2025-09-30 05:16:24.150119 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-09-30 05:16:24.614886 | localhost | changed
2025-09-30 05:16:24.656894 | 
2025-09-30 05:16:24.656971 | PLAY [localhost]
2025-09-30 05:16:24.673323 | 
2025-09-30 05:16:24.673406 | TASK [Generate bulk log download script]
2025-09-30 05:16:24.693069 | localhost | ok
2025-09-30 05:16:24.708431 | 
2025-09-30 05:16:24.708542 | TASK [local-log-download : Check API endpoint is defined]
2025-09-30 05:16:24.758254 | localhost | ok: All assertions passed
2025-09-30 05:16:24.764202 | 
2025-09-30 05:16:24.764285 | TASK [local-log-download : Create download script]
2025-09-30 05:16:25.206495 | localhost -> localhost | changed
2025-09-30 05:16:25.226512 | 
2025-09-30 05:16:25.226642 | TASK [Register quick-download link]
2025-09-30 05:16:25.252201 | localhost | ok
2025-09-30 05:16:25.311274 | 
2025-09-30 05:16:25.311390 | PLAY [logserver.rdoproject.org]
2025-09-30 05:16:25.325152 | 
2025-09-30 05:16:25.325231 | TASK [Set zuul-log-path fact]
2025-09-30 05:16:25.343289 | logserver.rdoproject.org | ok
2025-09-30 05:16:25.354809 | 
2025-09-30 05:16:25.354894 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 05:16:25.391875 | logserver.rdoproject.org | ok
2025-09-30 05:16:25.397004 | 
2025-09-30 05:16:25.397101 | TASK [upload-logs : Create log directories]
2025-09-30 05:16:26.242556 | logserver.rdoproject.org | changed
2025-09-30 05:16:26.249705 | 
2025-09-30 05:16:26.249840 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-09-30 05:16:26.583403 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008981
2025-09-30 05:16:26.592907 | 
2025-09-30 05:16:26.593101 | TASK [upload-logs : Upload logs to log server]
2025-09-30 05:16:27.338443 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-09-30 05:16:27.344661 | 
2025-09-30 05:16:27.344797 | LOOP [upload-logs : Compress console log and json output]
2025-09-30 05:16:27.416716 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:16:27.429258 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:16:27.440123 | 
2025-09-30 05:16:27.440318 | LOOP [upload-logs : Upload compressed console log and json output]
2025-09-30 05:16:27.492967 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:16:27.493311 | 
2025-09-30 05:16:27.496430 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:16:27.507245 | 
2025-09-30 05:16:27.507455 | LOOP [upload-logs : Upload console log and json output]