2025-12-05 23:36:37.231638 | Job console starting...
2025-12-05 23:36:37.242453 | Updating repositories
2025-12-05 23:36:37.272607 | Preparing job workspace
2025-12-05 23:36:40.988579 | Running Ansible setup...
2025-12-05 23:36:45.645533 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 23:36:46.390575 | 
2025-12-05 23:36:46.390764 | PLAY [localhost]
2025-12-05 23:36:46.402110 | 
2025-12-05 23:36:46.402202 | TASK [Gathering Facts]
2025-12-05 23:36:47.596002 | localhost | ok
2025-12-05 23:36:47.614091 | 
2025-12-05 23:36:47.614326 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-05 23:36:47.997397 | localhost -> localhost | changed
2025-12-05 23:36:48.002737 | 
2025-12-05 23:36:48.002806 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-05 23:36:48.896781 | localhost -> localhost | changed
2025-12-05 23:36:48.904746 | 
2025-12-05 23:36:48.904808 | TASK [Setup log path fact]
2025-12-05 23:36:48.922859 | localhost | ok
2025-12-05 23:36:48.940311 | 
2025-12-05 23:36:48.940404 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 23:36:48.967339 | localhost | ok
2025-12-05 23:36:48.974708 | 
2025-12-05 23:36:48.974774 | TASK [emit-job-header : Print job information]
2025-12-05 23:36:49.001791 | # Job Information
2025-12-05 23:36:49.001992 | Ansible Version: 2.15.12
2025-12-05 23:36:49.002067 | Job: cifmw-molecule-krb_request
2025-12-05 23:36:49.002088 | Pipeline: github-check
2025-12-05 23:36:49.002106 | Executor: ze01.softwarefactory-project.io
2025-12-05 23:36:49.002124 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539
2025-12-05 23:36:49.002142 | Log URL (when completed): https://logserver.rdoproject.org/a88/rdoproject.org/a886a179462e45bb9d4e5675490b88d8/
2025-12-05 23:36:49.002160 | Event ID: 0eecf260-d233-11f0-9ab7-da45df476e85
2025-12-05 23:36:49.007320 | 
2025-12-05 23:36:49.007398 | LOOP [emit-job-header : Print node information]
2025-12-05 23:36:49.109534 | localhost | ok:
2025-12-05 23:36:49.109724 | localhost | # Node Information
2025-12-05 23:36:49.109751 | localhost | Inventory Hostname: controller
2025-12-05 23:36:49.109777 | localhost | Hostname: np0005548182
2025-12-05 23:36:49.109796 | localhost | Username: zuul
2025-12-05 23:36:49.109815 | localhost | Distro: CentOS 9
2025-12-05 23:36:49.109853 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-05 23:36:49.109872 | localhost | Region: RegionOne
2025-12-05 23:36:49.109889 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-05 23:36:49.109905 | localhost | Product Name: OpenStack Nova
2025-12-05 23:36:49.109921 | localhost | Interface IP: 38.102.83.154
2025-12-05 23:36:49.133107 | 
2025-12-05 23:36:49.133186 | PLAY [all]
2025-12-05 23:36:49.139331 | 
2025-12-05 23:36:49.139389 | TASK [Gather network facts]
2025-12-05 23:36:49.662909 | controller | ok
2025-12-05 23:36:49.681768 | 
2025-12-05 23:36:49.681864 | TASK [include_role : start-zuul-console]
2025-12-05 23:36:49.721380 | controller | ok
2025-12-05 23:36:49.741844 | 
2025-12-05 23:36:49.741922 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-05 23:36:50.208265 | controller | ok
2025-12-05 23:36:50.221195 | 
2025-12-05 23:36:50.221253 | TASK [include_role : add-build-sshkey]
2025-12-05 23:36:50.249008 | controller | ok
2025-12-05 23:36:50.262440 | 
2025-12-05 23:36:50.262524 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 23:36:50.648802 | controller -> localhost | ok
2025-12-05 23:36:50.655879 | 
2025-12-05 23:36:50.655947 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 23:36:50.697788 | controller | ok
2025-12-05 23:36:50.734736 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 23:36:50.740572 | 
2025-12-05 23:36:50.740633 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 23:36:51.570421 | controller -> localhost | Generating public/private rsa key pair.
2025-12-05 23:36:51.570645 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/a886a179462e45bb9d4e5675490b88d8_id_rsa.
2025-12-05 23:36:51.570678 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/a886a179462e45bb9d4e5675490b88d8_id_rsa.pub.
2025-12-05 23:36:51.570700 | controller -> localhost | The key fingerprint is:
2025-12-05 23:36:51.570720 | controller -> localhost | SHA256:joGa/hIPEkJ02YTWeokj/ikaZvx50Kjw8e2+RM4UEak zuul-build-sshkey
2025-12-05 23:36:51.570739 | controller -> localhost | The key's randomart image is:
2025-12-05 23:36:51.570757 | controller -> localhost | +---[RSA 3072]----+
2025-12-05 23:36:51.570775 | controller -> localhost | |.. .*.oo         |
2025-12-05 23:36:51.570794 | controller -> localhost | | ..+ o..         |
2025-12-05 23:36:51.570827 | controller -> localhost | |. . o.o          |
2025-12-05 23:36:51.570845 | controller -> localhost | |o. +E+ .         |
2025-12-05 23:36:51.570862 | controller -> localhost | |o.. * + S        |
2025-12-05 23:36:51.570879 | controller -> localhost | |+.+= * +         |
2025-12-05 23:36:51.570896 | controller -> localhost | |o*=*o.= .        |
2025-12-05 23:36:51.570915 | controller -> localhost | |o=+o+o.          |
2025-12-05 23:36:51.570932 | controller -> localhost | |o o=oo+.         |
2025-12-05 23:36:51.570948 | controller -> localhost | +----[SHA256]-----+
2025-12-05 23:36:51.570997 | controller -> localhost | ok: Runtime: 0:00:00.313199
2025-12-05 23:36:51.576768 | 
2025-12-05 23:36:51.576853 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 23:36:51.605321 | controller | ok
2025-12-05 23:36:51.618665 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 23:36:51.630555 | 
2025-12-05 23:36:51.630672 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 23:36:51.655089 | controller | skipping: Conditional result was False
2025-12-05 23:36:51.660602 | 
2025-12-05 23:36:51.660695 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 23:36:52.221261 | controller | changed
2025-12-05 23:36:52.229606 | 
2025-12-05 23:36:52.229701 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 23:36:52.499292 | controller | ok
2025-12-05 23:36:52.504483 | 
2025-12-05 23:36:52.504546 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 23:36:53.480535 | controller | changed
2025-12-05 23:36:53.491220 | 
2025-12-05 23:36:53.491334 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 23:36:54.460534 | controller | changed
2025-12-05 23:36:54.466901 | 
2025-12-05 23:36:54.467029 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 23:36:54.514247 | controller | skipping: Conditional result was False
2025-12-05 23:36:54.520077 | 
2025-12-05 23:36:54.520148 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 23:36:54.942060 | controller -> localhost | changed
2025-12-05 23:36:54.951357 | 
2025-12-05 23:36:54.951419 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 23:36:55.212313 | controller -> localhost | Identity added: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/a886a179462e45bb9d4e5675490b88d8_id_rsa (zuul-build-sshkey)
2025-12-05 23:36:55.212539 | controller -> localhost | ok: Runtime: 0:00:00.009403
2025-12-05 23:36:55.219398 | 
2025-12-05 23:36:55.219466 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 23:36:55.659250 | controller | ok
2025-12-05 23:36:55.664030 | 
2025-12-05 23:36:55.664094 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 23:36:55.701455 | controller | skipping: Conditional result was False
2025-12-05 23:36:55.711635 | 
2025-12-05 23:36:55.711716 | TASK [include_role : validate-host]
2025-12-05 23:36:55.745190 | controller | ok
2025-12-05 23:36:55.765956 | 
2025-12-05 23:36:55.766058 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-05 23:36:55.794299 | controller | ok
2025-12-05 23:36:55.798935 | 
2025-12-05 23:36:55.798997 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-05 23:36:56.130983 | controller -> localhost | ok
2025-12-05 23:36:56.169944 | 
2025-12-05 23:36:56.170080 | TASK [validate-host : Collect information about the host]
2025-12-05 23:36:56.915709 | controller | ok
2025-12-05 23:36:56.928625 | 
2025-12-05 23:36:56.928706 | TASK [validate-host : Sanitize hostname]
2025-12-05 23:36:56.994215 | controller | ok
2025-12-05 23:36:56.999044 | 
2025-12-05 23:36:56.999108 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-05 23:36:57.520327 | controller -> localhost | changed
2025-12-05 23:36:57.525729 | 
2025-12-05 23:36:57.525794 | TASK [validate-host : Collect information about zuul worker]
2025-12-05 23:36:57.954279 | controller | ok
2025-12-05 23:36:57.959323 | 
2025-12-05 23:36:57.959385 | TASK [validate-host : Write out all zuul information for each host]
2025-12-05 23:36:58.417980 | controller -> localhost | changed
2025-12-05 23:36:58.430214 | 
2025-12-05 23:36:58.430309 | TASK [include_role : prepare-workspace-openshift]
2025-12-05 23:36:58.468677 | controller | skipping: Conditional result was False
2025-12-05 23:36:58.474846 | 
2025-12-05 23:36:58.474928 | TASK [include_role : remove-zuul-sshkey]
2025-12-05 23:36:58.498838 | controller | skipping: Conditional result was False
2025-12-05 23:36:58.504486 | 
2025-12-05 23:36:58.504556 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 23:36:58.802624 | controller | ok: "logs"
2025-12-05 23:36:58.802879 | controller | ok: All items complete
2025-12-05 23:36:58.802915 | 
2025-12-05 23:36:59.015107 | controller | ok: "artifacts"
2025-12-05 23:36:59.247160 | controller | ok: "docs"
2025-12-05 23:36:59.261429 | 
2025-12-05 23:36:59.261558 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 23:36:59.566321 | controller | changed: "logs"
2025-12-05 23:36:59.799409 | controller | changed: "artifacts"
2025-12-05 23:37:00.031422 | controller | changed: "docs"
2025-12-05 23:37:00.058353 | 
2025-12-05 23:37:00.058450 | PLAY RECAP
2025-12-05 23:37:00.058496 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-05 23:37:00.058524 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 23:37:00.058543 | 
2025-12-05 23:37:00.163415 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 23:37:00.164348 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 23:37:00.722862 | 
2025-12-05 23:37:00.722983 | PLAY [localhost]
2025-12-05 23:37:00.739917 | 
2025-12-05 23:37:00.739995 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-05 23:37:01.157353 | localhost | ok
2025-12-05 23:37:01.162775 | 
2025-12-05 23:37:01.163055 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-05 23:37:01.858447 | localhost | changed
2025-12-05 23:37:01.901284 | 
2025-12-05 23:37:01.901379 | PLAY [all]
2025-12-05 23:37:01.916499 | 
2025-12-05 23:37:01.916564 | TASK [include_role : prepare-workspace]
2025-12-05 23:37:01.935240 | controller | ok
2025-12-05 23:37:01.964514 | 
2025-12-05 23:37:01.964647 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-05 23:37:02.378239 | controller | ok
2025-12-05 23:37:02.385054 | 
2025-12-05 23:37:02.385119 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-05 23:37:03.966761 | controller | Output suppressed because no_log was given
2025-12-05 23:37:03.979421 | 
2025-12-05 23:37:03.979484 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 23:37:04.241840 | controller | changed: "logs"
2025-12-05 23:37:04.467260 | controller | changed: "artifacts"
2025-12-05 23:37:04.685457 | controller | changed: "docs"
2025-12-05 23:37:04.707123 | 
2025-12-05 23:37:04.707335 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 23:37:04.979830 | controller | changed: "logs"
2025-12-05 23:37:04.980121 | controller | changed: All items complete
2025-12-05 23:37:04.980159 | 
2025-12-05 23:37:05.197337 | controller | changed: "artifacts"
2025-12-05 23:37:05.444737 | controller | changed: "docs"
2025-12-05 23:37:05.460597 | 
2025-12-05 23:37:05.460742 | TASK [Check if worker can sudo]
2025-12-05 23:37:06.013134 | controller | ok: Runtime: 0:00:00.038264
2025-12-05 23:37:06.019378 | 
2025-12-05 23:37:06.019458 | TASK [configure-mirrors : Gather needed facts]
2025-12-05 23:37:06.063463 | controller | skipping: Conditional result was False
2025-12-05 23:37:06.069498 | 
2025-12-05 23:37:06.069574 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-05 23:37:06.141233 | controller | ok
2025-12-05 23:37:06.149602 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-05 23:37:06.155100 | 
2025-12-05 23:37:06.155172 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-05 23:37:06.471951 | controller | ok
2025-12-05 23:37:06.479299 | 
2025-12-05 23:37:06.479403 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-05 23:37:06.536468 | controller | ok: "/var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-05 23:37:06.551846 | 
2025-12-05 23:37:06.551946 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-05 23:37:07.571289 | controller | changed
2025-12-05 23:37:07.578398 | 
2025-12-05 23:37:07.578468 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-05 23:37:07.668157 | controller | ok: "/var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-05 23:37:07.668311 | controller | ok: All items complete
2025-12-05 23:37:07.668338 | 
2025-12-05 23:37:07.722005 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-05 23:37:07.729646 | 
2025-12-05 23:37:07.729716 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-05 23:37:08.647657 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-05 23:37:09.408552 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-05 23:37:09.423141 | 
2025-12-05 23:37:09.423210 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-05 23:37:09.859496 | controller | changed: section and option added
2025-12-05 23:37:09.895605 | 
2025-12-05 23:37:09.895749 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-05 23:37:10.569538 | controller | 29 files removed
2025-12-05 23:37:10.569742 | controller | ok: Item: dnf clean all Runtime: 0:00:00.335136
2025-12-05 23:37:10.569781 | controller | changed: All items complete
2025-12-05 23:37:10.569802 | 
2025-12-05 23:37:23.657481 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-12-05 23:37:23.658196 | controller | DNF version: 4.14.0
2025-12-05 23:37:23.658255 | controller | cachedir: /var/cache/dnf
2025-12-05 23:37:23.658279 | controller | Making cache files for all metadata files.
2025-12-05 23:37:23.658297 | controller | baseos: has expired and will be refreshed.
2025-12-05 23:37:23.658314 | controller | appstream: has expired and will be refreshed.
2025-12-05 23:37:23.658330 | controller | crb: has expired and will be refreshed.
2025-12-05 23:37:23.658354 | controller | extras-common: has expired and will be refreshed.
2025-12-05 23:37:23.658371 | controller | repo: downloading from remote: baseos
2025-12-05 23:37:23.658387 | controller | CentOS Stream 9 - BaseOS                         45 MB/s | 8.8 MB     00:00
2025-12-05 23:37:23.658404 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-05 23:37:23.658420 | controller | repo: downloading from remote: appstream
2025-12-05 23:37:23.658436 | controller | CentOS Stream 9 - AppStream                      91 MB/s |  25 MB     00:00
2025-12-05 23:37:23.658452 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-05 23:37:23.658468 | controller | repo: downloading from remote: crb
2025-12-05 23:37:23.658484 | controller | CentOS Stream 9 - CRB                            58 MB/s | 7.3 MB     00:00
2025-12-05 23:37:23.658500 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-05 23:37:23.658517 | controller | repo: downloading from remote: extras-common
2025-12-05 23:37:23.658533 | controller | CentOS Stream 9 - Extras packages               1.5 MB/s |  20 kB     00:00
2025-12-05 23:37:23.658549 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-05 23:37:23.658565 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-05 23:37:23.658582 | controller | Completion plugin: Generating completion cache...
2025-12-05 23:37:23.658598 | controller | Metadata cache created.
2025-12-05 23:37:23.658624 | controller | ok: Item: dnf makecache -v Runtime: 0:00:12.815258
2025-12-05 23:37:23.682798 | 
2025-12-05 23:37:23.682905 | PLAY RECAP
2025-12-05 23:37:23.682957 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-05 23:37:23.682992 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 23:37:23.683038 | 
2025-12-05 23:37:23.798449 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 23:37:23.799301 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 23:37:24.400678 | 
2025-12-05 23:37:24.400790 | PLAY [all]
2025-12-05 23:37:24.422390 | 
2025-12-05 23:37:24.422473 | TASK [Install binary dependencies]
2025-12-05 23:37:24.502658 | controller | ok
2025-12-05 23:37:24.522447 | 
2025-12-05 23:37:24.522527 | TASK [bindep : Include find tasks]
2025-12-05 23:37:24.565027 | controller | ok
2025-12-05 23:37:24.572812 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-05 23:37:24.578737 | 
2025-12-05 23:37:24.578799 | TASK [bindep : Look for bindep.txt]
2025-12-05 23:37:24.998435 | controller | ok
2025-12-05 23:37:25.007807 | 
2025-12-05 23:37:25.007912 | TASK [bindep : Define bindep_file fact]
2025-12-05 23:37:25.051926 | controller | ok
2025-12-05 23:37:25.059939 | 
2025-12-05 23:37:25.060185 | TASK [bindep : Look for other-requirements.txt]
2025-12-05 23:37:25.096264 | controller | skipping: Conditional result was False
2025-12-05 23:37:25.104947 | 
2025-12-05 23:37:25.105070 | TASK [bindep : Define bindep_file fact]
2025-12-05 23:37:25.151548 | controller | skipping: Conditional result was False
2025-12-05 23:37:25.159986 | 
2025-12-05 23:37:25.160126 | TASK [bindep : Look for bindep fallback file]
2025-12-05 23:37:25.196891 | controller | skipping: Conditional result was False
2025-12-05 23:37:25.203077 | 
2025-12-05 23:37:25.203155 | TASK [bindep : Define bindep_file fact]
2025-12-05 23:37:25.226569 | controller | skipping: Conditional result was False
2025-12-05 23:37:25.233202 | 
2025-12-05 23:37:25.233300 | TASK [bindep : Include bindep tasks]
2025-12-05 23:37:25.274710 | controller | ok
2025-12-05 23:37:25.282287 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-05 23:37:25.290994 | 
2025-12-05 23:37:25.291098 | TASK [bindep : Look for bindep command]
2025-12-05 23:37:25.314700 | controller | skipping: Conditional result was False
2025-12-05 23:37:25.324349 | 
2025-12-05 23:37:25.324452 | TASK [bindep : Check for system bindep]
2025-12-05 23:37:25.878056 | controller | ok: Runtime: 0:00:00.006506
2025-12-05 23:37:25.890955 | 
2025-12-05 23:37:25.891120 | TASK [bindep : Define bindep_command fact]
2025-12-05 23:37:25.917994 | controller | skipping: Conditional result was False
2025-12-05 23:37:25.931110 | 
2025-12-05 23:37:25.931254 | TASK [bindep : Include install tasks]
2025-12-05 23:37:25.978878 | controller | ok
2025-12-05 23:37:25.996346 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-05 23:37:26.009614 | 
2025-12-05 23:37:26.009697 | TASK [bindep : Create temp dir for bindep]
2025-12-05 23:37:26.433113 | controller | changed
2025-12-05 23:37:26.449475 | 
2025-12-05 23:37:26.449613 | TASK [Ensure we have pip dependencies]
2025-12-05 23:37:26.479255 | controller | ok
2025-12-05 23:37:26.517559 | 
2025-12-05 23:37:26.517676 | TASK [ensure-pip : Check if pip is installed]
2025-12-05 18:37:26.800781 | controller | /usr/bin/pip3
2025-12-05 18:37:26.824294 | controller | /usr/bin/python3: No module named wheel
2025-12-05 23:37:27.049666 | controller | ok: Runtime: 0:00:00.036099
2025-12-05 23:37:27.062146 | 
2025-12-05 23:37:27.062276 | LOOP [ensure-pip : Install pip from packages]
2025-12-05 23:37:27.108263 | controller | ok: "/var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-05 23:37:27.121404 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-05 23:37:27.131699 | 
2025-12-05 23:37:27.131760 | TASK [ensure-pip : Install Python 3 pip]
2025-12-05 23:37:29.320990 | controller | changed
2025-12-05 23:37:29.342088 | 
2025-12-05 23:37:29.342294 | TASK [ensure-pip : Check for EPEL repository]
2025-12-05 23:37:29.416259 | controller | skipping: Conditional result was False
2025-12-05 23:37:29.422531 | 
2025-12-05 23:37:29.422597 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-05 23:37:29.496625 | controller | skipping: Conditional result was False
2025-12-05 23:37:29.503076 | 
2025-12-05 23:37:29.503143 | TASK [ensure-pip : Install Python 2 pip]
2025-12-05 23:37:29.540537 | controller | skipping: Conditional result was False
2025-12-05 23:37:29.557294 | 
2025-12-05 23:37:29.557400 | TASK [ensure-pip : Ensure setuptools]
2025-12-05 23:37:29.581596 | controller | skipping: Conditional result was False
2025-12-05 23:37:29.587334 | 
2025-12-05 23:37:29.587407 | TASK [ensure-pip : Check for ensurepip module]
2025-12-05 23:37:30.118524 | controller | skipping: Conditional result was False
2025-12-05 23:37:30.132697 | 
2025-12-05 23:37:30.132868 | TASK [ensure-pip : Ensure python3-venv]
2025-12-05 23:37:30.149366 | controller | skipping: Conditional result was False
2025-12-05 23:37:30.163628 | 
2025-12-05 23:37:30.163969 | TASK [ensure-pip : Install pip from source]
2025-12-05 23:37:30.190430 | controller | skipping: Conditional result was False
2025-12-05 23:37:30.199876 | 
2025-12-05 23:37:30.200254 | TASK [ensure-pip : Probe for venv python full path]
2025-12-05 18:37:30.467125 | controller | /usr/bin/python3
2025-12-05 23:37:30.736044 | controller | ok: Runtime: 0:00:00.006482
2025-12-05 23:37:30.751405 | 
2025-12-05 23:37:30.753258 | TASK [ensure-pip : Set host default]
2025-12-05 23:37:30.826228 | controller | ok
2025-12-05 23:37:30.831392 | 
2025-12-05 23:37:30.831470 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-05 23:37:30.881960 | controller | ok
2025-12-05 23:37:30.892364 | 
2025-12-05 23:37:30.892432 | TASK [bindep : Install bindep into temporary venv]
2025-12-05 23:37:35.599305 | controller | changed
2025-12-05 23:37:35.614976 | 
2025-12-05 23:37:35.615092 | TASK [bindep : Define bindep_command]
2025-12-05 23:37:35.674789 | controller | ok
2025-12-05 23:37:35.694849 | 
2025-12-05 23:37:35.694938 | LOOP [bindep : Include package tasks]
2025-12-05 23:37:35.777934 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-05 23:37:35.778160 | controller | ok: All items complete
2025-12-05 23:37:35.778189 | 
2025-12-05 23:37:35.788758 | controller | included: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-05 23:37:35.804606 | 
2025-12-05 23:37:35.804684 | TASK [bindep : Define bindep_run fact]
2025-12-05 23:37:35.833267 | controller | ok
2025-12-05 23:37:35.841949 | 
2025-12-05 23:37:35.842032 | TASK [bindep : Get list of packages to install from bindep]
2025-12-05 18:37:37.415758 | controller | podman
2025-12-05 18:37:37.449593 | controller | python3-jmespath
2025-12-05 18:37:37.449823 | controller | python3-libvirt
2025-12-05 18:37:37.449834 | controller | python3-lxml
2025-12-05 18:37:37.449846 | controller | python3-netaddr
2025-12-05 23:37:37.917969 | controller | ok: Runtime: 0:00:01.183273
2025-12-05 23:37:37.926347 | 
2025-12-05 23:37:37.926456 | TASK [bindep : Install distro packages from bindep]
2025-12-05 23:38:50.379832 | controller | changed
2025-12-05 23:38:50.393612 | 
2025-12-05 23:38:50.393772 | TASK [bindep : Check that packages are installed]
2025-12-05 23:38:52.432154 | controller | ok: Runtime: 0:00:01.520694
2025-12-05 23:38:52.438288 | 
2025-12-05 23:38:52.438434 | TASK [bindep : Fail if we cannot install all packages]
2025-12-05 23:38:52.482953 | controller | skipping: Conditional result was False
2025-12-05 23:38:52.496646 | 
2025-12-05 23:38:52.496726 | TASK [Run test-setup role]
2025-12-05 23:38:52.531739 | controller | ok
2025-12-05 23:38:52.560651 | 
2025-12-05 23:38:52.560768 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-05 23:38:52.825070 | controller | ok
2025-12-05 23:38:52.830400 | 
2025-12-05 23:38:52.830465 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-05 23:38:53.360721 | controller | skipping: Conditional result was False
2025-12-05 23:38:53.381532 | 
2025-12-05 23:38:53.381618 | TASK [bindep : Remove bindep temp dir]
2025-12-05 23:38:53.776826 | controller | ok
2025-12-05 23:38:53.805611 | 
2025-12-05 23:38:53.805740 | PLAY RECAP
2025-12-05 23:38:53.805788 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-05 23:38:53.805808 | 
2025-12-05 23:38:53.922056 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 23:38:53.922866 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 23:38:54.493143 | 
2025-12-05 23:38:54.493255 | PLAY [all]
2025-12-05 23:38:54.522090 | 
2025-12-05 23:38:54.522190 | TASK [Abort when test_command variable is undefined]
2025-12-05 23:38:54.567241 | controller | skipping: Conditional result was False
2025-12-05 23:38:54.572968 | 
2025-12-05 23:38:54.573065 | TASK [Convert test_command to list]
2025-12-05 23:38:54.617096 | controller | skipping: Conditional result was False
2025-12-05 23:38:54.623507 | 
2025-12-05 23:38:54.623575 | TASK [Use test_command list]
2025-12-05 23:38:54.672507 | controller | ok
2025-12-05 23:38:54.677980 | 
2025-12-05 23:38:54.678104 | LOOP [Run test_command]
2025-12-05 23:38:55.108231 | controller | no check to run
2025-12-05 23:38:55.108388 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008006
2025-12-05 23:38:55.131155 | 
2025-12-05 23:38:55.131251 | PLAY RECAP
2025-12-05 23:38:55.131290 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 23:38:55.131310 | 
2025-12-05 23:38:55.214822 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 23:38:55.215662 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 23:38:55.777941 | 
2025-12-05 23:38:55.778073 | PLAY [all]
2025-12-05 23:38:55.803123 | 
2025-12-05 23:38:55.803224 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-05 23:38:56.217792 | controller | changed: non-zero return code
2025-12-05 23:38:56.234596 | 
2025-12-05 23:38:56.234712 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-05 23:38:56.258951 | controller | skipping: Conditional result was False
2025-12-05 23:38:56.265392 | 
2025-12-05 23:38:56.265472 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-05 23:38:56.297380 | 
2025-12-05 23:38:56.297569 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-05 23:38:56.354442 | 
2025-12-05 23:38:56.354660 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-05 23:38:56.368853 | controller | skipping: Conditional result was False
2025-12-05 23:38:56.376964 | 
2025-12-05 23:38:56.377097 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-05 23:38:56.400702 | 
2025-12-05 23:38:56.400850 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-05 23:38:56.414577 | controller | skipping: Conditional result was False
2025-12-05 23:38:56.420879 | 
2025-12-05 23:38:56.420974 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-05 23:38:56.434607 | controller | skipping: Conditional result was False
2025-12-05 23:38:56.441261 | 
2025-12-05 23:38:56.441349 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-05 23:38:56.457521 | controller | skipping: Conditional result was False
2025-12-05 23:38:56.482034 | 
2025-12-05 23:38:56.482103 | PLAY RECAP
2025-12-05 23:38:56.482143 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-05 23:38:56.482163 | 
2025-12-05 23:38:56.579267 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 23:38:56.580054 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 23:38:57.142488 | 
2025-12-05 23:38:57.142591 | PLAY [all]
2025-12-05 23:38:57.164874 | 
2025-12-05 23:38:57.164957 | TASK [include_role : fetch-output]
2025-12-05 23:38:57.204583 | controller | ok
2025-12-05 23:38:57.222131 | 
2025-12-05 23:38:57.222214 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 23:38:57.286520 | controller | skipping: Conditional result was False
2025-12-05 23:38:57.292770 | 
2025-12-05 23:38:57.292866 | TASK [fetch-output : Set log path for single node]
2025-12-05 23:38:57.325632 | controller | ok
2025-12-05 23:38:57.330750 | 
2025-12-05 23:38:57.330815 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 23:38:57.866597 | controller -> localhost | ok: "/var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/logs"
2025-12-05 23:38:58.194808 | controller -> localhost | changed: "/var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/artifacts"
2025-12-05 23:38:58.447452 | controller -> localhost | changed: "/var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/docs"
2025-12-05 23:38:58.459813 | 
2025-12-05 23:38:58.459926 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 23:38:59.097862 | controller | changed: .d..t...... ./
2025-12-05 23:38:59.102070 | controller | changed: All items complete
2025-12-05 23:38:59.102133 | 
2025-12-05 23:38:59.680204 | controller | changed: .d..t...... ./
2025-12-05 23:39:00.145342 | controller | changed: .d..t...... ./
2025-12-05 23:39:00.167061 | 
2025-12-05 23:39:00.167177 | TASK [include_role : fetch-output-openshift]
2025-12-05 23:39:00.180975 | controller | skipping: Conditional result was False
2025-12-05 23:39:00.187427 | 
2025-12-05 23:39:00.187523 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-05 23:39:00.731997 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007785
2025-12-05 23:39:00.976561 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008260
2025-12-05 23:39:01.011627 | 
2025-12-05 23:39:01.011720 | PLAY [all]
2025-12-05 23:39:01.025622 | 
2025-12-05 23:39:01.025686 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-05 23:39:01.501496 | controller | changed
2025-12-05 23:39:01.534132 | 
2025-12-05 23:39:01.534227 | PLAY RECAP
2025-12-05 23:39:01.534271 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 23:39:01.534292 | 
2025-12-05 23:39:01.629576 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 23:39:01.630451 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-05 23:39:02.286899 | 
2025-12-05 23:39:02.287026 | PLAY [localhost]
2025-12-05 23:39:02.310423 | 
2025-12-05 23:39:02.310557 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-05 23:39:02.808259 | localhost | changed
2025-12-05 23:39:02.813173 | 
2025-12-05 23:39:02.813248 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-05 23:39:02.841933 | localhost | ok
2025-12-05 23:39:02.851089 | 
2025-12-05 23:39:02.851159 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-05 23:39:03.324944 | localhost | changed
2025-12-05 23:39:03.330497 | 
2025-12-05 23:39:03.330566 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-05 23:39:04.049035 | localhost | changed
2025-12-05 23:39:04.059143 | 
2025-12-05 23:39:04.059223 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-05 23:39:04.534786 | localhost | Identity added: /var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/tmp/ansible.rx3kj8zj (/var/lib/zuul/builds/a886a179462e45bb9d4e5675490b88d8/work/tmp/ansible.rx3kj8zj)
2025-12-05 23:39:04.534970 | localhost | ok: Runtime: 0:00:00.013728
2025-12-05 23:39:04.540302 | 
2025-12-05 23:39:04.540434 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-05 23:39:04.822171 | localhost | ok: Runtime: 0:00:00.011420
2025-12-05 23:39:04.827641 | 
2025-12-05 23:39:04.827793 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-05 23:39:04.875916 | localhost | changed
2025-12-05 23:39:04.880290 | 
2025-12-05 23:39:04.880354 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-05 23:39:05.311921 | localhost | changed
2025-12-05 23:39:05.338293 | 
2025-12-05 23:39:05.338364 | PLAY [localhost]
2025-12-05 23:39:05.350885 | 
2025-12-05 23:39:05.350943 | TASK [Generate bulk log download script]
2025-12-05 23:39:05.368361 | localhost | ok
2025-12-05 23:39:05.380658 | 
2025-12-05 23:39:05.380725 | TASK [local-log-download : Check API endpoint is defined]
2025-12-05 23:39:05.408625 | localhost | ok: All assertions passed
2025-12-05 23:39:05.413411 | 
2025-12-05 23:39:05.413471 | TASK [local-log-download : Create download script]
2025-12-05 23:39:05.795213 | localhost -> localhost | changed
2025-12-05 23:39:05.804583 | 
2025-12-05 23:39:05.804671 | TASK [Register quick-download link]
2025-12-05 23:39:05.822245 | localhost | ok
2025-12-05 23:39:05.863733 | 
2025-12-05 23:39:05.863840 | PLAY [logserver.rdoproject.org]
2025-12-05 23:39:05.874814 | 
2025-12-05 23:39:05.874877 | TASK [Set zuul-log-path fact]
2025-12-05 23:39:05.891274 | logserver.rdoproject.org | ok
2025-12-05 23:39:05.901191 | 
2025-12-05 23:39:05.901268 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 23:39:05.928888 | logserver.rdoproject.org | ok
2025-12-05 23:39:05.934472 | 
2025-12-05 23:39:05.934641 | TASK [upload-logs : Create log directories]
2025-12-05 23:39:06.583498 | logserver.rdoproject.org | changed
2025-12-05 23:39:06.586977 | 
2025-12-05 23:39:06.587068 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-05 23:39:06.877115 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009011
2025-12-05 23:39:06.881993 | 
2025-12-05 23:39:06.882087 | TASK [upload-logs : Upload logs to log server]
2025-12-05 23:39:07.524547 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-05 23:39:07.528123 | 
2025-12-05 23:39:07.528187 | LOOP [upload-logs : Compress console log and json output]
2025-12-05 23:39:07.567987 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 23:39:07.577739 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 23:39:07.586111 | 
2025-12-05 23:39:07.586224 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-05 23:39:07.645926 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 23:39:07.646191 | 
2025-12-05 23:39:07.651446 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 23:39:07.665496 | 
2025-12-05 23:39:07.665615 | LOOP [upload-logs : Upload console log and json output]