2025-10-02 14:13:09.045451 | Job console starting...
2025-10-02 14:13:09.065910 | Updating repositories
2025-10-02 14:13:09.094071 | Preparing job workspace
2025-10-02 14:13:13.760167 | Running Ansible setup...
2025-10-02 14:13:19.788027 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-02 14:13:20.650057 | 
2025-10-02 14:13:20.650194 | PLAY [localhost]
2025-10-02 14:13:20.692506 | 
2025-10-02 14:13:20.692643 | TASK [Gathering Facts]
2025-10-02 14:13:21.715714 | localhost | ok
2025-10-02 14:13:21.739330 | 
2025-10-02 14:13:21.739532 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-02 14:13:22.163254 | localhost -> localhost | changed
2025-10-02 14:13:22.169081 | 
2025-10-02 14:13:22.169167 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-02 14:13:23.092979 | localhost -> localhost | changed
2025-10-02 14:13:23.102864 | 
2025-10-02 14:13:23.102964 | TASK [Setup log path fact]
2025-10-02 14:13:23.128597 | localhost | ok
2025-10-02 14:13:23.141156 | 
2025-10-02 14:13:23.141243 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 14:13:23.169151 | localhost | ok
2025-10-02 14:13:23.177313 | 
2025-10-02 14:13:23.177401 | TASK [emit-job-header : Print job information]
2025-10-02 14:13:23.206660 | # Job Information
2025-10-02 14:13:23.206946 | Ansible Version: 2.15.12
2025-10-02 14:13:23.206975 | Job: cifmw-molecule-polarion
2025-10-02 14:13:23.206994 | Pipeline: github-check
2025-10-02 14:13:23.207012 | Executor: ze03.softwarefactory-project.io
2025-10-02 14:13:23.207030 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-02 14:13:23.207048 | Log URL (when completed): https://logserver.rdoproject.org/7b0/rdoproject.org/7b065c964f3242ef8eeab82e02357d3d/
2025-10-02 14:13:23.207066 | Event ID: be9565c0-9f99-11f0-9e8d-1085adf9bc04
2025-10-02 14:13:23.211383 | 
2025-10-02 14:13:23.211461 | LOOP [emit-job-header : Print node information]
2025-10-02 14:13:23.305856 | localhost | ok:
2025-10-02 14:13:23.306075 | localhost | # Node Information
2025-10-02 14:13:23.306102 | localhost | Inventory Hostname: controller
2025-10-02 14:13:23.306123 | localhost | Hostname: np0005466333
2025-10-02 14:13:23.306142 | localhost | Username: zuul
2025-10-02 14:13:23.306161 | localhost | Distro: CentOS 9
2025-10-02 14:13:23.306179 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-02 14:13:23.306195 | localhost | Region: RegionOne
2025-10-02 14:13:23.306211 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-02 14:13:23.306227 | localhost | Product Name: OpenStack Nova
2025-10-02 14:13:23.306243 | localhost | Interface IP: 38.102.83.177
2025-10-02 14:13:23.332433 | 
2025-10-02 14:13:23.332558 | PLAY [all]
2025-10-02 14:13:23.340609 | 
2025-10-02 14:13:23.340703 | TASK [Gather network facts]
2025-10-02 14:13:23.908673 | controller | ok
2025-10-02 14:13:23.928629 | 
2025-10-02 14:13:23.928814 | TASK [include_role : start-zuul-console]
2025-10-02 14:13:23.957651 | controller | ok
2025-10-02 14:13:23.980078 | 
2025-10-02 14:13:23.980188 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-02 14:13:24.405152 | controller | ok
2025-10-02 14:13:24.413821 | 
2025-10-02 14:13:24.413903 | TASK [include_role : add-build-sshkey]
2025-10-02 14:13:24.455061 | controller | ok
2025-10-02 14:13:24.481001 | 
2025-10-02 14:13:24.481205 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-02 14:13:24.973315 | controller -> localhost | ok
2025-10-02 14:13:25.038555 | 
2025-10-02 14:13:25.038673 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-02 14:13:25.174122 | controller | ok
2025-10-02 14:13:25.227285 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-02 14:13:25.233687 | 
2025-10-02 14:13:25.233836 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-02 14:13:27.356753 | controller -> localhost | Generating public/private rsa key pair.
2025-10-02 14:13:27.356984 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/7b065c964f3242ef8eeab82e02357d3d_id_rsa.
2025-10-02 14:13:27.357017 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/7b065c964f3242ef8eeab82e02357d3d_id_rsa.pub.
2025-10-02 14:13:27.357040 | controller -> localhost | The key fingerprint is:
2025-10-02 14:13:27.357061 | controller -> localhost | SHA256:6lGtAUwtYQTGEt4o5p0z7LKdY3WBsfYOKdBsOhNrvpw zuul-build-sshkey
2025-10-02 14:13:27.357082 | controller -> localhost | The key's randomart image is:
2025-10-02 14:13:27.357101 | controller -> localhost | +---[RSA 3072]----+
2025-10-02 14:13:27.357120 | controller -> localhost | |  .ooo=o         |
2025-10-02 14:13:27.357144 | controller -> localhost | | ..+.=. .        |
2025-10-02 14:13:27.357171 | controller -> localhost | |..=.. *.         |
2025-10-02 14:13:27.357200 | controller -> localhost | |o+o+.+ o .       |
2025-10-02 14:13:27.357223 | controller -> localhost | | .**. o S .      |
2025-10-02 14:13:27.357242 | controller -> localhost | | *..o+ = o       |
2025-10-02 14:13:27.357260 | controller -> localhost | |o.o.o * .        |
2025-10-02 14:13:27.357278 | controller -> localhost | |..=o.. o         |
2025-10-02 14:13:27.357295 | controller -> localhost | | Eoo. .          |
2025-10-02 14:13:27.357313 | controller -> localhost | +----[SHA256]-----+
2025-10-02 14:13:27.357357 | controller -> localhost | ok: Runtime: 0:00:00.412744
2025-10-02 14:13:27.364192 | 
2025-10-02 14:13:27.364267 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-02 14:13:27.411775 | controller | ok
2025-10-02 14:13:27.425869 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-02 14:13:27.436790 | 
2025-10-02 14:13:27.436892 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-02 14:13:27.496905 | controller | skipping: Conditional result was False
2025-10-02 14:13:27.504990 | 
2025-10-02 14:13:27.505106 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-02 14:13:28.113778 | controller | changed
2025-10-02 14:13:28.125648 | 
2025-10-02 14:13:28.125715 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-02 14:13:28.474801 | controller | ok
2025-10-02 14:13:28.481930 | 
2025-10-02 14:13:28.481998 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-02 14:13:29.560702 | controller | changed
2025-10-02 14:13:29.566559 | 
2025-10-02 14:13:29.566634 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-02 14:13:30.497898 | controller | changed
2025-10-02 14:13:30.509355 | 
2025-10-02 14:13:30.509474 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-02 14:13:30.557996 | controller | skipping: Conditional result was False
2025-10-02 14:13:30.564103 | 
2025-10-02 14:13:30.564178 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-02 14:13:30.997946 | controller -> localhost | changed
2025-10-02 14:13:31.009040 | 
2025-10-02 14:13:31.009179 | TASK [add-build-sshkey : Add back temp key]
2025-10-02 14:13:31.361743 | controller -> localhost | Identity added: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/7b065c964f3242ef8eeab82e02357d3d_id_rsa (zuul-build-sshkey)
2025-10-02 14:13:31.362002 | controller -> localhost | ok: Runtime: 0:00:00.014271
2025-10-02 14:13:31.368260 | 
2025-10-02 14:13:31.368323 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-02 14:13:31.770042 | controller | ok
2025-10-02 14:13:31.779858 | 
2025-10-02 14:13:31.779949 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-02 14:13:31.827977 | controller | skipping: Conditional result was False
2025-10-02 14:13:31.851423 | 
2025-10-02 14:13:31.851545 | TASK [include_role : validate-host]
2025-10-02 14:13:31.881953 | controller | ok
2025-10-02 14:13:31.957376 | 
2025-10-02 14:13:31.957494 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-02 14:13:31.997049 | controller | ok
2025-10-02 14:13:32.001982 | 
2025-10-02 14:13:32.002049 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-02 14:13:32.295362 | controller -> localhost | ok
2025-10-02 14:13:32.304566 | 
2025-10-02 14:13:32.304681 | TASK [validate-host : Collect information about the host]
2025-10-02 14:13:33.106637 | controller | ok
2025-10-02 14:13:33.131044 | 
2025-10-02 14:13:33.131169 | TASK [validate-host : Sanitize hostname]
2025-10-02 14:13:33.201845 | controller | ok
2025-10-02 14:13:33.212655 | 
2025-10-02 14:13:33.212800 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-02 14:13:33.838479 | controller -> localhost | changed
2025-10-02 14:13:33.844129 | 
2025-10-02 14:13:33.844195 | TASK [validate-host : Collect information about zuul worker]
2025-10-02 14:13:34.277363 | controller | ok
2025-10-02 14:13:34.288453 | 
2025-10-02 14:13:34.288562 | TASK [validate-host : Write out all zuul information for each host]
2025-10-02 14:13:34.901071 | controller -> localhost | changed
2025-10-02 14:13:34.915903 | 
2025-10-02 14:13:34.916014 | TASK [include_role : prepare-workspace-openshift]
2025-10-02 14:13:34.947382 | controller | skipping: Conditional result was False
2025-10-02 14:13:34.953180 | 
2025-10-02 14:13:34.953255 | TASK [include_role : remove-zuul-sshkey]
2025-10-02 14:13:34.990321 | controller | skipping: Conditional result was False
2025-10-02 14:13:35.000949 | 
2025-10-02 14:13:35.001088 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-02 14:13:35.306129 | controller | ok: "logs"
2025-10-02 14:13:35.306365 | controller | ok: All items complete
2025-10-02 14:13:35.306393 | 
2025-10-02 14:13:35.540616 | controller | ok: "artifacts"
2025-10-02 14:13:35.766491 | controller | ok: "docs"
2025-10-02 14:13:35.776132 | 
2025-10-02 14:13:35.776245 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-02 14:13:36.051101 | controller | changed: "logs"
2025-10-02 14:13:36.298439 | controller | changed: "artifacts"
2025-10-02 14:13:36.542238 | controller | changed: "docs"
2025-10-02 14:13:36.594831 | 
2025-10-02 14:13:36.594931 | PLAY RECAP
2025-10-02 14:13:36.594975 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-02 14:13:36.595003 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-02 14:13:36.595023 | 
2025-10-02 14:13:36.742980 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-02 14:13:36.744697 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-02 14:13:37.849079 | 
2025-10-02 14:13:37.849219 | PLAY [localhost]
2025-10-02 14:13:37.868297 | 
2025-10-02 14:13:37.868469 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-02 14:13:38.463783 | localhost | ok
2025-10-02 14:13:38.475194 | 
2025-10-02 14:13:38.475376 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-02 14:13:39.408585 | localhost | changed
2025-10-02 14:13:39.479383 | 
2025-10-02 14:13:39.479507 | PLAY [all]
2025-10-02 14:13:39.554700 | 
2025-10-02 14:13:39.554836 | TASK [include_role : prepare-workspace]
2025-10-02 14:13:39.585058 | controller | ok
2025-10-02 14:13:39.608756 | 
2025-10-02 14:13:39.608903 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-02 14:13:39.998702 | controller | ok
2025-10-02 14:13:40.005829 | 
2025-10-02 14:13:40.005925 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-02 14:13:42.494551 | controller | Output suppressed because no_log was given
2025-10-02 14:13:42.506411 | 
2025-10-02 14:13:42.506491 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-02 14:13:42.850033 | controller | changed: "logs"
2025-10-02 14:13:43.106563 | controller | changed: "artifacts"
2025-10-02 14:13:43.377686 | controller | changed: "docs"
2025-10-02 14:13:43.394269 | 
2025-10-02 14:13:43.394372 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-02 14:13:43.721250 | controller | changed: "logs"
2025-10-02 14:13:43.721503 | controller | changed: All items complete
2025-10-02 14:13:43.721536 | 
2025-10-02 14:13:43.988844 | controller | changed: "artifacts"
2025-10-02 14:13:44.267713 | controller | changed: "docs"
2025-10-02 14:13:44.284817 | 
2025-10-02 14:13:44.284924 | TASK [Check if worker can sudo]
2025-10-02 14:13:44.893506 | controller | ok: Runtime: 0:00:00.065637
2025-10-02 14:13:44.905422 | 
2025-10-02 14:13:44.905498 | TASK [configure-mirrors : Gather needed facts]
2025-10-02 14:13:45.061533 | controller | skipping: Conditional result was False
2025-10-02 14:13:45.067600 | 
2025-10-02 14:13:45.067667 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-02 14:13:45.281407 | controller | ok
2025-10-02 14:13:45.400354 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-02 14:13:45.415123 | 
2025-10-02 14:13:45.415257 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-02 14:13:45.759516 | controller | ok
2025-10-02 14:13:45.768239 | 
2025-10-02 14:13:45.768332 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-02 14:13:45.862849 | controller | ok: "/var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-02 14:13:45.871830 | 
2025-10-02 14:13:45.871961 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-02 14:13:47.015368 | controller | changed
2025-10-02 14:13:47.029926 | 
2025-10-02 14:13:47.030052 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-02 14:13:47.168769 | controller | ok: "/var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-02 14:13:47.168931 | controller | ok: All items complete
2025-10-02 14:13:47.168958 | 
2025-10-02 14:13:47.288100 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-02 14:13:47.321233 | 
2025-10-02 14:13:47.321363 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-02 14:13:48.620970 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-02 14:13:49.617664 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-02 14:13:49.636467 | 
2025-10-02 14:13:49.636607 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-02 14:13:50.171022 | controller | changed: section and option added
2025-10-02 14:13:50.210737 | 
2025-10-02 14:13:50.210870 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-02 14:13:51.969155 | controller | 29 files removed
2025-10-02 14:13:51.971756 | controller | ok: Item: dnf clean all Runtime: 0:00:01.384743
2025-10-02 14:13:51.971837 | controller | changed: All items complete
2025-10-02 14:13:51.971862 | 
2025-10-02 14:14:02.977777 | 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-02 14:14:02.977905 | controller | DNF version: 4.14.0
2025-10-02 14:14:02.977945 | controller | cachedir: /var/cache/dnf
2025-10-02 14:14:02.977973 | controller | Making cache files for all metadata files.
2025-10-02 14:14:02.978000 | controller | baseos: has expired and will be refreshed.
2025-10-02 14:14:02.978024 | controller | appstream: has expired and will be refreshed.
2025-10-02 14:14:02.978048 | controller | crb: has expired and will be refreshed.
2025-10-02 14:14:02.978082 | controller | extras-common: has expired and will be refreshed.
2025-10-02 14:14:02.978106 | controller | repo: downloading from remote: baseos
2025-10-02 14:14:02.978130 | controller | CentOS Stream 9 - BaseOS                         54 MB/s | 8.8 MB     00:00
2025-10-02 14:14:02.978155 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-02 14:14:02.978179 | controller | repo: downloading from remote: appstream
2025-10-02 14:14:02.978202 | controller | CentOS Stream 9 - AppStream                     115 MB/s |  25 MB     00:00
2025-10-02 14:14:02.978227 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-02 14:14:02.978250 | controller | repo: downloading from remote: crb
2025-10-02 14:14:02.978276 | controller | CentOS Stream 9 - CRB                            81 MB/s | 7.1 MB     00:00
2025-10-02 14:14:02.978303 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-02 14:14:02.978327 | controller | repo: downloading from remote: extras-common
2025-10-02 14:14:02.978351 | controller | CentOS Stream 9 - Extras packages               1.0 MB/s |  20 kB     00:00
2025-10-02 14:14:02.978374 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-02 14:14:02.978398 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-02 14:14:02.978422 | controller | Completion plugin: Generating completion cache...
2025-10-02 14:14:02.978445 | controller | Metadata cache created.
2025-10-02 14:14:02.978481 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.765209
2025-10-02 14:14:03.050248 | 
2025-10-02 14:14:03.050358 | PLAY RECAP
2025-10-02 14:14:03.050402 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-02 14:14:03.050426 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-02 14:14:03.050444 | 
2025-10-02 14:14:03.171966 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-02 14:14:03.172814 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-02 14:14:03.777905 | 
2025-10-02 14:14:03.778049 | PLAY [all]
2025-10-02 14:14:03.801058 | 
2025-10-02 14:14:03.801207 | TASK [Install binary dependencies]
2025-10-02 14:14:03.852074 | controller | ok
2025-10-02 14:14:03.882830 | 
2025-10-02 14:14:03.882978 | TASK [bindep : Include find tasks]
2025-10-02 14:14:03.911882 | controller | ok
2025-10-02 14:14:03.921289 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-02 14:14:03.927376 | 
2025-10-02 14:14:03.927440 | TASK [bindep : Look for bindep.txt]
2025-10-02 14:14:04.333021 | controller | ok
2025-10-02 14:14:04.340470 | 
2025-10-02 14:14:04.340575 | TASK [bindep : Define bindep_file fact]
2025-10-02 14:14:04.370865 | controller | ok
2025-10-02 14:14:04.376413 | 
2025-10-02 14:14:04.376498 | TASK [bindep : Look for other-requirements.txt]
2025-10-02 14:14:04.390535 | controller | skipping: Conditional result was False
2025-10-02 14:14:04.397009 | 
2025-10-02 14:14:04.397101 | TASK [bindep : Define bindep_file fact]
2025-10-02 14:14:04.421566 | controller | skipping: Conditional result was False
2025-10-02 14:14:04.428076 | 
2025-10-02 14:14:04.428154 | TASK [bindep : Look for bindep fallback file]
2025-10-02 14:14:04.452561 | controller | skipping: Conditional result was False
2025-10-02 14:14:04.459705 | 
2025-10-02 14:14:04.459807 | TASK [bindep : Define bindep_file fact]
2025-10-02 14:14:04.484568 | controller | skipping: Conditional result was False
2025-10-02 14:14:04.490781 | 
2025-10-02 14:14:04.490858 | TASK [bindep : Include bindep tasks]
2025-10-02 14:14:04.521044 | controller | ok
2025-10-02 14:14:04.535774 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-02 14:14:04.544282 | 
2025-10-02 14:14:04.544404 | TASK [bindep : Look for bindep command]
2025-10-02 14:14:04.579832 | controller | skipping: Conditional result was False
2025-10-02 14:14:04.587006 | 
2025-10-02 14:14:04.587072 | TASK [bindep : Check for system bindep]
2025-10-02 14:14:05.120341 | controller | ok: Runtime: 0:00:00.007802
2025-10-02 14:14:05.127928 | 
2025-10-02 14:14:05.128013 | TASK [bindep : Define bindep_command fact]
2025-10-02 14:14:05.163465 | controller | skipping: Conditional result was False
2025-10-02 14:14:05.169509 | 
2025-10-02 14:14:05.169583 | TASK [bindep : Include install tasks]
2025-10-02 14:14:05.219082 | controller | ok
2025-10-02 14:14:05.232593 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-02 14:14:05.241693 | 
2025-10-02 14:14:05.241848 | TASK [bindep : Create temp dir for bindep]
2025-10-02 14:14:05.658993 | controller | changed
2025-10-02 14:14:05.664555 | 
2025-10-02 14:14:05.664640 | TASK [Ensure we have pip dependencies]
2025-10-02 14:14:05.702379 | controller | ok
2025-10-02 14:14:05.752505 | 
2025-10-02 14:14:05.752668 | TASK [ensure-pip : Check if pip is installed]
2025-10-02 10:14:06.028798 | controller | /usr/bin/pip3
2025-10-02 10:14:06.054182 | controller | /usr/bin/python3: No module named wheel
2025-10-02 14:14:06.292393 | controller | ok: Runtime: 0:00:00.036212
2025-10-02 14:14:06.298256 | 
2025-10-02 14:14:06.298319 | LOOP [ensure-pip : Install pip from packages]
2025-10-02 14:14:06.326345 | controller | ok: "/var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-02 14:14:06.345958 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-02 14:14:06.373523 | 
2025-10-02 14:14:06.373784 | TASK [ensure-pip : Install Python 3 pip]
2025-10-02 14:14:09.456903 | controller | changed
2025-10-02 14:14:09.462423 | 
2025-10-02 14:14:09.462483 | TASK [ensure-pip : Check for EPEL repository]
2025-10-02 14:14:09.517438 | controller | skipping: Conditional result was False
2025-10-02 14:14:09.523942 | 
2025-10-02 14:14:09.524011 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-02 14:14:09.571886 | controller | skipping: Conditional result was False
2025-10-02 14:14:09.579393 | 
2025-10-02 14:14:09.579463 | TASK [ensure-pip : Install Python 2 pip]
2025-10-02 14:14:09.621160 | controller | skipping: Conditional result was False
2025-10-02 14:14:09.631120 | 
2025-10-02 14:14:09.631217 | TASK [ensure-pip : Ensure setuptools]
2025-10-02 14:14:09.667343 | controller | skipping: Conditional result was False
2025-10-02 14:14:09.682930 | 
2025-10-02 14:14:09.683088 | TASK [ensure-pip : Check for ensurepip module]
2025-10-02 14:14:10.223947 | controller | skipping: Conditional result was False
2025-10-02 14:14:10.232770 | 
2025-10-02 14:14:10.232903 | TASK [ensure-pip : Ensure python3-venv]
2025-10-02 14:14:10.258109 | controller | skipping: Conditional result was False
2025-10-02 14:14:10.264617 | 
2025-10-02 14:14:10.264702 | TASK [ensure-pip : Install pip from source]
2025-10-02 14:14:10.281335 | controller | skipping: Conditional result was False
2025-10-02 14:14:10.287327 | 
2025-10-02 14:14:10.287419 | TASK [ensure-pip : Probe for venv python full path]
2025-10-02 10:14:10.581235 | controller | /usr/bin/python3
2025-10-02 14:14:10.817928 | controller | ok: Runtime: 0:00:00.006166
2025-10-02 14:14:10.823560 | 
2025-10-02 14:14:10.823623 | TASK [ensure-pip : Set host default]
2025-10-02 14:14:10.892845 | controller | ok
2025-10-02 14:14:10.898690 | 
2025-10-02 14:14:10.898832 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-02 14:14:10.955029 | controller | ok
2025-10-02 14:14:10.968774 | 
2025-10-02 14:14:10.968856 | TASK [bindep : Install bindep into temporary venv]
2025-10-02 14:14:16.323634 | controller | changed
2025-10-02 14:14:16.329482 | 
2025-10-02 14:14:16.329553 | TASK [bindep : Define bindep_command]
2025-10-02 14:14:16.405615 | controller | ok
2025-10-02 14:14:16.442693 | 
2025-10-02 14:14:16.442919 | LOOP [bindep : Include package tasks]
2025-10-02 14:14:16.539420 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-02 14:14:16.539581 | controller | ok: All items complete
2025-10-02 14:14:16.539606 | 
2025-10-02 14:14:16.560072 | controller | included: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-02 14:14:16.576488 | 
2025-10-02 14:14:16.576640 | TASK [bindep : Define bindep_run fact]
2025-10-02 14:14:16.658311 | controller | ok
2025-10-02 14:14:16.667069 | 
2025-10-02 14:14:16.667179 | TASK [bindep : Get list of packages to install from bindep]
2025-10-02 10:14:18.093519 | controller | podman
2025-10-02 10:14:18.121796 | controller | python3-jmespath
2025-10-02 10:14:18.121896 | controller | python3-libvirt
2025-10-02 10:14:18.122033 | controller | python3-lxml
2025-10-02 10:14:18.122050 | controller | python3-netaddr
2025-10-02 14:14:18.240030 | controller | ok: Runtime: 0:00:01.129866
2025-10-02 14:14:18.247208 | 
2025-10-02 14:14:18.247359 | TASK [bindep : Install distro packages from bindep]
2025-10-02 14:15:28.332435 | controller | changed
2025-10-02 14:15:28.337991 | 
2025-10-02 14:15:28.338054 | TASK [bindep : Check that packages are installed]
2025-10-02 14:15:29.884535 | controller | ok: Runtime: 0:00:01.166982
2025-10-02 14:15:29.890812 | 
2025-10-02 14:15:29.890915 | TASK [bindep : Fail if we cannot install all packages]
2025-10-02 14:15:29.916661 | controller | skipping: Conditional result was False
2025-10-02 14:15:29.933812 | 
2025-10-02 14:15:29.933972 | TASK [Run test-setup role]
2025-10-02 14:15:29.961452 | controller | ok
2025-10-02 14:15:29.986733 | 
2025-10-02 14:15:29.987412 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-02 14:15:30.298320 | controller | ok
2025-10-02 14:15:30.303309 | 
2025-10-02 14:15:30.303372 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-02 14:15:30.867159 | controller | skipping: Conditional result was False
2025-10-02 14:15:30.895896 | 
2025-10-02 14:15:30.896010 | TASK [bindep : Remove bindep temp dir]
2025-10-02 14:15:31.295064 | controller | ok
2025-10-02 14:15:31.306258 | 
2025-10-02 14:15:31.306321 | PLAY RECAP
2025-10-02 14:15:31.306366 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-02 14:15:31.306391 | 
2025-10-02 14:15:31.403647 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-02 14:15:31.405677 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-02 14:15:32.089294 | 
2025-10-02 14:15:32.089431 | PLAY [all]
2025-10-02 14:15:32.115946 | 
2025-10-02 14:15:32.116118 | TASK [Abort when test_command variable is undefined]
2025-10-02 14:15:32.160979 | controller | skipping: Conditional result was False
2025-10-02 14:15:32.167040 | 
2025-10-02 14:15:32.167138 | TASK [Convert test_command to list]
2025-10-02 14:15:32.211409 | controller | skipping: Conditional result was False
2025-10-02 14:15:32.218330 | 
2025-10-02 14:15:32.218401 | TASK [Use test_command list]
2025-10-02 14:15:32.267261 | controller | ok
2025-10-02 14:15:32.272528 | 
2025-10-02 14:15:32.272587 | LOOP [Run test_command]
2025-10-02 14:15:32.756239 | controller | no check to run
2025-10-02 14:15:32.756469 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.038978
2025-10-02 14:15:32.789388 | 
2025-10-02 14:15:32.789505 | PLAY RECAP
2025-10-02 14:15:32.789545 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-02 14:15:32.789566 | 
2025-10-02 14:15:32.897671 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-02 14:15:32.898605 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-02 14:15:33.790307 | 
2025-10-02 14:15:33.790448 | PLAY [all]
2025-10-02 14:15:33.814013 | 
2025-10-02 14:15:33.814124 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-02 14:15:34.338017 | controller | changed: non-zero return code
2025-10-02 14:15:34.345712 | 
2025-10-02 14:15:34.345915 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-02 14:15:34.387544 | controller | skipping: Conditional result was False
2025-10-02 14:15:34.399549 | 
2025-10-02 14:15:34.399807 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-02 14:15:34.438831 | 
2025-10-02 14:15:34.439119 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-02 14:15:34.476622 | 
2025-10-02 14:15:34.476914 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-02 14:15:34.504877 | controller | skipping: Conditional result was False
2025-10-02 14:15:34.515589 | 
2025-10-02 14:15:34.515800 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-02 14:15:34.557615 | 
2025-10-02 14:15:34.557981 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-02 14:15:34.576170 | controller | skipping: Conditional result was False
2025-10-02 14:15:34.587826 | 
2025-10-02 14:15:34.588003 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-02 14:15:34.606480 | controller | skipping: Conditional result was False
2025-10-02 14:15:34.617786 | 
2025-10-02 14:15:34.617965 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-02 14:15:34.635086 | controller | skipping: Conditional result was False
2025-10-02 14:15:34.666323 | 
2025-10-02 14:15:34.666442 | PLAY RECAP
2025-10-02 14:15:34.666488 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-02 14:15:34.666509 | 
2025-10-02 14:15:34.803671 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-02 14:15:34.805927 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-02 14:15:35.419281 | 
2025-10-02 14:15:35.419406 | PLAY [all]
2025-10-02 14:15:35.437986 | 
2025-10-02 14:15:35.438068 | TASK [include_role : fetch-output]
2025-10-02 14:15:35.481127 | controller | ok
2025-10-02 14:15:35.498745 | 
2025-10-02 14:15:35.498890 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-02 14:15:35.563504 | controller | skipping: Conditional result was False
2025-10-02 14:15:35.572179 | 
2025-10-02 14:15:35.572292 | TASK [fetch-output : Set log path for single node]
2025-10-02 14:15:35.609605 | controller | ok
2025-10-02 14:15:35.621137 | 
2025-10-02 14:15:35.621308 | LOOP [fetch-output : Ensure local output dirs]
2025-10-02 14:15:36.038492 | controller -> localhost | ok: "/var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/logs"
2025-10-02 14:15:36.256474 | controller -> localhost | changed: "/var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/artifacts"
2025-10-02 14:15:36.556500 | controller -> localhost | changed: "/var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/docs"
2025-10-02 14:15:36.577640 | 
2025-10-02 14:15:36.577768 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-02 14:15:37.241213 | controller | changed: .d..t...... ./
2025-10-02 14:15:37.241432 | controller | changed: All items complete
2025-10-02 14:15:37.241459 | 
2025-10-02 14:15:37.828181 | controller | changed: .d..t...... ./
2025-10-02 14:15:38.377464 | controller | changed: .d..t...... ./
2025-10-02 14:15:38.396460 | 
2025-10-02 14:15:38.396676 | TASK [include_role : fetch-output-openshift]
2025-10-02 14:15:38.423678 | controller | skipping: Conditional result was False
2025-10-02 14:15:38.432314 | 
2025-10-02 14:15:38.432458 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-02 14:15:38.956910 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.025759
2025-10-02 14:15:39.196244 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008932
2025-10-02 14:15:39.223831 | 
2025-10-02 14:15:39.223947 | PLAY [all]
2025-10-02 14:15:39.238517 | 
2025-10-02 14:15:39.238620 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-02 14:15:39.747503 | controller | changed
2025-10-02 14:15:39.780104 | 
2025-10-02 14:15:39.780195 | PLAY RECAP
2025-10-02 14:15:39.780249 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-02 14:15:39.780278 | 
2025-10-02 14:15:39.887071 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-02 14:15:39.888797 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-02 14:15:40.581933 | 
2025-10-02 14:15:40.582064 | PLAY [localhost]
2025-10-02 14:15:40.602392 | 
2025-10-02 14:15:40.602526 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-02 14:15:41.086230 | localhost | changed
2025-10-02 14:15:41.098211 | 
2025-10-02 14:15:41.098409 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-02 14:15:41.137388 | localhost | ok
2025-10-02 14:15:41.157213 | 
2025-10-02 14:15:41.157359 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-02 14:15:41.548256 | localhost | changed
2025-10-02 14:15:41.554231 | 
2025-10-02 14:15:41.554328 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-02 14:15:42.282618 | localhost | changed
2025-10-02 14:15:42.287749 | 
2025-10-02 14:15:42.287823 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-02 14:15:42.694097 | localhost | Identity added: /var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/tmp/ansible.pcnx6l5c (/var/lib/zuul/builds/7b065c964f3242ef8eeab82e02357d3d/work/tmp/ansible.pcnx6l5c)
2025-10-02 14:15:42.694280 | localhost | ok: Runtime: 0:00:00.007229
2025-10-02 14:15:42.698526 | 
2025-10-02 14:15:42.698586 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-02 14:15:43.003334 | localhost | ok: Runtime: 0:00:00.025952
2025-10-02 14:15:43.008200 | 
2025-10-02 14:15:43.008308 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-02 14:15:43.068826 | localhost | changed
2025-10-02 14:15:43.073529 | 
2025-10-02 14:15:43.073598 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-02 14:15:43.456827 | localhost | changed
2025-10-02 14:15:43.477528 | 
2025-10-02 14:15:43.477654 | PLAY [localhost]
2025-10-02 14:15:43.490280 | 
2025-10-02 14:15:43.490409 | TASK [Generate bulk log download script]
2025-10-02 14:15:43.508440 | localhost | ok
2025-10-02 14:15:43.520659 | 
2025-10-02 14:15:43.520799 | TASK [local-log-download : Check API endpoint is defined]
2025-10-02 14:15:43.548445 | localhost | ok: All assertions passed
2025-10-02 14:15:43.553079 | 
2025-10-02 14:15:43.553159 | TASK [local-log-download : Create download script]
2025-10-02 14:15:43.994810 | localhost -> localhost | changed
2025-10-02 14:15:44.003498 | 
2025-10-02 14:15:44.003592 | TASK [Register quick-download link]
2025-10-02 14:15:44.020991 | localhost | ok
2025-10-02 14:15:44.060239 | 
2025-10-02 14:15:44.060347 | PLAY [logserver.rdoproject.org]
2025-10-02 14:15:44.070698 | 
2025-10-02 14:15:44.070810 | TASK [Set zuul-log-path fact]
2025-10-02 14:15:44.086974 | logserver.rdoproject.org | ok
2025-10-02 14:15:44.096672 | 
2025-10-02 14:15:44.096798 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-02 14:15:44.123075 | logserver.rdoproject.org | ok
2025-10-02 14:15:44.128831 | 
2025-10-02 14:15:44.128915 | TASK [upload-logs : Create log directories]
2025-10-02 14:15:44.774446 | logserver.rdoproject.org | changed
2025-10-02 14:15:44.777614 | 
2025-10-02 14:15:44.777684 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-02 14:15:45.048260 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009978
2025-10-02 14:15:45.058112 | 
2025-10-02 14:15:45.058289 | TASK [upload-logs : Upload logs to log server]
2025-10-02 14:15:45.797382 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-02 14:15:45.803253 | 
2025-10-02 14:15:45.803339 | LOOP [upload-logs : Compress console log and json output]
2025-10-02 14:15:45.868115 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 14:15:45.877399 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 14:15:45.882751 | 
2025-10-02 14:15:45.882847 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-02 14:15:45.951285 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 14:15:45.951538 | 
2025-10-02 14:15:45.958620 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-02 14:15:45.970890 | 
2025-10-02 14:15:45.971004 | LOOP [upload-logs : Upload console log and json output]