2025-10-13 06:07:23.002740 | Job console starting...
2025-10-13 06:07:23.014945 | Updating repositories
2025-10-13 06:07:23.041424 | Preparing job workspace
2025-10-13 06:07:27.097337 | Running Ansible setup...
2025-10-13 06:07:31.078983 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:07:31.689108 | 
2025-10-13 06:07:31.689220 | PLAY [localhost]
2025-10-13 06:07:31.698383 | 
2025-10-13 06:07:31.698453 | TASK [Gathering Facts]
2025-10-13 06:07:32.646671 | localhost | ok
2025-10-13 06:07:32.680094 | 
2025-10-13 06:07:32.680283 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 06:07:33.093852 | localhost -> localhost | changed
2025-10-13 06:07:33.101439 | 
2025-10-13 06:07:33.101530 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 06:07:33.944360 | localhost -> localhost | changed
2025-10-13 06:07:33.961143 | 
2025-10-13 06:07:33.961307 | TASK [Setup log path fact]
2025-10-13 06:07:33.981538 | localhost | ok
2025-10-13 06:07:33.996987 | 
2025-10-13 06:07:33.997161 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:07:34.027674 | localhost | ok
2025-10-13 06:07:34.037436 | 
2025-10-13 06:07:34.037503 | TASK [emit-job-header : Print job information]
2025-10-13 06:07:34.081885 | # Job Information
2025-10-13 06:07:34.082076 | Ansible Version: 2.15.12
2025-10-13 06:07:34.082104 | Job: cifmw-molecule-cleanup_openstack
2025-10-13 06:07:34.082129 | Pipeline: github-check
2025-10-13 06:07:34.082153 | Executor: ze01.softwarefactory-project.io
2025-10-13 06:07:34.082172 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-13 06:07:34.082191 | Log URL (when completed): https://logserver.rdoproject.org/167/rdoproject.org/16709550f8f541e6a8d9ee03d590dc4b/
2025-10-13 06:07:34.082209 | Event ID: a3968a60-a7fa-11f0-8c52-d08cf4908dcc
2025-10-13 06:07:34.091482 | 
2025-10-13 06:07:34.091627 | LOOP [emit-job-header : Print node information]
2025-10-13 06:07:34.193831 | localhost | ok:
2025-10-13 06:07:34.194093 | localhost | # Node Information
2025-10-13 06:07:34.194126 | localhost | Inventory Hostname: controller
2025-10-13 06:07:34.194151 | localhost | Hostname: np0005482067
2025-10-13 06:07:34.194171 | localhost | Username: zuul
2025-10-13 06:07:34.194193 | localhost | Distro: CentOS 9
2025-10-13 06:07:34.194215 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 06:07:34.194239 | localhost | Region: RegionOne
2025-10-13 06:07:34.194259 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 06:07:34.194276 | localhost | Product Name: OpenStack Nova
2025-10-13 06:07:34.194293 | localhost | Interface IP: 38.102.83.156
2025-10-13 06:07:34.218131 | 
2025-10-13 06:07:34.218260 | PLAY [all]
2025-10-13 06:07:34.224601 | 
2025-10-13 06:07:34.224662 | TASK [Gather network facts]
2025-10-13 06:07:34.716785 | controller | ok
2025-10-13 06:07:34.746859 | 
2025-10-13 06:07:34.746949 | TASK [include_role : start-zuul-console]
2025-10-13 06:07:34.794654 | controller | ok
2025-10-13 06:07:34.846580 | 
2025-10-13 06:07:34.846678 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 06:07:35.381630 | controller | ok
2025-10-13 06:07:35.390382 | 
2025-10-13 06:07:35.390441 | TASK [include_role : add-build-sshkey]
2025-10-13 06:07:35.409536 | controller | ok
2025-10-13 06:07:35.424819 | 
2025-10-13 06:07:35.424886 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 06:07:35.630960 | controller -> localhost | ok
2025-10-13 06:07:35.636731 | 
2025-10-13 06:07:35.636796 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 06:07:35.660849 | controller | ok
2025-10-13 06:07:35.676899 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 06:07:35.682736 | 
2025-10-13 06:07:35.682793 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 06:07:36.324056 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 06:07:36.324247 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/16709550f8f541e6a8d9ee03d590dc4b_id_rsa.
2025-10-13 06:07:36.324277 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/16709550f8f541e6a8d9ee03d590dc4b_id_rsa.pub.
2025-10-13 06:07:36.324299 | controller -> localhost | The key fingerprint is:
2025-10-13 06:07:36.324318 | controller -> localhost | SHA256:BSZ1C9ZMpme1YlFs0OIpOc+7NYlgj8tArR9peUGuphw zuul-build-sshkey
2025-10-13 06:07:36.324336 | controller -> localhost | The key's randomart image is:
2025-10-13 06:07:36.324354 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 06:07:36.324372 | controller -> localhost | |      ..*+*=o    |
2025-10-13 06:07:36.324389 | controller -> localhost | |       + *+++.   |
2025-10-13 06:07:36.324406 | controller -> localhost | |        .oO+.    |
2025-10-13 06:07:36.324423 | controller -> localhost | |       .+Bo.     |
2025-10-13 06:07:36.324440 | controller -> localhost | |      . S=o      |
2025-10-13 06:07:36.324457 | controller -> localhost | |     . o Boo .   |
2025-10-13 06:07:36.324473 | controller -> localhost | |      E O +.+    |
2025-10-13 06:07:36.324490 | controller -> localhost | |     . O +.. .   |
2025-10-13 06:07:36.324507 | controller -> localhost | |      o + ..     |
2025-10-13 06:07:36.324523 | controller -> localhost | +----[SHA256]-----+
2025-10-13 06:07:36.324567 | controller -> localhost | ok: Runtime: 0:00:00.269904
2025-10-13 06:07:36.330116 | 
2025-10-13 06:07:36.330175 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 06:07:36.359358 | controller | ok
2025-10-13 06:07:36.384060 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 06:07:36.396195 | 
2025-10-13 06:07:36.396313 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 06:07:36.420645 | controller | skipping: Conditional result was False
2025-10-13 06:07:36.426268 | 
2025-10-13 06:07:36.426347 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 06:07:36.904161 | controller | changed
2025-10-13 06:07:36.909055 | 
2025-10-13 06:07:36.909117 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 06:07:37.195811 | controller | ok
2025-10-13 06:07:37.203502 | 
2025-10-13 06:07:37.203588 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 06:07:38.112619 | controller | changed
2025-10-13 06:07:38.118076 | 
2025-10-13 06:07:38.118162 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 06:07:39.097928 | controller | changed
2025-10-13 06:07:39.103350 | 
2025-10-13 06:07:39.103408 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 06:07:39.127896 | controller | skipping: Conditional result was False
2025-10-13 06:07:39.135043 | 
2025-10-13 06:07:39.135246 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 06:07:39.534030 | controller -> localhost | changed
2025-10-13 06:07:39.562211 | 
2025-10-13 06:07:39.562334 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 06:07:39.918189 | controller -> localhost | Identity added: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/16709550f8f541e6a8d9ee03d590dc4b_id_rsa (zuul-build-sshkey)
2025-10-13 06:07:39.918440 | controller -> localhost | ok: Runtime: 0:00:00.032275
2025-10-13 06:07:39.924249 | 
2025-10-13 06:07:39.924312 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 06:07:40.348800 | controller | ok
2025-10-13 06:07:40.369156 | 
2025-10-13 06:07:40.369379 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 06:07:40.405942 | controller | skipping: Conditional result was False
2025-10-13 06:07:40.420748 | 
2025-10-13 06:07:40.420885 | TASK [include_role : validate-host]
2025-10-13 06:07:40.451666 | controller | ok
2025-10-13 06:07:40.479519 | 
2025-10-13 06:07:40.479668 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 06:07:40.514670 | controller | ok
2025-10-13 06:07:40.523464 | 
2025-10-13 06:07:40.523618 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 06:07:40.774491 | controller -> localhost | ok
2025-10-13 06:07:40.787133 | 
2025-10-13 06:07:40.787271 | TASK [validate-host : Collect information about the host]
2025-10-13 06:07:41.668164 | controller | ok
2025-10-13 06:07:41.677440 | 
2025-10-13 06:07:41.677588 | TASK [validate-host : Sanitize hostname]
2025-10-13 06:07:41.742053 | controller | ok
2025-10-13 06:07:41.749056 | 
2025-10-13 06:07:41.749254 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 06:07:42.281653 | controller -> localhost | changed
2025-10-13 06:07:42.287283 | 
2025-10-13 06:07:42.287345 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 06:07:42.745488 | controller | ok
2025-10-13 06:07:42.756005 | 
2025-10-13 06:07:42.756183 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 06:07:43.196855 | controller -> localhost | changed
2025-10-13 06:07:43.223434 | 
2025-10-13 06:07:43.223605 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 06:07:43.239607 | controller | skipping: Conditional result was False
2025-10-13 06:07:43.247239 | 
2025-10-13 06:07:43.247324 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 06:07:43.294707 | controller | skipping: Conditional result was False
2025-10-13 06:07:43.307479 | 
2025-10-13 06:07:43.307671 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:07:43.624409 | controller | ok: "logs"
2025-10-13 06:07:43.625396 | controller | ok: All items complete
2025-10-13 06:07:43.625434 | 
2025-10-13 06:07:43.875557 | controller | ok: "artifacts"
2025-10-13 06:07:44.105504 | controller | ok: "docs"
2025-10-13 06:07:44.121690 | 
2025-10-13 06:07:44.121839 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:07:44.446454 | controller | changed: "logs"
2025-10-13 06:07:44.733206 | controller | changed: "artifacts"
2025-10-13 06:07:44.974752 | controller | changed: "docs"
2025-10-13 06:07:45.019489 | 
2025-10-13 06:07:45.019611 | PLAY RECAP
2025-10-13 06:07:45.019655 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 06:07:45.019681 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:07:45.019699 | 
2025-10-13 06:07:45.138933 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:07:45.139807 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:07:45.747063 | 
2025-10-13 06:07:45.747179 | PLAY [localhost]
2025-10-13 06:07:45.763046 | 
2025-10-13 06:07:45.763124 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 06:07:46.171214 | localhost | ok
2025-10-13 06:07:46.176230 | 
2025-10-13 06:07:46.176309 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 06:07:46.913723 | localhost | changed
2025-10-13 06:07:46.933536 | 
2025-10-13 06:07:46.933614 | PLAY [all]
2025-10-13 06:07:46.948702 | 
2025-10-13 06:07:46.948788 | TASK [include_role : prepare-workspace]
2025-10-13 06:07:46.985764 | controller | ok
2025-10-13 06:07:47.019598 | 
2025-10-13 06:07:47.019721 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 06:07:47.455122 | controller | ok
2025-10-13 06:07:47.464748 | 
2025-10-13 06:07:47.464907 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 06:07:49.272698 | controller | Output suppressed because no_log was given
2025-10-13 06:07:49.290394 | 
2025-10-13 06:07:49.290482 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:07:49.629623 | controller | changed: "logs"
2025-10-13 06:07:49.887087 | controller | changed: "artifacts"
2025-10-13 06:07:50.122105 | controller | changed: "docs"
2025-10-13 06:07:50.146121 | 
2025-10-13 06:07:50.146310 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:07:50.421695 | controller | changed: "logs"
2025-10-13 06:07:50.421934 | controller | changed: All items complete
2025-10-13 06:07:50.421964 | 
2025-10-13 06:07:50.716238 | controller | changed: "artifacts"
2025-10-13 06:07:50.954615 | controller | changed: "docs"
2025-10-13 06:07:50.973857 | 
2025-10-13 06:07:50.973974 | TASK [Check if worker can sudo]
2025-10-13 06:07:51.516448 | controller | ok: Runtime: 0:00:00.048894
2025-10-13 06:07:51.523564 | 
2025-10-13 06:07:51.523651 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 06:07:51.592800 | controller | skipping: Conditional result was False
2025-10-13 06:07:51.601278 | 
2025-10-13 06:07:51.601397 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 06:07:51.673507 | controller | ok
2025-10-13 06:07:51.683487 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 06:07:51.689817 | 
2025-10-13 06:07:51.689898 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 06:07:52.035700 | controller | ok
2025-10-13 06:07:52.044130 | 
2025-10-13 06:07:52.044249 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 06:07:52.137753 | controller | ok: "/var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 06:07:52.153357 | 
2025-10-13 06:07:52.153515 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 06:07:53.030822 | controller | changed
2025-10-13 06:07:53.042281 | 
2025-10-13 06:07:53.042392 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 06:07:53.132764 | controller | ok: "/var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 06:07:53.132981 | controller | ok: All items complete
2025-10-13 06:07:53.133009 | 
2025-10-13 06:07:53.180711 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 06:07:53.187274 | 
2025-10-13 06:07:53.187339 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 06:07:54.253498 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 06:07:55.114134 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 06:07:55.136185 | 
2025-10-13 06:07:55.136370 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 06:07:55.649165 | controller | changed: section and option added
2025-10-13 06:07:55.678702 | 
2025-10-13 06:07:55.678846 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 06:07:56.457902 | controller | 29 files removed
2025-10-13 06:07:56.458160 | controller | ok: Item: dnf clean all Runtime: 0:00:00.460043
2025-10-13 06:07:56.458203 | controller | changed: All items complete
2025-10-13 06:07:56.458225 | 
2025-10-13 06:08:06.990008 | 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-13 06:08:06.990207 | controller | DNF version: 4.14.0
2025-10-13 06:08:06.990266 | controller | cachedir: /var/cache/dnf
2025-10-13 06:08:06.990312 | controller | Making cache files for all metadata files.
2025-10-13 06:08:06.990357 | controller | baseos: has expired and will be refreshed.
2025-10-13 06:08:06.990398 | controller | appstream: has expired and will be refreshed.
2025-10-13 06:08:06.990437 | controller | crb: has expired and will be refreshed.
2025-10-13 06:08:06.990496 | controller | extras-common: has expired and will be refreshed.
2025-10-13 06:08:06.990536 | controller | repo: downloading from remote: baseos
2025-10-13 06:08:06.990576 | controller | CentOS Stream 9 - BaseOS                         76 MB/s | 8.8 MB     00:00
2025-10-13 06:08:06.990616 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 06:08:06.990655 | controller | repo: downloading from remote: appstream
2025-10-13 06:08:06.990694 | controller | CentOS Stream 9 - AppStream                     109 MB/s |  25 MB     00:00
2025-10-13 06:08:06.990734 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 06:08:06.990772 | controller | repo: downloading from remote: crb
2025-10-13 06:08:06.990811 | controller | CentOS Stream 9 - CRB                            68 MB/s | 7.2 MB     00:00
2025-10-13 06:08:06.990851 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 06:08:06.990916 | controller | repo: downloading from remote: extras-common
2025-10-13 06:08:06.991011 | controller | CentOS Stream 9 - Extras packages               1.8 MB/s |  20 kB     00:00
2025-10-13 06:08:06.991143 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 06:08:06.991224 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 06:08:06.991271 | controller | Completion plugin: Generating completion cache...
2025-10-13 06:08:06.991313 | controller | Metadata cache created.
2025-10-13 06:08:06.991373 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.252565
2025-10-13 06:08:07.021388 | 
2025-10-13 06:08:07.021540 | PLAY RECAP
2025-10-13 06:08:07.021621 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 06:08:07.021679 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:08:07.021719 | 
2025-10-13 06:08:07.146918 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:08:07.148664 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:08:07.744105 | 
2025-10-13 06:08:07.744232 | PLAY [all]
2025-10-13 06:08:07.764992 | 
2025-10-13 06:08:07.765108 | TASK [Install binary dependencies]
2025-10-13 06:08:07.814500 | controller | ok
2025-10-13 06:08:07.835944 | 
2025-10-13 06:08:07.836087 | TASK [bindep : Include find tasks]
2025-10-13 06:08:07.865052 | controller | ok
2025-10-13 06:08:07.872476 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 06:08:07.878533 | 
2025-10-13 06:08:07.878600 | TASK [bindep : Look for bindep.txt]
2025-10-13 06:08:08.355740 | controller | ok
2025-10-13 06:08:08.362298 | 
2025-10-13 06:08:08.362362 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:08:08.392906 | controller | ok
2025-10-13 06:08:08.398533 | 
2025-10-13 06:08:08.398601 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 06:08:08.443674 | controller | skipping: Conditional result was False
2025-10-13 06:08:08.450123 | 
2025-10-13 06:08:08.450225 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:08:08.474397 | controller | skipping: Conditional result was False
2025-10-13 06:08:08.480598 | 
2025-10-13 06:08:08.480682 | TASK [bindep : Look for bindep fallback file]
2025-10-13 06:08:08.505578 | controller | skipping: Conditional result was False
2025-10-13 06:08:08.512220 | 
2025-10-13 06:08:08.512305 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:08:08.537302 | controller | skipping: Conditional result was False
2025-10-13 06:08:08.543850 | 
2025-10-13 06:08:08.543923 | TASK [bindep : Include bindep tasks]
2025-10-13 06:08:08.586047 | controller | ok
2025-10-13 06:08:08.592888 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 06:08:08.600599 | 
2025-10-13 06:08:08.600660 | TASK [bindep : Look for bindep command]
2025-10-13 06:08:08.645360 | controller | skipping: Conditional result was False
2025-10-13 06:08:08.652241 | 
2025-10-13 06:08:08.652314 | TASK [bindep : Check for system bindep]
2025-10-13 06:08:09.207866 | controller | ok: Runtime: 0:00:00.009238
2025-10-13 06:08:09.213861 | 
2025-10-13 06:08:09.213956 | TASK [bindep : Define bindep_command fact]
2025-10-13 06:08:09.240474 | controller | skipping: Conditional result was False
2025-10-13 06:08:09.247262 | 
2025-10-13 06:08:09.247420 | TASK [bindep : Include install tasks]
2025-10-13 06:08:09.289206 | controller | ok
2025-10-13 06:08:09.296976 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 06:08:09.307050 | 
2025-10-13 06:08:09.307125 | TASK [bindep : Create temp dir for bindep]
2025-10-13 06:08:09.718966 | controller | changed
2025-10-13 06:08:09.726970 | 
2025-10-13 06:08:09.727050 | TASK [Ensure we have pip dependencies]
2025-10-13 06:08:09.745698 | controller | ok
2025-10-13 06:08:09.785883 | 
2025-10-13 06:08:09.786069 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 02:08:10.070397 | controller | /usr/bin/pip3
2025-10-13 02:08:10.113204 | controller | /usr/bin/python3: No module named wheel
2025-10-13 06:08:10.325329 | controller | ok: Runtime: 0:00:00.060140
2025-10-13 06:08:10.337262 | 
2025-10-13 06:08:10.337397 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 06:08:10.393767 | controller | ok: "/var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 06:08:10.419125 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 06:08:10.443460 | 
2025-10-13 06:08:10.443602 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 06:08:12.715170 | controller | changed
2025-10-13 06:08:12.720461 | 
2025-10-13 06:08:12.720521 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 06:08:12.755650 | controller | skipping: Conditional result was False
2025-10-13 06:08:12.762600 | 
2025-10-13 06:08:12.762671 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 06:08:12.828423 | controller | skipping: Conditional result was False
2025-10-13 06:08:12.842578 | 
2025-10-13 06:08:12.842770 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 06:08:12.901539 | controller | skipping: Conditional result was False
2025-10-13 06:08:12.916584 | 
2025-10-13 06:08:12.916793 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 06:08:12.943941 | controller | skipping: Conditional result was False
2025-10-13 06:08:12.958428 | 
2025-10-13 06:08:12.958622 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 06:08:13.506224 | controller | skipping: Conditional result was False
2025-10-13 06:08:13.519864 | 
2025-10-13 06:08:13.520114 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 06:08:13.548723 | controller | skipping: Conditional result was False
2025-10-13 06:08:13.560647 | 
2025-10-13 06:08:13.560792 | TASK [ensure-pip : Install pip from source]
2025-10-13 06:08:13.588366 | controller | skipping: Conditional result was False
2025-10-13 06:08:13.598649 | 
2025-10-13 06:08:13.598741 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 02:08:13.894479 | controller | /usr/bin/python3
2025-10-13 06:08:14.141813 | controller | ok: Runtime: 0:00:00.006025
2025-10-13 06:08:14.154230 | 
2025-10-13 06:08:14.154362 | TASK [ensure-pip : Set host default]
2025-10-13 06:08:14.229683 | controller | ok
2025-10-13 06:08:14.236951 | 
2025-10-13 06:08:14.237046 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 06:08:14.310876 | controller | ok
2025-10-13 06:08:14.325457 | 
2025-10-13 06:08:14.325539 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 06:08:18.511973 | controller | changed
2025-10-13 06:08:18.522058 | 
2025-10-13 06:08:18.522236 | TASK [bindep : Define bindep_command]
2025-10-13 06:08:18.559081 | controller | ok
2025-10-13 06:08:18.567066 | 
2025-10-13 06:08:18.567199 | LOOP [bindep : Include package tasks]
2025-10-13 06:08:18.611976 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 06:08:18.612169 | controller | ok: All items complete
2025-10-13 06:08:18.612196 | 
2025-10-13 06:08:18.625832 | controller | included: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 06:08:18.640934 | 
2025-10-13 06:08:18.641043 | TASK [bindep : Define bindep_run fact]
2025-10-13 06:08:18.673163 | controller | ok
2025-10-13 06:08:18.680005 | 
2025-10-13 06:08:18.680111 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 02:08:20.383265 | controller | podman
2025-10-13 02:08:20.425319 | controller | python3-jmespath
2025-10-13 02:08:20.425542 | controller | python3-libvirt
2025-10-13 02:08:20.425563 | controller | python3-lxml
2025-10-13 02:08:20.425580 | controller | python3-netaddr
2025-10-13 06:08:20.725847 | controller | ok: Runtime: 0:00:01.461178
2025-10-13 06:08:20.736870 | 
2025-10-13 06:08:20.737000 | TASK [bindep : Install distro packages from bindep]
2025-10-13 06:09:25.027684 | controller | changed
2025-10-13 06:09:25.041367 | 
2025-10-13 06:09:25.041459 | TASK [bindep : Check that packages are installed]
2025-10-13 06:09:26.614712 | controller | ok: Runtime: 0:00:01.058304
2025-10-13 06:09:26.620747 | 
2025-10-13 06:09:26.620811 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 06:09:26.655200 | controller | skipping: Conditional result was False
2025-10-13 06:09:26.665781 | 
2025-10-13 06:09:26.665848 | TASK [Run test-setup role]
2025-10-13 06:09:26.687440 | controller | ok
2025-10-13 06:09:26.710490 | 
2025-10-13 06:09:26.710647 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 06:09:26.950329 | controller | ok
2025-10-13 06:09:26.961500 | 
2025-10-13 06:09:26.961642 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 06:09:27.509160 | controller | skipping: Conditional result was False
2025-10-13 06:09:27.552306 | 
2025-10-13 06:09:27.552503 | TASK [bindep : Remove bindep temp dir]
2025-10-13 06:09:27.911468 | controller | ok
2025-10-13 06:09:27.930784 | 
2025-10-13 06:09:27.930901 | PLAY RECAP
2025-10-13 06:09:27.930943 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 06:09:27.930965 | 
2025-10-13 06:09:28.030172 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:09:28.031852 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:09:28.593904 | 
2025-10-13 06:09:28.594038 | PLAY [all]
2025-10-13 06:09:28.613335 | 
2025-10-13 06:09:28.613416 | TASK [Abort when test_command variable is undefined]
2025-10-13 06:09:28.637948 | controller | skipping: Conditional result was False
2025-10-13 06:09:28.643763 | 
2025-10-13 06:09:28.643833 | TASK [Convert test_command to list]
2025-10-13 06:09:28.688219 | controller | skipping: Conditional result was False
2025-10-13 06:09:28.694584 | 
2025-10-13 06:09:28.694662 | TASK [Use test_command list]
2025-10-13 06:09:28.739906 | controller | ok
2025-10-13 06:09:28.751653 | 
2025-10-13 06:09:28.751782 | LOOP [Run test_command]
2025-10-13 06:09:29.126616 | controller | no check to run
2025-10-13 06:09:29.126947 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004754
2025-10-13 06:09:29.165056 | 
2025-10-13 06:09:29.165256 | PLAY RECAP
2025-10-13 06:09:29.165330 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:09:29.165369 | 
2025-10-13 06:09:29.276332 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:09:29.278088 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:09:29.889587 | 
2025-10-13 06:09:29.889707 | PLAY [all]
2025-10-13 06:09:29.910133 | 
2025-10-13 06:09:29.910220 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 06:09:30.311355 | controller | changed: non-zero return code
2025-10-13 06:09:30.330379 | 
2025-10-13 06:09:30.330631 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 06:09:30.357957 | controller | skipping: Conditional result was False
2025-10-13 06:09:30.371100 | 
2025-10-13 06:09:30.371251 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 06:09:30.411627 | 
2025-10-13 06:09:30.411986 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 06:09:30.459495 | 
2025-10-13 06:09:30.459700 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 06:09:30.485332 | controller | skipping: Conditional result was False
2025-10-13 06:09:30.498279 | 
2025-10-13 06:09:30.498423 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 06:09:30.527669 | 
2025-10-13 06:09:30.527850 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 06:09:30.552550 | controller | skipping: Conditional result was False
2025-10-13 06:09:30.565262 | 
2025-10-13 06:09:30.565452 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 06:09:30.582342 | controller | skipping: Conditional result was False
2025-10-13 06:09:30.596768 | 
2025-10-13 06:09:30.596951 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 06:09:30.613680 | controller | skipping: Conditional result was False
2025-10-13 06:09:30.656260 | 
2025-10-13 06:09:30.656400 | PLAY RECAP
2025-10-13 06:09:30.656459 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 06:09:30.656490 | 
2025-10-13 06:09:30.778349 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:09:30.780100 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:09:31.404643 | 
2025-10-13 06:09:31.404758 | PLAY [all]
2025-10-13 06:09:31.424104 | 
2025-10-13 06:09:31.424190 | TASK [include_role : fetch-output]
2025-10-13 06:09:31.473048 | controller | ok
2025-10-13 06:09:31.489599 | 
2025-10-13 06:09:31.489680 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 06:09:31.564748 | controller | skipping: Conditional result was False
2025-10-13 06:09:31.570336 | 
2025-10-13 06:09:31.570400 | TASK [fetch-output : Set log path for single node]
2025-10-13 06:09:31.629488 | controller | ok
2025-10-13 06:09:31.634401 | 
2025-10-13 06:09:31.634467 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 06:09:32.076715 | controller -> localhost | ok: "/var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/logs"
2025-10-13 06:09:32.347875 | controller -> localhost | changed: "/var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/artifacts"
2025-10-13 06:09:32.604486 | controller -> localhost | changed: "/var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/docs"
2025-10-13 06:09:32.621224 | 
2025-10-13 06:09:32.621380 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 06:09:33.271090 | controller | changed: .d..t...... ./
2025-10-13 06:09:33.271460 | controller | changed: All items complete
2025-10-13 06:09:33.271520 | 
2025-10-13 06:09:33.824088 | controller | changed: .d..t...... ./
2025-10-13 06:09:34.342986 | controller | changed: .d..t...... ./
2025-10-13 06:09:34.370922 | 
2025-10-13 06:09:34.371096 | TASK [include_role : fetch-output-openshift]
2025-10-13 06:09:34.396383 | controller | skipping: Conditional result was False
2025-10-13 06:09:34.404749 | 
2025-10-13 06:09:34.404842 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 06:09:34.831989 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014523
2025-10-13 06:09:35.132190 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013856
2025-10-13 06:09:35.194396 | 
2025-10-13 06:09:35.194507 | PLAY [all]
2025-10-13 06:09:35.214234 | 
2025-10-13 06:09:35.214345 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 06:09:35.679594 | controller | changed
2025-10-13 06:09:35.727686 | 
2025-10-13 06:09:35.727893 | PLAY RECAP
2025-10-13 06:09:35.727960 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:09:35.728000 | 
2025-10-13 06:09:35.841681 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:09:35.843369 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 06:09:36.521115 | 
2025-10-13 06:09:36.521255 | PLAY [localhost]
2025-10-13 06:09:36.540114 | 
2025-10-13 06:09:36.540244 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 06:09:37.025129 | localhost | changed
2025-10-13 06:09:37.030413 | 
2025-10-13 06:09:37.030529 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 06:09:37.057933 | localhost | ok
2025-10-13 06:09:37.066256 | 
2025-10-13 06:09:37.066325 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 06:09:37.422263 | localhost | changed
2025-10-13 06:09:37.429542 | 
2025-10-13 06:09:37.429626 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 06:09:38.166487 | localhost | changed
2025-10-13 06:09:38.173567 | 
2025-10-13 06:09:38.173654 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 06:09:38.621583 | localhost | Identity added: /var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/tmp/ansible.ym6pdpvb (/var/lib/zuul/builds/16709550f8f541e6a8d9ee03d590dc4b/work/tmp/ansible.ym6pdpvb)
2025-10-13 06:09:38.621821 | localhost | ok: Runtime: 0:00:00.013200
2025-10-13 06:09:38.627848 | 
2025-10-13 06:09:38.627935 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 06:09:38.965962 | localhost | ok: Runtime: 0:00:00.011679
2025-10-13 06:09:38.970817 | 
2025-10-13 06:09:38.970884 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 06:09:39.041280 | localhost | changed
2025-10-13 06:09:39.045583 | 
2025-10-13 06:09:39.045647 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 06:09:39.449941 | localhost | changed
2025-10-13 06:09:39.470597 | 
2025-10-13 06:09:39.470652 | PLAY [localhost]
2025-10-13 06:09:39.482632 | 
2025-10-13 06:09:39.482689 | TASK [Generate bulk log download script]
2025-10-13 06:09:39.501489 | localhost | ok
2025-10-13 06:09:39.513527 | 
2025-10-13 06:09:39.513614 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 06:09:39.562233 | localhost | ok: All assertions passed
2025-10-13 06:09:39.566972 | 
2025-10-13 06:09:39.567049 | TASK [local-log-download : Create download script]
2025-10-13 06:09:40.049777 | localhost -> localhost | changed
2025-10-13 06:09:40.069830 | 
2025-10-13 06:09:40.070041 | TASK [Register quick-download link]
2025-10-13 06:09:40.098163 | localhost | ok
2025-10-13 06:09:40.157978 | 
2025-10-13 06:09:40.158105 | PLAY [logserver.rdoproject.org]
2025-10-13 06:09:40.167890 | 
2025-10-13 06:09:40.167964 | TASK [Set zuul-log-path fact]
2025-10-13 06:09:40.185708 | logserver.rdoproject.org | ok
2025-10-13 06:09:40.195122 | 
2025-10-13 06:09:40.195206 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:09:40.232537 | logserver.rdoproject.org | ok
2025-10-13 06:09:40.237855 | 
2025-10-13 06:09:40.237916 | TASK [upload-logs : Create log directories]
2025-10-13 06:09:40.952881 | logserver.rdoproject.org | changed
2025-10-13 06:09:40.960306 | 
2025-10-13 06:09:40.960449 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 06:09:41.292969 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009255
2025-10-13 06:09:41.298262 | 
2025-10-13 06:09:41.298334 | TASK [upload-logs : Upload logs to log server]
2025-10-13 06:09:42.067165 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 06:09:42.073479 | 
2025-10-13 06:09:42.073615 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 06:09:42.147927 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:42.173739 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:42.189748 | 
2025-10-13 06:09:42.189959 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 06:09:42.259938 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:42.260422 | 
2025-10-13 06:09:42.264487 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:09:42.274238 | 
2025-10-13 06:09:42.274422 | LOOP [upload-logs : Upload console log and json output]