2025-10-14 06:49:54.693169 | Job console starting...
2025-10-14 06:49:54.704328 | Updating repositories
2025-10-14 06:49:54.730717 | Preparing job workspace
2025-10-14 06:49:58.931872 | Running Ansible setup...
2025-10-14 06:50:02.742977 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-14 06:50:03.328933 | 
2025-10-14 06:50:03.329058 | PLAY [localhost]
2025-10-14 06:50:03.338131 | 
2025-10-14 06:50:03.338224 | TASK [Gathering Facts]
2025-10-14 06:50:04.362942 | localhost | ok
2025-10-14 06:50:04.377867 | 
2025-10-14 06:50:04.377984 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-14 06:50:04.782243 | localhost -> localhost | changed
2025-10-14 06:50:04.794585 | 
2025-10-14 06:50:04.794812 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-14 06:50:05.630554 | localhost -> localhost | changed
2025-10-14 06:50:05.643712 | 
2025-10-14 06:50:05.643878 | TASK [Setup log path fact]
2025-10-14 06:50:05.665933 | localhost | ok
2025-10-14 06:50:05.684456 | 
2025-10-14 06:50:05.684614 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-14 06:50:05.715505 | localhost | ok
2025-10-14 06:50:05.726824 | 
2025-10-14 06:50:05.726971 | TASK [emit-job-header : Print job information]
2025-10-14 06:50:05.778423 | # Job Information
2025-10-14 06:50:05.778634 | Ansible Version: 2.15.12
2025-10-14 06:50:05.778670 | Job: cifmw-molecule-recognize_ssh_keypair
2025-10-14 06:50:05.778698 | Pipeline: github-check
2025-10-14 06:50:05.778750 | Executor: ze03.softwarefactory-project.io
2025-10-14 06:50:05.778785 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-14 06:50:05.778815 | Log URL (when completed): https://logserver.rdoproject.org/3a1/rdoproject.org/3a17ff270f2f4427bc420f6aee20dc83/
2025-10-14 06:50:05.778842 | Event ID: c940b7c0-a8c9-11f0-80da-b48bf6033ab5
2025-10-14 06:50:05.784838 | 
2025-10-14 06:50:05.784975 | LOOP [emit-job-header : Print node information]
2025-10-14 06:50:05.905133 | localhost | ok:
2025-10-14 06:50:05.905290 | localhost | # Node Information
2025-10-14 06:50:05.905320 | localhost | Inventory Hostname: controller
2025-10-14 06:50:05.905344 | localhost | Hostname: np0005486823
2025-10-14 06:50:05.905365 | localhost | Username: zuul
2025-10-14 06:50:05.905387 | localhost | Distro: CentOS 9
2025-10-14 06:50:05.905407 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-14 06:50:05.905425 | localhost | Region: RegionOne
2025-10-14 06:50:05.905443 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-14 06:50:05.905462 | localhost | Product Name: OpenStack Nova
2025-10-14 06:50:05.905480 | localhost | Interface IP: 38.102.83.238
2025-10-14 06:50:05.941078 | 
2025-10-14 06:50:05.941208 | PLAY [all]
2025-10-14 06:50:05.948822 | 
2025-10-14 06:50:05.948923 | TASK [Gather network facts]
2025-10-14 06:50:06.476375 | controller | ok
2025-10-14 06:50:06.518494 | 
2025-10-14 06:50:06.518635 | TASK [include_role : start-zuul-console]
2025-10-14 06:50:06.541599 | controller | ok
2025-10-14 06:50:06.558943 | 
2025-10-14 06:50:06.559086 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-14 06:50:06.967331 | controller | ok
2025-10-14 06:50:06.976565 | 
2025-10-14 06:50:06.976670 | TASK [include_role : add-build-sshkey]
2025-10-14 06:50:06.997129 | controller | ok
2025-10-14 06:50:07.011197 | 
2025-10-14 06:50:07.011322 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-14 06:50:07.275905 | controller -> localhost | ok
2025-10-14 06:50:07.289435 | 
2025-10-14 06:50:07.289841 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-14 06:50:07.316409 | controller | ok
2025-10-14 06:50:07.335522 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-14 06:50:07.344781 | 
2025-10-14 06:50:07.344912 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-14 06:50:08.262625 | controller -> localhost | Generating public/private rsa key pair.
2025-10-14 06:50:08.263053 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/3a17ff270f2f4427bc420f6aee20dc83_id_rsa.
2025-10-14 06:50:08.263120 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/3a17ff270f2f4427bc420f6aee20dc83_id_rsa.pub.
2025-10-14 06:50:08.263167 | controller -> localhost | The key fingerprint is:
2025-10-14 06:50:08.263208 | controller -> localhost | SHA256:zEpF7nSQ+qtYy4N0cGnY9Fe+8wcOqVIwWcoKtLoZ1wU zuul-build-sshkey
2025-10-14 06:50:08.263248 | controller -> localhost | The key's randomart image is:
2025-10-14 06:50:08.263286 | controller -> localhost | +---[RSA 3072]----+
2025-10-14 06:50:08.263323 | controller -> localhost | |        o.       |
2025-10-14 06:50:08.263362 | controller -> localhost | |    . Eo... .    |
2025-10-14 06:50:08.263399 | controller -> localhost | |   . = *++.o     |
2025-10-14 06:50:08.263437 | controller -> localhost | |    = **O.. .    |
2025-10-14 06:50:08.263474 | controller -> localhost | |   . *.+S+   o   |
2025-10-14 06:50:08.263511 | controller -> localhost | |  o o.+.. . = .  |
2025-10-14 06:50:08.263546 | controller -> localhost | |   * oo  o . = . |
2025-10-14 06:50:08.263582 | controller -> localhost | |  o .+..o .   o .|
2025-10-14 06:50:08.263618 | controller -> localhost | |    . +o .     . |
2025-10-14 06:50:08.263653 | controller -> localhost | +----[SHA256]-----+
2025-10-14 06:50:08.263919 | controller -> localhost | ok: Runtime: 0:00:00.403115
2025-10-14 06:50:08.276651 | 
2025-10-14 06:50:08.276822 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-14 06:50:08.303878 | controller | ok
2025-10-14 06:50:08.323638 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-14 06:50:08.335255 | 
2025-10-14 06:50:08.335344 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-14 06:50:08.360126 | controller | skipping: Conditional result was False
2025-10-14 06:50:08.369046 | 
2025-10-14 06:50:08.369164 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-14 06:50:08.851489 | controller | changed
2025-10-14 06:50:08.864974 | 
2025-10-14 06:50:08.865158 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-14 06:50:09.165311 | controller | ok
2025-10-14 06:50:09.180773 | 
2025-10-14 06:50:09.180965 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-14 06:50:10.121265 | controller | changed
2025-10-14 06:50:10.137201 | 
2025-10-14 06:50:10.137519 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-14 06:50:10.995245 | controller | changed
2025-10-14 06:50:11.006105 | 
2025-10-14 06:50:11.006227 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-14 06:50:11.033765 | controller | skipping: Conditional result was False
2025-10-14 06:50:11.046419 | 
2025-10-14 06:50:11.046555 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-14 06:50:11.461371 | controller -> localhost | changed
2025-10-14 06:50:11.471369 | 
2025-10-14 06:50:11.471432 | TASK [add-build-sshkey : Add back temp key]
2025-10-14 06:50:11.741080 | controller -> localhost | Identity added: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/3a17ff270f2f4427bc420f6aee20dc83_id_rsa (zuul-build-sshkey)
2025-10-14 06:50:11.741417 | controller -> localhost | ok: Runtime: 0:00:00.009581
2025-10-14 06:50:11.753362 | 
2025-10-14 06:50:11.753545 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-14 06:50:12.113486 | controller | ok
2025-10-14 06:50:12.123541 | 
2025-10-14 06:50:12.123667 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-14 06:50:12.150669 | controller | skipping: Conditional result was False
2025-10-14 06:50:12.172229 | 
2025-10-14 06:50:12.172380 | TASK [include_role : validate-host]
2025-10-14 06:50:12.195546 | controller | ok
2025-10-14 06:50:12.221342 | 
2025-10-14 06:50:12.221440 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-14 06:50:12.252373 | controller | ok
2025-10-14 06:50:12.258466 | 
2025-10-14 06:50:12.258549 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-14 06:50:12.507468 | controller -> localhost | ok
2025-10-14 06:50:12.513324 | 
2025-10-14 06:50:12.513419 | TASK [validate-host : Collect information about the host]
2025-10-14 06:50:13.309960 | controller | ok
2025-10-14 06:50:13.330199 | 
2025-10-14 06:50:13.330391 | TASK [validate-host : Sanitize hostname]
2025-10-14 06:50:13.410496 | controller | ok
2025-10-14 06:50:13.425878 | 
2025-10-14 06:50:13.426065 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-14 06:50:13.886866 | controller -> localhost | changed
2025-10-14 06:50:13.895427 | 
2025-10-14 06:50:13.895563 | TASK [validate-host : Collect information about zuul worker]
2025-10-14 06:50:14.295767 | controller | ok
2025-10-14 06:50:14.308857 | 
2025-10-14 06:50:14.309033 | TASK [validate-host : Write out all zuul information for each host]
2025-10-14 06:50:14.728667 | controller -> localhost | changed
2025-10-14 06:50:14.743285 | 
2025-10-14 06:50:14.743411 | TASK [include_role : prepare-workspace-openshift]
2025-10-14 06:50:14.759536 | controller | skipping: Conditional result was False
2025-10-14 06:50:14.767486 | 
2025-10-14 06:50:14.767607 | TASK [include_role : remove-zuul-sshkey]
2025-10-14 06:50:14.784132 | controller | skipping: Conditional result was False
2025-10-14 06:50:14.792549 | 
2025-10-14 06:50:14.793090 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-14 06:50:15.023951 | controller | ok: "logs"
2025-10-14 06:50:15.024220 | controller | ok: All items complete
2025-10-14 06:50:15.024248 | 
2025-10-14 06:50:15.261223 | controller | ok: "artifacts"
2025-10-14 06:50:15.503672 | controller | ok: "docs"
2025-10-14 06:50:15.513785 | 
2025-10-14 06:50:15.513899 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-14 06:50:15.813900 | controller | changed: "logs"
2025-10-14 06:50:16.025183 | controller | changed: "artifacts"
2025-10-14 06:50:16.245746 | controller | changed: "docs"
2025-10-14 06:50:16.295678 | 
2025-10-14 06:50:16.295886 | PLAY RECAP
2025-10-14 06:50:16.295969 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-14 06:50:16.296024 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-14 06:50:16.296063 | 
2025-10-14 06:50:16.422355 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-14 06:50:16.423167 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-14 06:50:17.063988 | 
2025-10-14 06:50:17.064103 | PLAY [localhost]
2025-10-14 06:50:17.083138 | 
2025-10-14 06:50:17.083308 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-14 06:50:17.461005 | localhost | ok
2025-10-14 06:50:17.467304 | 
2025-10-14 06:50:17.467405 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-14 06:50:18.138295 | localhost | changed
2025-10-14 06:50:18.158107 | 
2025-10-14 06:50:18.158180 | PLAY [all]
2025-10-14 06:50:18.173171 | 
2025-10-14 06:50:18.173240 | TASK [include_role : prepare-workspace]
2025-10-14 06:50:18.191390 | controller | ok
2025-10-14 06:50:18.205140 | 
2025-10-14 06:50:18.205235 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-14 06:50:18.586135 | controller | ok
2025-10-14 06:50:18.597044 | 
2025-10-14 06:50:18.597155 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-14 06:50:20.540254 | controller | Output suppressed because no_log was given
2025-10-14 06:50:20.564929 | 
2025-10-14 06:50:20.565073 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-14 06:50:20.857712 | controller | changed: "logs"
2025-10-14 06:50:21.088046 | controller | changed: "artifacts"
2025-10-14 06:50:21.302223 | controller | changed: "docs"
2025-10-14 06:50:21.311472 | 
2025-10-14 06:50:21.311632 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-14 06:50:21.582312 | controller | changed: "logs"
2025-10-14 06:50:21.582622 | controller | changed: All items complete
2025-10-14 06:50:21.582663 | 
2025-10-14 06:50:21.833286 | controller | changed: "artifacts"
2025-10-14 06:50:22.097776 | controller | changed: "docs"
2025-10-14 06:50:22.122771 | 
2025-10-14 06:50:22.122919 | TASK [Check if worker can sudo]
2025-10-14 06:50:22.664831 | controller | ok: Runtime: 0:00:00.061126
2025-10-14 06:50:22.673053 | 
2025-10-14 06:50:22.673180 | TASK [configure-mirrors : Gather needed facts]
2025-10-14 06:50:22.750110 | controller | skipping: Conditional result was False
2025-10-14 06:50:22.758940 | 
2025-10-14 06:50:22.759086 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-14 06:50:22.823351 | controller | ok
2025-10-14 06:50:22.834607 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-14 06:50:22.844007 | 
2025-10-14 06:50:22.844150 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-14 06:50:23.169939 | controller | ok
2025-10-14 06:50:23.180679 | 
2025-10-14 06:50:23.180952 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-14 06:50:23.257217 | controller | ok: "/var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-14 06:50:23.270154 | 
2025-10-14 06:50:23.270362 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-14 06:50:24.265126 | controller | changed
2025-10-14 06:50:24.272879 | 
2025-10-14 06:50:24.272974 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-14 06:50:24.359159 | controller | ok: "/var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-14 06:50:24.359389 | controller | ok: All items complete
2025-10-14 06:50:24.359419 | 
2025-10-14 06:50:24.409529 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-14 06:50:24.416033 | 
2025-10-14 06:50:24.416099 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-14 06:50:25.588259 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-14 06:50:26.680945 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-14 06:50:26.696894 | 
2025-10-14 06:50:26.697266 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-14 06:50:27.200566 | controller | changed: section and option added
2025-10-14 06:50:27.232672 | 
2025-10-14 06:50:27.232835 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-14 06:50:28.131184 | controller | 29 files removed
2025-10-14 06:50:28.131559 | controller | ok: Item: dnf clean all Runtime: 0:00:00.537121
2025-10-14 06:50:28.131647 | controller | changed: All items complete
2025-10-14 06:50:28.131697 | 
2025-10-14 06:50:39.020486 | 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-14 06:50:39.020672 | controller | DNF version: 4.14.0
2025-10-14 06:50:39.020983 | controller | cachedir: /var/cache/dnf
2025-10-14 06:50:39.021051 | controller | Making cache files for all metadata files.
2025-10-14 06:50:39.021113 | controller | baseos: has expired and will be refreshed.
2025-10-14 06:50:39.021170 | controller | appstream: has expired and will be refreshed.
2025-10-14 06:50:39.021214 | controller | crb: has expired and will be refreshed.
2025-10-14 06:50:39.021267 | controller | extras-common: has expired and will be refreshed.
2025-10-14 06:50:39.021306 | controller | repo: downloading from remote: baseos
2025-10-14 06:50:39.021342 | controller | CentOS Stream 9 - BaseOS                         81 MB/s | 8.8 MB     00:00
2025-10-14 06:50:39.021380 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-14 06:50:39.021416 | controller | repo: downloading from remote: appstream
2025-10-14 06:50:39.021452 | controller | CentOS Stream 9 - AppStream                     100 MB/s |  25 MB     00:00
2025-10-14 06:50:39.021488 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-14 06:50:39.021523 | controller | repo: downloading from remote: crb
2025-10-14 06:50:39.021558 | controller | CentOS Stream 9 - CRB                            95 MB/s | 7.2 MB     00:00
2025-10-14 06:50:39.021595 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-14 06:50:39.021631 | controller | repo: downloading from remote: extras-common
2025-10-14 06:50:39.021667 | controller | CentOS Stream 9 - Extras packages               951 kB/s |  20 kB     00:00
2025-10-14 06:50:39.021703 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-14 06:50:39.021787 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-14 06:50:39.021830 | controller | Completion plugin: Generating completion cache...
2025-10-14 06:50:39.021866 | controller | Metadata cache created.
2025-10-14 06:50:39.021927 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.571613
2025-10-14 06:50:39.054970 | 
2025-10-14 06:50:39.055141 | PLAY RECAP
2025-10-14 06:50:39.055228 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-14 06:50:39.055286 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-14 06:50:39.055326 | 
2025-10-14 06:50:39.193594 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-14 06:50:39.195361 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-14 06:50:39.774623 | 
2025-10-14 06:50:39.774758 | PLAY [all]
2025-10-14 06:50:39.795907 | 
2025-10-14 06:50:39.795999 | TASK [Install binary dependencies]
2025-10-14 06:50:39.882673 | controller | ok
2025-10-14 06:50:39.926178 | 
2025-10-14 06:50:39.926388 | TASK [bindep : Include find tasks]
2025-10-14 06:50:39.976281 | controller | ok
2025-10-14 06:50:39.996232 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-14 06:50:40.007445 | 
2025-10-14 06:50:40.007615 | TASK [bindep : Look for bindep.txt]
2025-10-14 06:50:40.518232 | controller | ok
2025-10-14 06:50:40.537932 | 
2025-10-14 06:50:40.538175 | TASK [bindep : Define bindep_file fact]
2025-10-14 06:50:40.572865 | controller | ok
2025-10-14 06:50:40.580377 | 
2025-10-14 06:50:40.580519 | TASK [bindep : Look for other-requirements.txt]
2025-10-14 06:50:40.596055 | controller | skipping: Conditional result was False
2025-10-14 06:50:40.605316 | 
2025-10-14 06:50:40.605606 | TASK [bindep : Define bindep_file fact]
2025-10-14 06:50:40.631663 | controller | skipping: Conditional result was False
2025-10-14 06:50:40.640100 | 
2025-10-14 06:50:40.640264 | TASK [bindep : Look for bindep fallback file]
2025-10-14 06:50:40.669555 | controller | skipping: Conditional result was False
2025-10-14 06:50:40.675605 | 
2025-10-14 06:50:40.675685 | TASK [bindep : Define bindep_file fact]
2025-10-14 06:50:40.709777 | controller | skipping: Conditional result was False
2025-10-14 06:50:40.715842 | 
2025-10-14 06:50:40.715908 | TASK [bindep : Include bindep tasks]
2025-10-14 06:50:40.763202 | controller | ok
2025-10-14 06:50:40.777209 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-14 06:50:40.789230 | 
2025-10-14 06:50:40.789326 | TASK [bindep : Look for bindep command]
2025-10-14 06:50:40.815842 | controller | skipping: Conditional result was False
2025-10-14 06:50:40.822642 | 
2025-10-14 06:50:40.822716 | TASK [bindep : Check for system bindep]
2025-10-14 06:50:41.358036 | controller | ok: Runtime: 0:00:00.009321
2025-10-14 06:50:41.374911 | 
2025-10-14 06:50:41.375080 | TASK [bindep : Define bindep_command fact]
2025-10-14 06:50:41.425224 | controller | skipping: Conditional result was False
2025-10-14 06:50:41.433413 | 
2025-10-14 06:50:41.433520 | TASK [bindep : Include install tasks]
2025-10-14 06:50:41.469422 | controller | ok
2025-10-14 06:50:41.484431 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-14 06:50:41.496766 | 
2025-10-14 06:50:41.496873 | TASK [bindep : Create temp dir for bindep]
2025-10-14 06:50:41.909514 | controller | changed
2025-10-14 06:50:41.921786 | 
2025-10-14 06:50:41.921921 | TASK [Ensure we have pip dependencies]
2025-10-14 06:50:41.952887 | controller | ok
2025-10-14 06:50:41.989266 | 
2025-10-14 06:50:41.989391 | TASK [ensure-pip : Check if pip is installed]
2025-10-14 02:50:42.321399 | controller | /usr/bin/pip3
2025-10-14 02:50:42.341586 | controller | /usr/bin/python3: No module named wheel
2025-10-14 06:50:42.535797 | controller | ok: Runtime: 0:00:00.030484
2025-10-14 06:50:42.541667 | 
2025-10-14 06:50:42.541941 | LOOP [ensure-pip : Install pip from packages]
2025-10-14 06:50:42.581847 | controller | ok: "/var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-14 06:50:42.595518 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-14 06:50:42.607667 | 
2025-10-14 06:50:42.607807 | TASK [ensure-pip : Install Python 3 pip]
2025-10-14 06:50:45.044355 | controller | changed
2025-10-14 06:50:45.070648 | 
2025-10-14 06:50:45.071059 | TASK [ensure-pip : Check for EPEL repository]
2025-10-14 06:50:45.150157 | controller | skipping: Conditional result was False
2025-10-14 06:50:45.159245 | 
2025-10-14 06:50:45.159372 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-14 06:50:45.206285 | controller | skipping: Conditional result was False
2025-10-14 06:50:45.219293 | 
2025-10-14 06:50:45.219475 | TASK [ensure-pip : Install Python 2 pip]
2025-10-14 06:50:45.257233 | controller | skipping: Conditional result was False
2025-10-14 06:50:45.271316 | 
2025-10-14 06:50:45.271499 | TASK [ensure-pip : Ensure setuptools]
2025-10-14 06:50:45.289046 | controller | skipping: Conditional result was False
2025-10-14 06:50:45.298287 | 
2025-10-14 06:50:45.298413 | TASK [ensure-pip : Check for ensurepip module]
2025-10-14 06:50:45.838060 | controller | skipping: Conditional result was False
2025-10-14 06:50:45.855680 | 
2025-10-14 06:50:45.855905 | TASK [ensure-pip : Ensure python3-venv]
2025-10-14 06:50:45.892442 | controller | skipping: Conditional result was False
2025-10-14 06:50:45.906362 | 
2025-10-14 06:50:45.906578 | TASK [ensure-pip : Install pip from source]
2025-10-14 06:50:45.925379 | controller | skipping: Conditional result was False
2025-10-14 06:50:45.940895 | 
2025-10-14 06:50:45.941094 | TASK [ensure-pip : Probe for venv python full path]
2025-10-14 02:50:46.225468 | controller | /usr/bin/python3
2025-10-14 06:50:46.486262 | controller | ok: Runtime: 0:00:00.004871
2025-10-14 06:50:46.511607 | 
2025-10-14 06:50:46.511848 | TASK [ensure-pip : Set host default]
2025-10-14 06:50:46.586635 | controller | ok
2025-10-14 06:50:46.594335 | 
2025-10-14 06:50:46.594450 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-14 06:50:46.656689 | controller | ok
2025-10-14 06:50:46.674452 | 
2025-10-14 06:50:46.674593 | TASK [bindep : Install bindep into temporary venv]
2025-10-14 06:50:51.111041 | controller | changed
2025-10-14 06:50:51.116923 | 
2025-10-14 06:50:51.116990 | TASK [bindep : Define bindep_command]
2025-10-14 06:50:51.147770 | controller | ok
2025-10-14 06:50:51.154497 | 
2025-10-14 06:50:51.154623 | LOOP [bindep : Include package tasks]
2025-10-14 06:50:51.215875 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-14 06:50:51.216048 | controller | ok: All items complete
2025-10-14 06:50:51.216074 | 
2025-10-14 06:50:51.233995 | controller | included: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-14 06:50:51.249563 | 
2025-10-14 06:50:51.249716 | TASK [bindep : Define bindep_run fact]
2025-10-14 06:50:51.282641 | controller | ok
2025-10-14 06:50:51.291819 | 
2025-10-14 06:50:51.291955 | TASK [bindep : Get list of packages to install from bindep]
2025-10-14 02:50:53.019761 | controller | podman
2025-10-14 02:50:53.054132 | controller | python3-jmespath
2025-10-14 02:50:53.054351 | controller | python3-libvirt
2025-10-14 02:50:53.054364 | controller | python3-lxml
2025-10-14 02:50:53.054371 | controller | python3-netaddr
2025-10-14 06:50:53.340316 | controller | ok: Runtime: 0:00:01.460884
2025-10-14 06:50:53.346307 | 
2025-10-14 06:50:53.346402 | TASK [bindep : Install distro packages from bindep]
2025-10-14 06:52:00.046712 | controller | changed
2025-10-14 06:52:00.054156 | 
2025-10-14 06:52:00.054308 | TASK [bindep : Check that packages are installed]
2025-10-14 06:52:02.086349 | controller | ok: Runtime: 0:00:01.398981
2025-10-14 06:52:02.092761 | 
2025-10-14 06:52:02.092860 | TASK [bindep : Fail if we cannot install all packages]
2025-10-14 06:52:02.157900 | controller | skipping: Conditional result was False
2025-10-14 06:52:02.173330 | 
2025-10-14 06:52:02.173445 | TASK [Run test-setup role]
2025-10-14 06:52:02.193515 | controller | ok
2025-10-14 06:52:02.209850 | 
2025-10-14 06:52:02.209968 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-14 06:52:02.473971 | controller | ok
2025-10-14 06:52:02.478963 | 
2025-10-14 06:52:02.479025 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-14 06:52:03.010760 | controller | skipping: Conditional result was False
2025-10-14 06:52:03.032295 | 
2025-10-14 06:52:03.032403 | TASK [bindep : Remove bindep temp dir]
2025-10-14 06:52:03.442588 | controller | ok
2025-10-14 06:52:03.462428 | 
2025-10-14 06:52:03.462491 | PLAY RECAP
2025-10-14 06:52:03.462532 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-14 06:52:03.462553 | 
2025-10-14 06:52:03.644514 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-14 06:52:03.645675 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-14 06:52:04.245264 | 
2025-10-14 06:52:04.245373 | PLAY [all]
2025-10-14 06:52:04.265090 | 
2025-10-14 06:52:04.265207 | TASK [Abort when test_command variable is undefined]
2025-10-14 06:52:04.309869 | controller | skipping: Conditional result was False
2025-10-14 06:52:04.315704 | 
2025-10-14 06:52:04.315836 | TASK [Convert test_command to list]
2025-10-14 06:52:04.359913 | controller | skipping: Conditional result was False
2025-10-14 06:52:04.366336 | 
2025-10-14 06:52:04.366415 | TASK [Use test_command list]
2025-10-14 06:52:04.415301 | controller | ok
2025-10-14 06:52:04.423787 | 
2025-10-14 06:52:04.423897 | LOOP [Run test_command]
2025-10-14 06:52:04.834155 | controller | no check to run
2025-10-14 06:52:04.834477 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005774
2025-10-14 06:52:04.874251 | 
2025-10-14 06:52:04.874511 | PLAY RECAP
2025-10-14 06:52:04.874568 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-14 06:52:04.874591 | 
2025-10-14 06:52:04.976973 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-14 06:52:04.980220 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-14 06:52:05.542476 | 
2025-10-14 06:52:05.542591 | PLAY [all]
2025-10-14 06:52:05.566252 | 
2025-10-14 06:52:05.566379 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-14 06:52:05.964220 | controller | changed: non-zero return code
2025-10-14 06:52:05.973867 | 
2025-10-14 06:52:05.974252 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-14 06:52:06.002547 | controller | skipping: Conditional result was False
2025-10-14 06:52:06.011827 | 
2025-10-14 06:52:06.012109 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-14 06:52:06.046486 | 
2025-10-14 06:52:06.046679 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-14 06:52:06.080537 | 
2025-10-14 06:52:06.080752 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-14 06:52:06.103003 | controller | skipping: Conditional result was False
2025-10-14 06:52:06.111813 | 
2025-10-14 06:52:06.111919 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-14 06:52:06.132636 | 
2025-10-14 06:52:06.132827 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-14 06:52:06.145884 | controller | skipping: Conditional result was False
2025-10-14 06:52:06.151311 | 
2025-10-14 06:52:06.151383 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-14 06:52:06.174541 | controller | skipping: Conditional result was False
2025-10-14 06:52:06.180090 | 
2025-10-14 06:52:06.180155 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-14 06:52:06.193084 | controller | skipping: Conditional result was False
2025-10-14 06:52:06.217548 | 
2025-10-14 06:52:06.217628 | PLAY RECAP
2025-10-14 06:52:06.217671 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-14 06:52:06.217690 | 
2025-10-14 06:52:06.309721 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-14 06:52:06.310565 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-14 06:52:06.875461 | 
2025-10-14 06:52:06.875564 | PLAY [all]
2025-10-14 06:52:06.894812 | 
2025-10-14 06:52:06.894918 | TASK [include_role : fetch-output]
2025-10-14 06:52:06.924346 | controller | ok
2025-10-14 06:52:06.941834 | 
2025-10-14 06:52:06.941930 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-14 06:52:06.986056 | controller | skipping: Conditional result was False
2025-10-14 06:52:06.992250 | 
2025-10-14 06:52:06.992323 | TASK [fetch-output : Set log path for single node]
2025-10-14 06:52:07.030878 | controller | ok
2025-10-14 06:52:07.035867 | 
2025-10-14 06:52:07.035937 | LOOP [fetch-output : Ensure local output dirs]
2025-10-14 06:52:07.447914 | controller -> localhost | ok: "/var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/logs"
2025-10-14 06:52:07.650468 | controller -> localhost | changed: "/var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/artifacts"
2025-10-14 06:52:07.854061 | controller -> localhost | changed: "/var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/docs"
2025-10-14 06:52:07.868933 | 
2025-10-14 06:52:07.869081 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-14 06:52:08.585452 | controller | changed: .d..t...... ./
2025-10-14 06:52:08.585637 | controller | changed: All items complete
2025-10-14 06:52:08.585665 | 
2025-10-14 06:52:09.152634 | controller | changed: .d..t...... ./
2025-10-14 06:52:09.649644 | controller | changed: .d..t...... ./
2025-10-14 06:52:09.670147 | 
2025-10-14 06:52:09.670245 | TASK [include_role : fetch-output-openshift]
2025-10-14 06:52:09.704870 | controller | skipping: Conditional result was False
2025-10-14 06:52:09.713468 | 
2025-10-14 06:52:09.713594 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-14 06:52:10.181991 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.011707
2025-10-14 06:52:10.414996 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012172
2025-10-14 06:52:10.449177 | 
2025-10-14 06:52:10.449265 | PLAY [all]
2025-10-14 06:52:10.463374 | 
2025-10-14 06:52:10.463470 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-14 06:52:10.996371 | controller | changed
2025-10-14 06:52:11.024299 | 
2025-10-14 06:52:11.024368 | PLAY RECAP
2025-10-14 06:52:11.024442 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-14 06:52:11.024467 | 
2025-10-14 06:52:11.133760 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-14 06:52:11.135269 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-14 06:52:11.842934 | 
2025-10-14 06:52:11.843067 | PLAY [localhost]
2025-10-14 06:52:11.862614 | 
2025-10-14 06:52:11.862773 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-14 06:52:12.248661 | localhost | changed
2025-10-14 06:52:12.253888 | 
2025-10-14 06:52:12.254020 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-14 06:52:12.282841 | localhost | ok
2025-10-14 06:52:12.291291 | 
2025-10-14 06:52:12.291388 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-14 06:52:12.728538 | localhost | changed
2025-10-14 06:52:12.734387 | 
2025-10-14 06:52:12.734461 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-14 06:52:13.459249 | localhost | changed
2025-10-14 06:52:13.465080 | 
2025-10-14 06:52:13.465155 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-14 06:52:14.010578 | localhost | Identity added: /var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/tmp/ansible.yko1wins (/var/lib/zuul/builds/3a17ff270f2f4427bc420f6aee20dc83/work/tmp/ansible.yko1wins)
2025-10-14 06:52:14.010841 | localhost | ok: Runtime: 0:00:00.013641
2025-10-14 06:52:14.016899 | 
2025-10-14 06:52:14.017005 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-14 06:52:14.278768 | localhost | ok: Runtime: 0:00:00.006478
2025-10-14 06:52:14.283476 | 
2025-10-14 06:52:14.283536 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-14 06:52:14.352920 | localhost | changed
2025-10-14 06:52:14.356975 | 
2025-10-14 06:52:14.357038 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-14 06:52:14.904623 | localhost | changed
2025-10-14 06:52:14.944685 | 
2025-10-14 06:52:14.944843 | PLAY [localhost]
2025-10-14 06:52:14.964536 | 
2025-10-14 06:52:14.964657 | TASK [Generate bulk log download script]
2025-10-14 06:52:14.989484 | localhost | ok
2025-10-14 06:52:15.002834 | 
2025-10-14 06:52:15.003013 | TASK [local-log-download : Check API endpoint is defined]
2025-10-14 06:52:15.042878 | localhost | ok: All assertions passed
2025-10-14 06:52:15.048001 | 
2025-10-14 06:52:15.048070 | TASK [local-log-download : Create download script]
2025-10-14 06:52:15.545043 | localhost -> localhost | changed
2025-10-14 06:52:15.556460 | 
2025-10-14 06:52:15.556527 | TASK [Register quick-download link]
2025-10-14 06:52:15.587012 | localhost | ok
2025-10-14 06:52:15.627521 | 
2025-10-14 06:52:15.627622 | PLAY [logserver.rdoproject.org]
2025-10-14 06:52:15.637455 | 
2025-10-14 06:52:15.637519 | TASK [Set zuul-log-path fact]
2025-10-14 06:52:15.657718 | logserver.rdoproject.org | ok
2025-10-14 06:52:15.672039 | 
2025-10-14 06:52:15.672150 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-14 06:52:15.708835 | logserver.rdoproject.org | ok
2025-10-14 06:52:15.715233 | 
2025-10-14 06:52:15.715296 | TASK [upload-logs : Create log directories]
2025-10-14 06:52:16.417027 | logserver.rdoproject.org | changed
2025-10-14 06:52:16.421360 | 
2025-10-14 06:52:16.421447 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-14 06:52:16.692604 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005392
2025-10-14 06:52:16.707482 | 
2025-10-14 06:52:16.707688 | TASK [upload-logs : Upload logs to log server]
2025-10-14 06:52:17.474710 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-14 06:52:17.477665 | 
2025-10-14 06:52:17.477745 | LOOP [upload-logs : Compress console log and json output]
2025-10-14 06:52:17.546137 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 06:52:17.553913 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 06:52:17.560680 | 
2025-10-14 06:52:17.560826 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-14 06:52:17.630838 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 06:52:17.631101 | 
2025-10-14 06:52:17.634785 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 06:52:17.645566 | 
2025-10-14 06:52:17.645683 | LOOP [upload-logs : Upload console log and json output]