2025-10-03 14:29:33.607836 | Job console starting...
2025-10-03 14:29:33.621644 | Updating repositories
2025-10-03 14:29:33.648560 | Preparing job workspace
2025-10-03 14:29:37.249530 | Running Ansible setup...
2025-10-03 14:29:46.213751 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 14:29:46.817425 | 
2025-10-03 14:29:46.817657 | PLAY [localhost]
2025-10-03 14:29:46.826519 | 
2025-10-03 14:29:46.826595 | TASK [Gathering Facts]
2025-10-03 14:29:47.811628 | localhost | ok
2025-10-03 14:29:47.830658 | 
2025-10-03 14:29:47.830768 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 14:29:48.329312 | localhost -> localhost | changed
2025-10-03 14:29:48.335516 | 
2025-10-03 14:29:48.335589 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 14:29:49.116655 | localhost -> localhost | changed
2025-10-03 14:29:49.153202 | 
2025-10-03 14:29:49.153378 | TASK [Setup log path fact]
2025-10-03 14:29:49.170790 | localhost | ok
2025-10-03 14:29:49.182231 | 
2025-10-03 14:29:49.182300 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 14:29:49.208936 | localhost | ok
2025-10-03 14:29:49.216489 | 
2025-10-03 14:29:49.216552 | TASK [emit-job-header : Print job information]
2025-10-03 14:29:49.254449 | # Job Information
2025-10-03 14:29:49.254628 | Ansible Version: 2.15.12
2025-10-03 14:29:49.254656 | Job: cifmw-molecule-openshift_adm
2025-10-03 14:29:49.254695 | Pipeline: github-check
2025-10-03 14:29:49.254718 | Executor: ze04.softwarefactory-project.io
2025-10-03 14:29:49.254737 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366
2025-10-03 14:29:49.254756 | Log URL (when completed): https://logserver.rdoproject.org/213/rdoproject.org/213f65ced9b445188cc06681d53253eb/
2025-10-03 14:29:49.254774 | Event ID: 2534be40-a065-11f0-8cb8-613a1bcbea70
2025-10-03 14:29:49.258771 | 
2025-10-03 14:29:49.258839 | LOOP [emit-job-header : Print node information]
2025-10-03 14:29:49.381720 | localhost | ok:
2025-10-03 14:29:49.381900 | localhost | # Node Information
2025-10-03 14:29:49.381930 | localhost | Inventory Hostname: controller
2025-10-03 14:29:49.381956 | localhost | Hostname: np0005469674
2025-10-03 14:29:49.381978 | localhost | Username: zuul
2025-10-03 14:29:49.382002 | localhost | Distro: CentOS 9
2025-10-03 14:29:49.382110 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-03 14:29:49.382135 | localhost | Region: RegionOne
2025-10-03 14:29:49.382156 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-03 14:29:49.382177 | localhost | Product Name: OpenStack Nova
2025-10-03 14:29:49.382200 | localhost | Interface IP: 38.102.83.200
2025-10-03 14:29:49.406828 | 
2025-10-03 14:29:49.406934 | PLAY [all]
2025-10-03 14:29:49.413421 | 
2025-10-03 14:29:49.413490 | TASK [Gather network facts]
2025-10-03 14:29:49.926884 | controller | ok
2025-10-03 14:29:49.948573 | 
2025-10-03 14:29:49.948714 | TASK [include_role : start-zuul-console]
2025-10-03 14:29:49.968876 | controller | ok
2025-10-03 14:29:49.981709 | 
2025-10-03 14:29:49.981779 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 14:29:50.417830 | controller | ok
2025-10-03 14:29:50.429821 | 
2025-10-03 14:29:50.429906 | TASK [include_role : add-build-sshkey]
2025-10-03 14:29:50.450705 | controller | ok
2025-10-03 14:29:50.468528 | 
2025-10-03 14:29:50.468593 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 14:29:50.757131 | controller -> localhost | ok
2025-10-03 14:29:50.762866 | 
2025-10-03 14:29:50.762935 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 14:29:50.795654 | controller | ok
2025-10-03 14:29:50.816244 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 14:29:50.822564 | 
2025-10-03 14:29:50.822631 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 14:29:51.509074 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 14:29:51.509266 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/213f65ced9b445188cc06681d53253eb_id_rsa.
2025-10-03 14:29:51.509310 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/213f65ced9b445188cc06681d53253eb_id_rsa.pub.
2025-10-03 14:29:51.509334 | controller -> localhost | The key fingerprint is:
2025-10-03 14:29:51.509355 | controller -> localhost | SHA256:3NQsojX1nEIK3hqVWUiSjqxwkQQEFX4yFVRoWYypP98 zuul-build-sshkey
2025-10-03 14:29:51.509375 | controller -> localhost | The key's randomart image is:
2025-10-03 14:29:51.509394 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 14:29:51.509413 | controller -> localhost | |==+++X=oo=+      |
2025-10-03 14:29:51.509432 | controller -> localhost | | .o.*.o=++ = .   |
2025-10-03 14:29:51.509451 | controller -> localhost | |  +=.oo * + *    |
2025-10-03 14:29:51.509470 | controller -> localhost | |. o+o .* = o     |
2025-10-03 14:29:51.509488 | controller -> localhost | | o o  o S .      |
2025-10-03 14:29:51.509506 | controller -> localhost | |  . o            |
2025-10-03 14:29:51.509524 | controller -> localhost | |     o .         |
2025-10-03 14:29:51.509543 | controller -> localhost | |      . E        |
2025-10-03 14:29:51.509561 | controller -> localhost | |                 |
2025-10-03 14:29:51.509578 | controller -> localhost | +----[SHA256]-----+
2025-10-03 14:29:51.509624 | controller -> localhost | ok: Runtime: 0:00:00.247251
2025-10-03 14:29:51.516246 | 
2025-10-03 14:29:51.516330 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 14:29:51.547652 | controller | ok
2025-10-03 14:29:51.557877 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 14:29:51.566425 | 
2025-10-03 14:29:51.566509 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 14:29:51.590944 | controller | skipping: Conditional result was False
2025-10-03 14:29:51.598491 | 
2025-10-03 14:29:51.598603 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 14:29:52.082099 | controller | changed
2025-10-03 14:29:52.087248 | 
2025-10-03 14:29:52.087316 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 14:29:52.775569 | controller | ok
2025-10-03 14:29:52.780922 | 
2025-10-03 14:29:52.780987 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 14:29:53.558395 | controller | changed
2025-10-03 14:29:53.581243 | 
2025-10-03 14:29:53.582071 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 14:29:54.580193 | controller | changed
2025-10-03 14:29:54.585978 | 
2025-10-03 14:29:54.586046 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 14:29:54.620829 | controller | skipping: Conditional result was False
2025-10-03 14:29:54.626692 | 
2025-10-03 14:29:54.626764 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 14:29:55.020010 | controller -> localhost | changed
2025-10-03 14:29:55.031475 | 
2025-10-03 14:29:55.031553 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 14:29:55.300826 | controller -> localhost | Identity added: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/213f65ced9b445188cc06681d53253eb_id_rsa (zuul-build-sshkey)
2025-10-03 14:29:55.301030 | controller -> localhost | ok: Runtime: 0:00:00.018883
2025-10-03 14:29:55.307190 | 
2025-10-03 14:29:55.307263 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 14:29:55.707805 | controller | ok
2025-10-03 14:29:55.716289 | 
2025-10-03 14:29:55.716402 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 14:29:55.741456 | controller | skipping: Conditional result was False
2025-10-03 14:29:55.751135 | 
2025-10-03 14:29:55.751217 | TASK [include_role : validate-host]
2025-10-03 14:29:55.769318 | controller | ok
2025-10-03 14:29:55.794919 | 
2025-10-03 14:29:55.795024 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 14:29:55.826631 | controller | ok
2025-10-03 14:29:55.832103 | 
2025-10-03 14:29:55.832174 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 14:29:56.059309 | controller -> localhost | ok
2025-10-03 14:29:56.068162 | 
2025-10-03 14:29:56.068257 | TASK [validate-host : Collect information about the host]
2025-10-03 14:29:56.870729 | controller | ok
2025-10-03 14:29:56.878952 | 
2025-10-03 14:29:56.879020 | TASK [validate-host : Sanitize hostname]
2025-10-03 14:29:56.928828 | controller | ok
2025-10-03 14:29:56.933767 | 
2025-10-03 14:29:56.933831 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 14:29:57.344059 | controller -> localhost | changed
2025-10-03 14:29:57.349670 | 
2025-10-03 14:29:57.349771 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 14:29:57.807203 | controller | ok
2025-10-03 14:29:57.812015 | 
2025-10-03 14:29:57.812078 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 14:29:58.263119 | controller -> localhost | changed
2025-10-03 14:29:58.277666 | 
2025-10-03 14:29:58.277807 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 14:29:58.294031 | controller | skipping: Conditional result was False
2025-10-03 14:29:58.302005 | 
2025-10-03 14:29:58.302087 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 14:29:58.326551 | controller | skipping: Conditional result was False
2025-10-03 14:29:58.334046 | 
2025-10-03 14:29:58.334134 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 14:29:58.592747 | controller | ok: "logs"
2025-10-03 14:29:58.593468 | controller | ok: All items complete
2025-10-03 14:29:58.593733 | 
2025-10-03 14:29:58.890057 | controller | ok: "artifacts"
2025-10-03 14:29:59.126415 | controller | ok: "docs"
2025-10-03 14:29:59.148116 | 
2025-10-03 14:29:59.148327 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 14:29:59.497424 | controller | changed: "logs"
2025-10-03 14:29:59.741470 | controller | changed: "artifacts"
2025-10-03 14:30:00.047718 | controller | changed: "docs"
2025-10-03 14:30:00.128943 | 
2025-10-03 14:30:00.129080 | PLAY RECAP
2025-10-03 14:30:00.129173 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 14:30:00.129233 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 14:30:00.129276 | 
2025-10-03 14:30:00.280197 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 14:30:00.281465 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 14:30:00.869482 | 
2025-10-03 14:30:00.869590 | PLAY [localhost]
2025-10-03 14:30:00.887117 | 
2025-10-03 14:30:00.887200 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-03 14:30:01.309537 | localhost | ok
2025-10-03 14:30:01.314827 | 
2025-10-03 14:30:01.314909 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-03 14:30:02.006504 | localhost | changed
2025-10-03 14:30:02.036900 | 
2025-10-03 14:30:02.037176 | PLAY [all]
2025-10-03 14:30:02.060457 | 
2025-10-03 14:30:02.060557 | TASK [include_role : prepare-workspace]
2025-10-03 14:30:02.090898 | controller | ok
2025-10-03 14:30:02.105603 | 
2025-10-03 14:30:02.105672 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 14:30:02.514559 | controller | ok
2025-10-03 14:30:02.525399 | 
2025-10-03 14:30:02.525492 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 14:30:04.128168 | controller | Output suppressed because no_log was given
2025-10-03 14:30:04.137831 | 
2025-10-03 14:30:04.137895 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 14:30:04.434396 | controller | changed: "logs"
2025-10-03 14:30:04.652478 | controller | changed: "artifacts"
2025-10-03 14:30:04.886116 | controller | changed: "docs"
2025-10-03 14:30:04.895536 | 
2025-10-03 14:30:04.895608 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 14:30:05.176581 | controller | changed: "logs"
2025-10-03 14:30:05.176883 | controller | changed: All items complete
2025-10-03 14:30:05.176914 | 
2025-10-03 14:30:05.385622 | controller | changed: "artifacts"
2025-10-03 14:30:05.597919 | controller | changed: "docs"
2025-10-03 14:30:05.617587 | 
2025-10-03 14:30:05.617855 | TASK [Check if worker can sudo]
2025-10-03 14:30:06.156408 | controller | ok: Runtime: 0:00:00.043368
2025-10-03 14:30:06.170381 | 
2025-10-03 14:30:06.170516 | TASK [configure-mirrors : Gather needed facts]
2025-10-03 14:30:06.255917 | controller | skipping: Conditional result was False
2025-10-03 14:30:06.261741 | 
2025-10-03 14:30:06.261807 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-03 14:30:06.330934 | controller | ok
2025-10-03 14:30:06.341908 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-03 14:30:06.408485 | 
2025-10-03 14:30:06.408884 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-03 14:30:06.711163 | controller | ok
2025-10-03 14:30:06.732081 | 
2025-10-03 14:30:06.732978 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-03 14:30:06.822519 | controller | ok: "/var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-03 14:30:06.829600 | 
2025-10-03 14:30:06.829700 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-03 14:30:07.741660 | controller | changed
2025-10-03 14:30:07.749579 | 
2025-10-03 14:30:07.749644 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-03 14:30:07.824537 | controller | ok: "/var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-03 14:30:07.824771 | controller | ok: All items complete
2025-10-03 14:30:07.824802 | 
2025-10-03 14:30:07.908020 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-03 14:30:07.921705 | 
2025-10-03 14:30:07.921805 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-03 14:30:09.090051 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-03 14:30:10.162824 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-03 14:30:10.172492 | 
2025-10-03 14:30:10.172601 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-03 14:30:10.649930 | controller | changed: section and option added
2025-10-03 14:30:10.669156 | 
2025-10-03 14:30:10.669225 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-03 14:30:11.763966 | controller | 29 files removed
2025-10-03 14:30:11.764187 | controller | ok: Item: dnf clean all Runtime: 0:00:00.762059
2025-10-03 14:30:11.764230 | controller | changed: All items complete
2025-10-03 14:30:11.764250 | 
2025-10-03 14:30:23.450361 | 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-03 14:30:23.450492 | controller | DNF version: 4.14.0
2025-10-03 14:30:23.450518 | controller | cachedir: /var/cache/dnf
2025-10-03 14:30:23.450539 | controller | Making cache files for all metadata files.
2025-10-03 14:30:23.450557 | controller | baseos: has expired and will be refreshed.
2025-10-03 14:30:23.450575 | controller | appstream: has expired and will be refreshed.
2025-10-03 14:30:23.450593 | controller | crb: has expired and will be refreshed.
2025-10-03 14:30:23.450622 | controller | extras-common: has expired and will be refreshed.
2025-10-03 14:30:23.450642 | controller | repo: downloading from remote: baseos
2025-10-03 14:30:23.450660 | controller | CentOS Stream 9 - BaseOS                         40 MB/s | 8.8 MB     00:00
2025-10-03 14:30:23.450698 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-03 14:30:23.450718 | controller | repo: downloading from remote: appstream
2025-10-03 14:30:23.450736 | controller | CentOS Stream 9 - AppStream                      38 MB/s |  25 MB     00:00
2025-10-03 14:30:23.450753 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-03 14:30:23.450769 | controller | repo: downloading from remote: crb
2025-10-03 14:30:23.450786 | controller | CentOS Stream 9 - CRB                            21 MB/s | 7.1 MB     00:00
2025-10-03 14:30:23.450803 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-03 14:30:23.450948 | controller | repo: downloading from remote: extras-common
2025-10-03 14:30:23.450975 | controller | CentOS Stream 9 - Extras packages               709 kB/s |  20 kB     00:00
2025-10-03 14:30:23.450993 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-03 14:30:23.451011 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-03 14:30:23.451028 | controller | Completion plugin: Generating completion cache...
2025-10-03 14:30:23.451046 | controller | Metadata cache created.
2025-10-03 14:30:23.451072 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.396691
2025-10-03 14:30:23.471559 | 
2025-10-03 14:30:23.471658 | PLAY RECAP
2025-10-03 14:30:23.471720 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 14:30:23.471747 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 14:30:23.471765 | 
2025-10-03 14:30:23.573286 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 14:30:23.574143 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 14:30:24.227320 | 
2025-10-03 14:30:24.227429 | PLAY [all]
2025-10-03 14:30:24.249551 | 
2025-10-03 14:30:24.249703 | TASK [Install binary dependencies]
2025-10-03 14:30:24.319878 | controller | ok
2025-10-03 14:30:24.339997 | 
2025-10-03 14:30:24.340179 | TASK [bindep : Include find tasks]
2025-10-03 14:30:24.369371 | controller | ok
2025-10-03 14:30:24.391607 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-03 14:30:24.398195 | 
2025-10-03 14:30:24.398289 | TASK [bindep : Look for bindep.txt]
2025-10-03 14:30:24.820593 | controller | ok
2025-10-03 14:30:24.828207 | 
2025-10-03 14:30:24.828281 | TASK [bindep : Define bindep_file fact]
2025-10-03 14:30:24.867946 | controller | ok
2025-10-03 14:30:24.873205 | 
2025-10-03 14:30:24.873270 | TASK [bindep : Look for other-requirements.txt]
2025-10-03 14:30:24.896877 | controller | skipping: Conditional result was False
2025-10-03 14:30:24.903004 | 
2025-10-03 14:30:24.903100 | TASK [bindep : Define bindep_file fact]
2025-10-03 14:30:24.947149 | controller | skipping: Conditional result was False
2025-10-03 14:30:24.953095 | 
2025-10-03 14:30:24.953164 | TASK [bindep : Look for bindep fallback file]
2025-10-03 14:30:24.976540 | controller | skipping: Conditional result was False
2025-10-03 14:30:24.982214 | 
2025-10-03 14:30:24.982284 | TASK [bindep : Define bindep_file fact]
2025-10-03 14:30:25.006146 | controller | skipping: Conditional result was False
2025-10-03 14:30:25.011998 | 
2025-10-03 14:30:25.012063 | TASK [bindep : Include bindep tasks]
2025-10-03 14:30:25.042574 | controller | ok
2025-10-03 14:30:25.049475 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-03 14:30:25.060145 | 
2025-10-03 14:30:25.060237 | TASK [bindep : Look for bindep command]
2025-10-03 14:30:25.084583 | controller | skipping: Conditional result was False
2025-10-03 14:30:25.091306 | 
2025-10-03 14:30:25.091393 | TASK [bindep : Check for system bindep]
2025-10-03 14:30:25.626624 | controller | ok: Runtime: 0:00:00.007718
2025-10-03 14:30:25.632324 | 
2025-10-03 14:30:25.632404 | TASK [bindep : Define bindep_command fact]
2025-10-03 14:30:25.666494 | controller | skipping: Conditional result was False
2025-10-03 14:30:25.672459 | 
2025-10-03 14:30:25.672539 | TASK [bindep : Include install tasks]
2025-10-03 14:30:25.715374 | controller | ok
2025-10-03 14:30:25.723056 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-03 14:30:25.731818 | 
2025-10-03 14:30:25.731889 | TASK [bindep : Create temp dir for bindep]
2025-10-03 14:30:26.182097 | controller | changed
2025-10-03 14:30:26.189578 | 
2025-10-03 14:30:26.189668 | TASK [Ensure we have pip dependencies]
2025-10-03 14:30:26.211595 | controller | ok
2025-10-03 14:30:26.239644 | 
2025-10-03 14:30:26.239763 | TASK [ensure-pip : Check if pip is installed]
2025-10-03 10:30:26.531401 | controller | /usr/bin/pip3
2025-10-03 10:30:26.581812 | controller | /usr/bin/python3: No module named wheel
2025-10-03 14:30:26.781321 | controller | ok: Runtime: 0:00:00.067536
2025-10-03 14:30:26.795589 | 
2025-10-03 14:30:26.795895 | LOOP [ensure-pip : Install pip from packages]
2025-10-03 14:30:26.854233 | controller | ok: "/var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-03 14:30:26.874930 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-03 14:30:26.890334 | 
2025-10-03 14:30:26.890433 | TASK [ensure-pip : Install Python 3 pip]
2025-10-03 14:30:30.121191 | controller | changed
2025-10-03 14:30:30.139134 | 
2025-10-03 14:30:30.139307 | TASK [ensure-pip : Check for EPEL repository]
2025-10-03 14:30:30.184068 | controller | skipping: Conditional result was False
2025-10-03 14:30:30.190703 | 
2025-10-03 14:30:30.190776 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-03 14:30:30.255084 | controller | skipping: Conditional result was False
2025-10-03 14:30:30.265182 | 
2025-10-03 14:30:30.265311 | TASK [ensure-pip : Install Python 2 pip]
2025-10-03 14:30:30.316749 | controller | skipping: Conditional result was False
2025-10-03 14:30:30.327155 | 
2025-10-03 14:30:30.327263 | TASK [ensure-pip : Ensure setuptools]
2025-10-03 14:30:30.341700 | controller | skipping: Conditional result was False
2025-10-03 14:30:30.348921 | 
2025-10-03 14:30:30.349048 | TASK [ensure-pip : Check for ensurepip module]
2025-10-03 14:30:30.879935 | controller | skipping: Conditional result was False
2025-10-03 14:30:30.885791 | 
2025-10-03 14:30:30.885870 | TASK [ensure-pip : Ensure python3-venv]
2025-10-03 14:30:30.930000 | controller | skipping: Conditional result was False
2025-10-03 14:30:30.937466 | 
2025-10-03 14:30:30.937563 | TASK [ensure-pip : Install pip from source]
2025-10-03 14:30:30.961390 | controller | skipping: Conditional result was False
2025-10-03 14:30:30.969455 | 
2025-10-03 14:30:30.969548 | TASK [ensure-pip : Probe for venv python full path]
2025-10-03 10:30:31.242812 | controller | /usr/bin/python3
2025-10-03 14:30:31.501206 | controller | ok: Runtime: 0:00:00.005566
2025-10-03 14:30:31.512955 | 
2025-10-03 14:30:31.513099 | TASK [ensure-pip : Set host default]
2025-10-03 14:30:31.592211 | controller | ok
2025-10-03 14:30:31.599566 | 
2025-10-03 14:30:31.599661 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-03 14:30:31.654653 | controller | ok
2025-10-03 14:30:31.668793 | 
2025-10-03 14:30:31.668881 | TASK [bindep : Install bindep into temporary venv]
2025-10-03 14:30:36.172760 | controller | changed
2025-10-03 14:30:36.184090 | 
2025-10-03 14:30:36.184292 | TASK [bindep : Define bindep_command]
2025-10-03 14:30:36.231574 | controller | ok
2025-10-03 14:30:36.244191 | 
2025-10-03 14:30:36.244360 | LOOP [bindep : Include package tasks]
2025-10-03 14:30:36.326970 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-03 14:30:36.327192 | controller | ok: All items complete
2025-10-03 14:30:36.327229 | 
2025-10-03 14:30:36.350731 | controller | included: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-03 14:30:36.375587 | 
2025-10-03 14:30:36.375745 | TASK [bindep : Define bindep_run fact]
2025-10-03 14:30:36.428714 | controller | ok
2025-10-03 14:30:36.435907 | 
2025-10-03 14:30:36.435993 | TASK [bindep : Get list of packages to install from bindep]
2025-10-03 10:30:37.809199 | controller | podman
2025-10-03 10:30:37.842042 | controller | python3-jmespath
2025-10-03 10:30:37.842179 | controller | python3-libvirt
2025-10-03 10:30:37.842188 | controller | python3-lxml
2025-10-03 10:30:37.842198 | controller | python3-netaddr
2025-10-03 14:30:37.976836 | controller | ok: Runtime: 0:00:01.151756
2025-10-03 14:30:37.995606 | 
2025-10-03 14:30:37.995802 | TASK [bindep : Install distro packages from bindep]
2025-10-03 14:31:53.748551 | controller | changed
2025-10-03 14:31:53.763350 | 
2025-10-03 14:31:53.763486 | TASK [bindep : Check that packages are installed]
2025-10-03 14:31:55.813146 | controller | ok: Runtime: 0:00:01.403175
2025-10-03 14:31:55.827007 | 
2025-10-03 14:31:55.827158 | TASK [bindep : Fail if we cannot install all packages]
2025-10-03 14:31:55.864222 | controller | skipping: Conditional result was False
2025-10-03 14:31:55.890857 | 
2025-10-03 14:31:55.891804 | TASK [Run test-setup role]
2025-10-03 14:31:55.921326 | controller | ok
2025-10-03 14:31:55.952853 | 
2025-10-03 14:31:55.953013 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-03 14:31:56.244411 | controller | ok
2025-10-03 14:31:56.252751 | 
2025-10-03 14:31:56.252850 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-03 14:31:56.792468 | controller | skipping: Conditional result was False
2025-10-03 14:31:56.837372 | 
2025-10-03 14:31:56.837560 | TASK [bindep : Remove bindep temp dir]
2025-10-03 14:31:57.276279 | controller | ok
2025-10-03 14:31:57.300829 | 
2025-10-03 14:31:57.301015 | PLAY RECAP
2025-10-03 14:31:57.301105 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-03 14:31:57.301151 | 
2025-10-03 14:31:57.435094 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 14:31:57.436104 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 14:31:57.991232 | 
2025-10-03 14:31:57.991360 | PLAY [all]
2025-10-03 14:31:58.011996 | 
2025-10-03 14:31:58.012118 | TASK [Abort when test_command variable is undefined]
2025-10-03 14:31:58.037484 | controller | skipping: Conditional result was False
2025-10-03 14:31:58.043805 | 
2025-10-03 14:31:58.043885 | TASK [Convert test_command to list]
2025-10-03 14:31:58.087852 | controller | skipping: Conditional result was False
2025-10-03 14:31:58.094521 | 
2025-10-03 14:31:58.094608 | TASK [Use test_command list]
2025-10-03 14:31:58.171830 | controller | ok
2025-10-03 14:31:58.185575 | 
2025-10-03 14:31:58.185832 | LOOP [Run test_command]
2025-10-03 14:31:58.620574 | controller | no check to run
2025-10-03 14:31:58.620863 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.010631
2025-10-03 14:31:58.667049 | 
2025-10-03 14:31:58.667213 | PLAY RECAP
2025-10-03 14:31:58.667281 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 14:31:58.667318 | 
2025-10-03 14:31:58.776620 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 14:31:58.777557 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 14:31:59.371121 | 
2025-10-03 14:31:59.371258 | PLAY [all]
2025-10-03 14:31:59.395907 | 
2025-10-03 14:31:59.396016 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-03 14:31:59.750622 | controller | changed: non-zero return code
2025-10-03 14:31:59.756210 | 
2025-10-03 14:31:59.756292 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-03 14:31:59.780730 | controller | skipping: Conditional result was False
2025-10-03 14:31:59.786876 | 
2025-10-03 14:31:59.786956 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-03 14:31:59.818634 | 
2025-10-03 14:31:59.818882 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-03 14:31:59.849491 | 
2025-10-03 14:31:59.849641 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-03 14:31:59.874259 | controller | skipping: Conditional result was False
2025-10-03 14:31:59.880666 | 
2025-10-03 14:31:59.880766 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-03 14:31:59.911480 | 
2025-10-03 14:31:59.911623 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-03 14:31:59.952505 | controller | skipping: Conditional result was False
2025-10-03 14:31:59.965233 | 
2025-10-03 14:31:59.965382 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-03 14:31:59.984081 | controller | skipping: Conditional result was False
2025-10-03 14:31:59.997590 | 
2025-10-03 14:31:59.997758 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-03 14:32:00.016760 | controller | skipping: Conditional result was False
2025-10-03 14:32:00.059117 | 
2025-10-03 14:32:00.059213 | PLAY RECAP
2025-10-03 14:32:00.059277 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-03 14:32:00.059312 | 
2025-10-03 14:32:00.171215 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 14:32:00.173048 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 14:32:00.759200 | 
2025-10-03 14:32:00.759316 | PLAY [all]
2025-10-03 14:32:00.777957 | 
2025-10-03 14:32:00.778032 | TASK [include_role : fetch-output]
2025-10-03 14:32:00.829127 | controller | ok
2025-10-03 14:32:00.853633 | 
2025-10-03 14:32:00.853763 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 14:32:00.930047 | controller | skipping: Conditional result was False
2025-10-03 14:32:00.942393 | 
2025-10-03 14:32:00.942538 | TASK [fetch-output : Set log path for single node]
2025-10-03 14:32:01.011471 | controller | ok
2025-10-03 14:32:01.022749 | 
2025-10-03 14:32:01.022892 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 14:32:01.487081 | controller -> localhost | ok: "/var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/logs"
2025-10-03 14:32:01.751534 | controller -> localhost | changed: "/var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/artifacts"
2025-10-03 14:32:02.026588 | controller -> localhost | changed: "/var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/docs"
2025-10-03 14:32:02.037310 | 
2025-10-03 14:32:02.037463 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 14:32:02.766282 | controller | changed: .d..t...... ./
2025-10-03 14:32:02.766571 | controller | changed: All items complete
2025-10-03 14:32:02.766601 | 
2025-10-03 14:32:03.345915 | controller | changed: .d..t...... ./
2025-10-03 14:32:03.896167 | controller | changed: .d..t...... ./
2025-10-03 14:32:03.931982 | 
2025-10-03 14:32:03.932209 | TASK [include_role : fetch-output-openshift]
2025-10-03 14:32:03.959899 | controller | skipping: Conditional result was False
2025-10-03 14:32:03.973404 | 
2025-10-03 14:32:03.973551 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 14:32:04.518873 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014174
2025-10-03 14:32:04.835515 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.014923
2025-10-03 14:32:04.866417 | 
2025-10-03 14:32:04.866838 | PLAY [all]
2025-10-03 14:32:04.902401 | 
2025-10-03 14:32:04.902610 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 14:32:05.413764 | controller | changed
2025-10-03 14:32:05.459000 | 
2025-10-03 14:32:05.459176 | PLAY RECAP
2025-10-03 14:32:05.459238 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 14:32:05.459269 | 
2025-10-03 14:32:05.627613 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 14:32:05.628968 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 14:32:06.304739 | 
2025-10-03 14:32:06.304851 | PLAY [localhost]
2025-10-03 14:32:06.323259 | 
2025-10-03 14:32:06.323351 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 14:32:06.757733 | localhost | changed
2025-10-03 14:32:06.771750 | 
2025-10-03 14:32:06.772050 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 14:32:06.816023 | localhost | ok
2025-10-03 14:32:06.839171 | 
2025-10-03 14:32:06.839740 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 14:32:07.220801 | localhost | changed
2025-10-03 14:32:07.228511 | 
2025-10-03 14:32:07.228748 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 14:32:07.858782 | localhost | changed
2025-10-03 14:32:07.869072 | 
2025-10-03 14:32:07.869161 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 14:32:08.256960 | localhost | Identity added: /var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/tmp/ansible.2m7icnik (/var/lib/zuul/builds/213f65ced9b445188cc06681d53253eb/work/tmp/ansible.2m7icnik)
2025-10-03 14:32:08.257150 | localhost | ok: Runtime: 0:00:00.010209
2025-10-03 14:32:08.261527 | 
2025-10-03 14:32:08.261595 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 14:32:08.548779 | localhost | ok: Runtime: 0:00:00.007136
2025-10-03 14:32:08.556782 | 
2025-10-03 14:32:08.556878 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 14:32:08.611402 | localhost | changed
2025-10-03 14:32:08.618547 | 
2025-10-03 14:32:08.618650 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 14:32:09.014715 | localhost | changed
2025-10-03 14:32:09.035411 | 
2025-10-03 14:32:09.035479 | PLAY [localhost]
2025-10-03 14:32:09.048965 | 
2025-10-03 14:32:09.049025 | TASK [Generate bulk log download script]
2025-10-03 14:32:09.079044 | localhost | ok
2025-10-03 14:32:09.091567 | 
2025-10-03 14:32:09.091633 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 14:32:09.144185 | localhost | ok: All assertions passed
2025-10-03 14:32:09.149216 | 
2025-10-03 14:32:09.149405 | TASK [local-log-download : Create download script]
2025-10-03 14:32:09.564252 | localhost -> localhost | changed
2025-10-03 14:32:09.577005 | 
2025-10-03 14:32:09.577093 | TASK [Register quick-download link]
2025-10-03 14:32:09.598136 | localhost | ok
2025-10-03 14:32:09.665644 | 
2025-10-03 14:32:09.665756 | PLAY [logserver.rdoproject.org]
2025-10-03 14:32:09.675585 | 
2025-10-03 14:32:09.675644 | TASK [Set zuul-log-path fact]
2025-10-03 14:32:09.691881 | logserver.rdoproject.org | ok
2025-10-03 14:32:09.701427 | 
2025-10-03 14:32:09.701512 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 14:32:09.738604 | logserver.rdoproject.org | ok
2025-10-03 14:32:09.744746 | 
2025-10-03 14:32:09.744832 | TASK [upload-logs : Create log directories]
2025-10-03 14:32:10.641563 | logserver.rdoproject.org | changed
2025-10-03 14:32:10.655143 | 
2025-10-03 14:32:10.655279 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 14:32:11.003149 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007492
2025-10-03 14:32:11.009328 | 
2025-10-03 14:32:11.009583 | TASK [upload-logs : Upload logs to log server]
2025-10-03 14:32:11.647285 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 14:32:11.650288 | 
2025-10-03 14:32:11.650353 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 14:32:11.702757 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 14:32:11.715591 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 14:32:11.731789 | 
2025-10-03 14:32:11.731965 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 14:32:11.781526 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 14:32:11.781789 | 
2025-10-03 14:32:11.787653 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 14:32:11.800354 | 
2025-10-03 14:32:11.800527 | LOOP [upload-logs : Upload console log and json output]