2025-10-03 13:23:36.822114 | Job console starting...
2025-10-03 13:23:36.834785 | Updating repositories
2025-10-03 13:23:36.869278 | Preparing job workspace
2025-10-03 13:23:40.550241 | Running Ansible setup...
2025-10-03 13:23:44.897272 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 13:23:45.584807 | 
2025-10-03 13:23:45.584974 | PLAY [localhost]
2025-10-03 13:23:45.607811 | 
2025-10-03 13:23:45.607956 | TASK [Gathering Facts]
2025-10-03 13:23:46.649938 | localhost | ok
2025-10-03 13:23:46.673072 | 
2025-10-03 13:23:46.673271 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 13:23:47.329265 | localhost -> localhost | changed
2025-10-03 13:23:47.334843 | 
2025-10-03 13:23:47.334949 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 13:23:48.433493 | localhost -> localhost | changed
2025-10-03 13:23:48.444693 | 
2025-10-03 13:23:48.444810 | TASK [Setup log path fact]
2025-10-03 13:23:48.493840 | localhost | ok
2025-10-03 13:23:48.531247 | 
2025-10-03 13:23:48.532483 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 13:23:48.596118 | localhost | ok
2025-10-03 13:23:48.607973 | 
2025-10-03 13:23:48.608070 | TASK [emit-job-header : Print job information]
2025-10-03 13:23:48.672300 | # Job Information
2025-10-03 13:23:48.672456 | Ansible Version: 2.15.12
2025-10-03 13:23:48.672483 | Job: cifmw-molecule-polarion
2025-10-03 13:23:48.672503 | Pipeline: github-check
2025-10-03 13:23:48.672521 | Executor: ze03.softwarefactory-project.io
2025-10-03 13:23:48.672539 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-03 13:23:48.672557 | Log URL (when completed): https://logserver.rdoproject.org/4cf/rdoproject.org/4cf8d0dce00a445aac1c053002a9091b/
2025-10-03 13:23:48.672575 | Event ID: f3678040-a05b-11f0-90a2-408975ecafa3
2025-10-03 13:23:48.676675 | 
2025-10-03 13:23:48.676763 | LOOP [emit-job-header : Print node information]
2025-10-03 13:23:48.773236 | localhost | ok:
2025-10-03 13:23:48.773450 | localhost | # Node Information
2025-10-03 13:23:48.773487 | localhost | Inventory Hostname: controller
2025-10-03 13:23:48.773515 | localhost | Hostname: np0005469350
2025-10-03 13:23:48.773539 | localhost | Username: zuul
2025-10-03 13:23:48.773566 | localhost | Distro: CentOS 9
2025-10-03 13:23:48.773589 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-03 13:23:48.773610 | localhost | Region: RegionOne
2025-10-03 13:23:48.773631 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-03 13:23:48.773652 | localhost | Product Name: OpenStack Nova
2025-10-03 13:23:48.773672 | localhost | Interface IP: 38.102.83.151
2025-10-03 13:23:48.805571 | 
2025-10-03 13:23:48.805700 | PLAY [all]
2025-10-03 13:23:48.813876 | 
2025-10-03 13:23:48.813978 | TASK [Gather network facts]
2025-10-03 13:23:49.341567 | controller | ok
2025-10-03 13:23:49.386903 | 
2025-10-03 13:23:49.386994 | TASK [include_role : start-zuul-console]
2025-10-03 13:23:49.433273 | controller | ok
2025-10-03 13:23:49.458373 | 
2025-10-03 13:23:49.458522 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 13:23:49.940482 | controller | ok
2025-10-03 13:23:49.957507 | 
2025-10-03 13:23:49.957635 | TASK [include_role : add-build-sshkey]
2025-10-03 13:23:49.987999 | controller | ok
2025-10-03 13:23:50.002399 | 
2025-10-03 13:23:50.002513 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 13:23:50.240649 | controller -> localhost | ok
2025-10-03 13:23:50.248650 | 
2025-10-03 13:23:50.248758 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 13:23:50.277743 | controller | ok
2025-10-03 13:23:50.291562 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 13:23:50.300250 | 
2025-10-03 13:23:50.300388 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 13:23:51.425547 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 13:23:51.425831 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/4cf8d0dce00a445aac1c053002a9091b_id_rsa.
2025-10-03 13:23:51.425871 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/4cf8d0dce00a445aac1c053002a9091b_id_rsa.pub.
2025-10-03 13:23:51.425896 | controller -> localhost | The key fingerprint is:
2025-10-03 13:23:51.425917 | controller -> localhost | SHA256:8nH8hl3oEwJg6hs0/C3JD0qs/9QskvCsIUwbta5+eVU zuul-build-sshkey
2025-10-03 13:23:51.425937 | controller -> localhost | The key's randomart image is:
2025-10-03 13:23:51.425957 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 13:23:51.425977 | controller -> localhost | |      o          |
2025-10-03 13:23:51.425999 | controller -> localhost | |   . o .         |
2025-10-03 13:23:51.426020 | controller -> localhost | |   .=   .        |
2025-10-03 13:23:51.426044 | controller -> localhost | |  .+.+ o E   .   |
2025-10-03 13:23:51.426069 | controller -> localhost | | o..= B S + o .  |
2025-10-03 13:23:51.426092 | controller -> localhost | |o +* = X o * o   |
2025-10-03 13:23:51.426116 | controller -> localhost | |.oo.O + = . *    |
2025-10-03 13:23:51.426139 | controller -> localhost | | ..* + .   . .   |
2025-10-03 13:23:51.426158 | controller -> localhost | |.oo o..          |
2025-10-03 13:23:51.426176 | controller -> localhost | +----[SHA256]-----+
2025-10-03 13:23:51.426227 | controller -> localhost | ok: Runtime: 0:00:00.630041
2025-10-03 13:23:51.433009 | 
2025-10-03 13:23:51.433078 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 13:23:51.483004 | controller | ok
2025-10-03 13:23:51.497133 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 13:23:51.506192 | 
2025-10-03 13:23:51.506261 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 13:23:51.561001 | controller | skipping: Conditional result was False
2025-10-03 13:23:51.567470 | 
2025-10-03 13:23:51.567593 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 13:23:52.195921 | controller | changed
2025-10-03 13:23:52.206821 | 
2025-10-03 13:23:52.206932 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 13:23:52.523261 | controller | ok
2025-10-03 13:23:52.528751 | 
2025-10-03 13:23:52.528858 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 13:23:53.430080 | controller | changed
2025-10-03 13:23:53.435932 | 
2025-10-03 13:23:53.436100 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 13:23:54.366429 | controller | changed
2025-10-03 13:23:54.372809 | 
2025-10-03 13:23:54.372879 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 13:23:54.393598 | controller | skipping: Conditional result was False
2025-10-03 13:23:54.416082 | 
2025-10-03 13:23:54.416214 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 13:23:54.861127 | controller -> localhost | changed
2025-10-03 13:23:54.875844 | 
2025-10-03 13:23:54.875966 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 13:23:55.172185 | controller -> localhost | Identity added: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/4cf8d0dce00a445aac1c053002a9091b_id_rsa (zuul-build-sshkey)
2025-10-03 13:23:55.172371 | controller -> localhost | ok: Runtime: 0:00:00.009190
2025-10-03 13:23:55.178512 | 
2025-10-03 13:23:55.178707 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 13:23:55.637862 | controller | ok
2025-10-03 13:23:55.643493 | 
2025-10-03 13:23:55.643578 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 13:23:55.684903 | controller | skipping: Conditional result was False
2025-10-03 13:23:55.698167 | 
2025-10-03 13:23:55.698361 | TASK [include_role : validate-host]
2025-10-03 13:23:55.737303 | controller | ok
2025-10-03 13:23:55.761970 | 
2025-10-03 13:23:55.762156 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 13:23:55.791404 | controller | ok
2025-10-03 13:23:55.797600 | 
2025-10-03 13:23:55.797689 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 13:23:56.220485 | controller -> localhost | ok
2025-10-03 13:23:56.225848 | 
2025-10-03 13:23:56.225923 | TASK [validate-host : Collect information about the host]
2025-10-03 13:23:57.058203 | controller | ok
2025-10-03 13:23:57.081337 | 
2025-10-03 13:23:57.081448 | TASK [validate-host : Sanitize hostname]
2025-10-03 13:23:57.151204 | controller | ok
2025-10-03 13:23:57.158447 | 
2025-10-03 13:23:57.158583 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 13:23:57.852642 | controller -> localhost | changed
2025-10-03 13:23:57.858599 | 
2025-10-03 13:23:57.858670 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 13:23:58.278454 | controller | ok
2025-10-03 13:23:58.283927 | 
2025-10-03 13:23:58.284016 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 13:23:58.943092 | controller -> localhost | changed
2025-10-03 13:23:58.954894 | 
2025-10-03 13:23:58.954999 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 13:23:58.969975 | controller | skipping: Conditional result was False
2025-10-03 13:23:58.976119 | 
2025-10-03 13:23:58.976221 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 13:23:58.993170 | controller | skipping: Conditional result was False
2025-10-03 13:23:59.000227 | 
2025-10-03 13:23:59.000358 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 13:23:59.241318 | controller | ok: "logs"
2025-10-03 13:23:59.241519 | controller | ok: All items complete
2025-10-03 13:23:59.241546 | 
2025-10-03 13:23:59.491534 | controller | ok: "artifacts"
2025-10-03 13:23:59.774093 | controller | ok: "docs"
2025-10-03 13:23:59.783425 | 
2025-10-03 13:23:59.783540 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 13:24:00.083866 | controller | changed: "logs"
2025-10-03 13:24:00.307579 | controller | changed: "artifacts"
2025-10-03 13:24:00.561678 | controller | changed: "docs"
2025-10-03 13:24:00.616446 | 
2025-10-03 13:24:00.616587 | PLAY RECAP
2025-10-03 13:24:00.616644 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 13:24:00.616679 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 13:24:00.616700 | 
2025-10-03 13:24:00.963704 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 13:24:00.964526 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 13:24:01.778768 | 
2025-10-03 13:24:01.778876 | PLAY [localhost]
2025-10-03 13:24:01.798059 | 
2025-10-03 13:24:01.798164 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-03 13:24:02.294170 | localhost | ok
2025-10-03 13:24:02.308651 | 
2025-10-03 13:24:02.308834 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-03 13:24:03.200778 | localhost | changed
2025-10-03 13:24:03.221628 | 
2025-10-03 13:24:03.221713 | PLAY [all]
2025-10-03 13:24:03.239930 | 
2025-10-03 13:24:03.240058 | TASK [include_role : prepare-workspace]
2025-10-03 13:24:03.259149 | controller | ok
2025-10-03 13:24:03.275565 | 
2025-10-03 13:24:03.275707 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 13:24:03.708065 | controller | ok
2025-10-03 13:24:03.717787 | 
2025-10-03 13:24:03.717928 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 13:24:06.070909 | controller | Output suppressed because no_log was given
2025-10-03 13:24:06.092941 | 
2025-10-03 13:24:06.093115 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 13:24:06.363570 | controller | changed: "logs"
2025-10-03 13:24:06.566261 | controller | changed: "artifacts"
2025-10-03 13:24:06.768517 | controller | changed: "docs"
2025-10-03 13:24:06.795624 | 
2025-10-03 13:24:06.795806 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 13:24:07.042824 | controller | changed: "logs"
2025-10-03 13:24:07.043078 | controller | changed: All items complete
2025-10-03 13:24:07.043113 | 
2025-10-03 13:24:07.282816 | controller | changed: "artifacts"
2025-10-03 13:24:07.537271 | controller | changed: "docs"
2025-10-03 13:24:07.558224 | 
2025-10-03 13:24:07.558342 | TASK [Check if worker can sudo]
2025-10-03 13:24:08.092581 | controller | ok: Runtime: 0:00:00.048604
2025-10-03 13:24:08.102320 | 
2025-10-03 13:24:08.102443 | TASK [configure-mirrors : Gather needed facts]
2025-10-03 13:24:08.157512 | controller | skipping: Conditional result was False
2025-10-03 13:24:08.164427 | 
2025-10-03 13:24:08.164543 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-03 13:24:08.242863 | controller | ok
2025-10-03 13:24:08.252806 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-03 13:24:08.303249 | 
2025-10-03 13:24:08.303366 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-03 13:24:08.605963 | controller | ok
2025-10-03 13:24:08.612016 | 
2025-10-03 13:24:08.612114 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-03 13:24:08.669366 | controller | ok: "/var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-03 13:24:08.685355 | 
2025-10-03 13:24:08.685480 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-03 13:24:09.585920 | controller | changed
2025-10-03 13:24:09.596569 | 
2025-10-03 13:24:09.596712 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-03 13:24:09.654149 | controller | ok: "/var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-03 13:24:09.654358 | controller | ok: All items complete
2025-10-03 13:24:09.654385 | 
2025-10-03 13:24:09.713438 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-03 13:24:09.733501 | 
2025-10-03 13:24:09.733606 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-03 13:24:10.750852 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-03 13:24:11.716615 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-03 13:24:11.729167 | 
2025-10-03 13:24:11.729292 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-03 13:24:12.234077 | controller | changed: section and option added
2025-10-03 13:24:12.266633 | 
2025-10-03 13:24:12.266846 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-03 13:24:13.119766 | controller | 29 files removed
2025-10-03 13:24:13.119994 | controller | ok: Item: dnf clean all Runtime: 0:00:00.468626
2025-10-03 13:24:13.120032 | controller | changed: All items complete
2025-10-03 13:24:13.120053 | 
2025-10-03 13:24:23.867275 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-10-03 13:24:23.867445 | controller | DNF version: 4.14.0
2025-10-03 13:24:23.867499 | controller | cachedir: /var/cache/dnf
2025-10-03 13:24:23.867532 | controller | Making cache files for all metadata files.
2025-10-03 13:24:23.867562 | controller | baseos: has expired and will be refreshed.
2025-10-03 13:24:23.867590 | controller | appstream: has expired and will be refreshed.
2025-10-03 13:24:23.867618 | controller | crb: has expired and will be refreshed.
2025-10-03 13:24:23.867654 | controller | extras-common: has expired and will be refreshed.
2025-10-03 13:24:23.867683 | controller | repo: downloading from remote: baseos
2025-10-03 13:24:23.867710 | controller | CentOS Stream 9 - BaseOS                         77 MB/s | 8.8 MB     00:00
2025-10-03 13:24:23.867763 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-03 13:24:23.867793 | controller | repo: downloading from remote: appstream
2025-10-03 13:24:23.867820 | controller | CentOS Stream 9 - AppStream                      89 MB/s |  25 MB     00:00
2025-10-03 13:24:23.867848 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-03 13:24:23.867875 | controller | repo: downloading from remote: crb
2025-10-03 13:24:23.867902 | controller | CentOS Stream 9 - CRB                           113 MB/s | 7.1 MB     00:00
2025-10-03 13:24:23.867929 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-03 13:24:23.867956 | controller | repo: downloading from remote: extras-common
2025-10-03 13:24:23.867983 | controller | CentOS Stream 9 - Extras packages               1.9 MB/s |  20 kB     00:00
2025-10-03 13:24:23.868015 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-03 13:24:23.868041 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-03 13:24:23.868068 | controller | Completion plugin: Generating completion cache...
2025-10-03 13:24:23.868095 | controller | Metadata cache created.
2025-10-03 13:24:23.868137 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.443534
2025-10-03 13:24:23.890086 | 
2025-10-03 13:24:23.890173 | PLAY RECAP
2025-10-03 13:24:23.890212 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 13:24:23.890237 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 13:24:23.890255 | 
2025-10-03 13:24:24.028465 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 13:24:24.031244 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 13:24:24.721210 | 
2025-10-03 13:24:24.721362 | PLAY [all]
2025-10-03 13:24:24.746696 | 
2025-10-03 13:24:24.746843 | TASK [Install binary dependencies]
2025-10-03 13:24:24.807525 | controller | ok
2025-10-03 13:24:24.831945 | 
2025-10-03 13:24:24.832099 | TASK [bindep : Include find tasks]
2025-10-03 13:24:24.861614 | controller | ok
2025-10-03 13:24:24.871505 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-03 13:24:24.879425 | 
2025-10-03 13:24:24.879576 | TASK [bindep : Look for bindep.txt]
2025-10-03 13:24:25.347568 | controller | ok
2025-10-03 13:24:25.357021 | 
2025-10-03 13:24:25.357147 | TASK [bindep : Define bindep_file fact]
2025-10-03 13:24:25.387457 | controller | ok
2025-10-03 13:24:25.392657 | 
2025-10-03 13:24:25.392766 | TASK [bindep : Look for other-requirements.txt]
2025-10-03 13:24:25.406753 | controller | skipping: Conditional result was False
2025-10-03 13:24:25.414416 | 
2025-10-03 13:24:25.414562 | TASK [bindep : Define bindep_file fact]
2025-10-03 13:24:25.440080 | controller | skipping: Conditional result was False
2025-10-03 13:24:25.447456 | 
2025-10-03 13:24:25.447601 | TASK [bindep : Look for bindep fallback file]
2025-10-03 13:24:25.471928 | controller | skipping: Conditional result was False
2025-10-03 13:24:25.478821 | 
2025-10-03 13:24:25.478948 | TASK [bindep : Define bindep_file fact]
2025-10-03 13:24:25.503160 | controller | skipping: Conditional result was False
2025-10-03 13:24:25.510359 | 
2025-10-03 13:24:25.510486 | TASK [bindep : Include bindep tasks]
2025-10-03 13:24:25.542023 | controller | ok
2025-10-03 13:24:25.553694 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-03 13:24:25.573674 | 
2025-10-03 13:24:25.573893 | TASK [bindep : Look for bindep command]
2025-10-03 13:24:25.600855 | controller | skipping: Conditional result was False
2025-10-03 13:24:25.612079 | 
2025-10-03 13:24:25.612223 | TASK [bindep : Check for system bindep]
2025-10-03 13:24:26.152495 | controller | ok: Runtime: 0:00:00.009193
2025-10-03 13:24:26.166546 | 
2025-10-03 13:24:26.166882 | TASK [bindep : Define bindep_command fact]
2025-10-03 13:24:26.206215 | controller | skipping: Conditional result was False
2025-10-03 13:24:26.215035 | 
2025-10-03 13:24:26.215233 | TASK [bindep : Include install tasks]
2025-10-03 13:24:26.265115 | controller | ok
2025-10-03 13:24:26.278386 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-03 13:24:26.293835 | 
2025-10-03 13:24:26.294076 | TASK [bindep : Create temp dir for bindep]
2025-10-03 13:24:26.723360 | controller | changed
2025-10-03 13:24:26.728591 | 
2025-10-03 13:24:26.728651 | TASK [Ensure we have pip dependencies]
2025-10-03 13:24:26.758137 | controller | ok
2025-10-03 13:24:26.785709 | 
2025-10-03 13:24:26.785843 | TASK [ensure-pip : Check if pip is installed]
2025-10-03 09:24:27.088557 | controller | /usr/bin/pip3
2025-10-03 09:24:27.141590 | controller | /usr/bin/python3: No module named wheel
2025-10-03 13:24:27.319274 | controller | ok: Runtime: 0:00:00.069743
2025-10-03 13:24:27.331648 | 
2025-10-03 13:24:27.331878 | LOOP [ensure-pip : Install pip from packages]
2025-10-03 13:24:27.377241 | controller | ok: "/var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-03 13:24:27.401576 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-03 13:24:27.422664 | 
2025-10-03 13:24:27.422874 | TASK [ensure-pip : Install Python 3 pip]
2025-10-03 13:24:29.895412 | controller | changed
2025-10-03 13:24:29.901480 | 
2025-10-03 13:24:29.901565 | TASK [ensure-pip : Check for EPEL repository]
2025-10-03 13:24:29.946230 | controller | skipping: Conditional result was False
2025-10-03 13:24:29.958934 | 
2025-10-03 13:24:29.959076 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-03 13:24:30.007825 | controller | skipping: Conditional result was False
2025-10-03 13:24:30.016846 | 
2025-10-03 13:24:30.016984 | TASK [ensure-pip : Install Python 2 pip]
2025-10-03 13:24:30.063380 | controller | skipping: Conditional result was False
2025-10-03 13:24:30.070767 | 
2025-10-03 13:24:30.070872 | TASK [ensure-pip : Ensure setuptools]
2025-10-03 13:24:30.084931 | controller | skipping: Conditional result was False
2025-10-03 13:24:30.091769 | 
2025-10-03 13:24:30.091872 | TASK [ensure-pip : Check for ensurepip module]
2025-10-03 13:24:30.621895 | controller | skipping: Conditional result was False
2025-10-03 13:24:30.628958 | 
2025-10-03 13:24:30.629038 | TASK [ensure-pip : Ensure python3-venv]
2025-10-03 13:24:30.643117 | controller | skipping: Conditional result was False
2025-10-03 13:24:30.649472 | 
2025-10-03 13:24:30.649540 | TASK [ensure-pip : Install pip from source]
2025-10-03 13:24:30.662624 | controller | skipping: Conditional result was False
2025-10-03 13:24:30.668536 | 
2025-10-03 13:24:30.668623 | TASK [ensure-pip : Probe for venv python full path]
2025-10-03 09:24:30.921451 | controller | /usr/bin/python3
2025-10-03 13:24:31.197954 | controller | ok: Runtime: 0:00:00.007878
2025-10-03 13:24:31.207681 | 
2025-10-03 13:24:31.207858 | TASK [ensure-pip : Set host default]
2025-10-03 13:24:31.261399 | controller | ok
2025-10-03 13:24:31.269671 | 
2025-10-03 13:24:31.269804 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-03 13:24:31.341950 | controller | ok
2025-10-03 13:24:31.352711 | 
2025-10-03 13:24:31.352837 | TASK [bindep : Install bindep into temporary venv]
2025-10-03 13:24:35.583846 | controller | changed
2025-10-03 13:24:35.590676 | 
2025-10-03 13:24:35.590854 | TASK [bindep : Define bindep_command]
2025-10-03 13:24:35.622974 | controller | ok
2025-10-03 13:24:35.631230 | 
2025-10-03 13:24:35.631373 | LOOP [bindep : Include package tasks]
2025-10-03 13:24:35.685409 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-03 13:24:35.685571 | controller | ok: All items complete
2025-10-03 13:24:35.685599 | 
2025-10-03 13:24:35.700545 | controller | included: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-03 13:24:35.718873 | 
2025-10-03 13:24:35.719021 | TASK [bindep : Define bindep_run fact]
2025-10-03 13:24:35.754103 | controller | ok
2025-10-03 13:24:35.767178 | 
2025-10-03 13:24:35.767331 | TASK [bindep : Get list of packages to install from bindep]
2025-10-03 09:24:37.572969 | controller | podman
2025-10-03 09:24:37.605112 | controller | python3-jmespath
2025-10-03 09:24:37.605195 | controller | python3-libvirt
2025-10-03 09:24:37.605281 | controller | python3-lxml
2025-10-03 09:24:37.605297 | controller | python3-netaddr
2025-10-03 13:24:37.814805 | controller | ok: Runtime: 0:00:01.529732
2025-10-03 13:24:37.822832 | 
2025-10-03 13:24:37.822922 | TASK [bindep : Install distro packages from bindep]
2025-10-03 13:25:42.136684 | controller | changed
2025-10-03 13:25:42.143108 | 
2025-10-03 13:25:42.143191 | TASK [bindep : Check that packages are installed]
2025-10-03 13:25:43.713349 | controller | ok: Runtime: 0:00:01.084165
2025-10-03 13:25:43.722214 | 
2025-10-03 13:25:43.722329 | TASK [bindep : Fail if we cannot install all packages]
2025-10-03 13:25:43.747875 | controller | skipping: Conditional result was False
2025-10-03 13:25:43.759701 | 
2025-10-03 13:25:43.759859 | TASK [Run test-setup role]
2025-10-03 13:25:43.778769 | controller | ok
2025-10-03 13:25:43.797391 | 
2025-10-03 13:25:43.797493 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-03 13:25:44.030337 | controller | ok
2025-10-03 13:25:44.042392 | 
2025-10-03 13:25:44.042491 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-03 13:25:44.584900 | controller | skipping: Conditional result was False
2025-10-03 13:25:44.616393 | 
2025-10-03 13:25:44.616575 | TASK [bindep : Remove bindep temp dir]
2025-10-03 13:25:44.982344 | controller | ok
2025-10-03 13:25:45.000841 | 
2025-10-03 13:25:45.000943 | PLAY RECAP
2025-10-03 13:25:45.000983 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-03 13:25:45.001003 | 
2025-10-03 13:25:45.161384 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-03 13:25:45.162294 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 13:25:45.963677 | 
2025-10-03 13:25:45.963837 | PLAY [all]
2025-10-03 13:25:45.991294 | 
2025-10-03 13:25:45.991452 | TASK [Abort when test_command variable is undefined]
2025-10-03 13:25:46.026335 | controller | skipping: Conditional result was False
2025-10-03 13:25:46.032633 | 
2025-10-03 13:25:46.032782 | TASK [Convert test_command to list]
2025-10-03 13:25:46.138553 | controller | skipping: Conditional result was False
2025-10-03 13:25:46.145238 | 
2025-10-03 13:25:46.145344 | TASK [Use test_command list]
2025-10-03 13:25:46.257965 | controller | ok
2025-10-03 13:25:46.271809 | 
2025-10-03 13:25:46.271953 | LOOP [Run test_command]
2025-10-03 13:25:46.748847 | controller | no check to run
2025-10-03 13:25:46.749054 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005833
2025-10-03 13:25:46.807319 | 
2025-10-03 13:25:46.807441 | PLAY RECAP
2025-10-03 13:25:46.807491 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 13:25:46.807512 | 
2025-10-03 13:25:47.033156 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-03 13:25:47.034361 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 13:25:47.844501 | 
2025-10-03 13:25:47.844645 | PLAY [all]
2025-10-03 13:25:47.884424 | 
2025-10-03 13:25:47.884567 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-03 13:25:48.284572 | controller | changed: non-zero return code
2025-10-03 13:25:48.292784 | 
2025-10-03 13:25:48.292906 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-03 13:25:48.335496 | controller | skipping: Conditional result was False
2025-10-03 13:25:48.342508 | 
2025-10-03 13:25:48.342607 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-03 13:25:48.389262 | 
2025-10-03 13:25:48.389432 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-03 13:25:48.444560 | 
2025-10-03 13:25:48.444714 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-03 13:25:48.475547 | controller | skipping: Conditional result was False
2025-10-03 13:25:48.482464 | 
2025-10-03 13:25:48.482542 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-03 13:25:48.544971 | 
2025-10-03 13:25:48.545119 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-03 13:25:48.571400 | controller | skipping: Conditional result was False
2025-10-03 13:25:48.590333 | 
2025-10-03 13:25:48.590455 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-03 13:25:48.659260 | controller | skipping: Conditional result was False
2025-10-03 13:25:48.667905 | 
2025-10-03 13:25:48.668003 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-03 13:25:48.719005 | controller | skipping: Conditional result was False
2025-10-03 13:25:48.790604 | 
2025-10-03 13:25:48.790707 | PLAY RECAP
2025-10-03 13:25:48.790802 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-03 13:25:48.790852 | 
2025-10-03 13:25:48.975253 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-03 13:25:48.976378 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 13:25:49.642073 | 
2025-10-03 13:25:49.642204 | PLAY [all]
2025-10-03 13:25:49.663265 | 
2025-10-03 13:25:49.663385 | TASK [include_role : fetch-output]
2025-10-03 13:25:49.725520 | controller | ok
2025-10-03 13:25:49.765971 | 
2025-10-03 13:25:49.766143 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 13:25:49.840525 | controller | skipping: Conditional result was False
2025-10-03 13:25:49.846700 | 
2025-10-03 13:25:49.846797 | TASK [fetch-output : Set log path for single node]
2025-10-03 13:25:49.920609 | controller | ok
2025-10-03 13:25:49.932464 | 
2025-10-03 13:25:49.932551 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 13:25:50.570586 | controller -> localhost | ok: "/var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/logs"
2025-10-03 13:25:50.875124 | controller -> localhost | changed: "/var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/artifacts"
2025-10-03 13:25:51.216610 | controller -> localhost | changed: "/var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/docs"
2025-10-03 13:25:51.227778 | 
2025-10-03 13:25:51.227923 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 13:25:52.084175 | controller | changed: .d..t...... ./
2025-10-03 13:25:52.084381 | controller | changed: All items complete
2025-10-03 13:25:52.084409 | 
2025-10-03 13:25:52.639926 | controller | changed: .d..t...... ./
2025-10-03 13:25:53.386811 | controller | changed: .d..t...... ./
2025-10-03 13:25:53.417495 | 
2025-10-03 13:25:53.417635 | TASK [include_role : fetch-output-openshift]
2025-10-03 13:25:53.439689 | controller | skipping: Conditional result was False
2025-10-03 13:25:53.446864 | 
2025-10-03 13:25:53.446961 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 13:25:54.011712 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010249
2025-10-03 13:25:54.264959 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.019578
2025-10-03 13:25:54.334842 | 
2025-10-03 13:25:54.334950 | PLAY [all]
2025-10-03 13:25:54.376871 | 
2025-10-03 13:25:54.376982 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 13:25:54.891363 | controller | changed
2025-10-03 13:25:54.922360 | 
2025-10-03 13:25:54.922477 | PLAY RECAP
2025-10-03 13:25:54.922872 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 13:25:54.922906 | 
2025-10-03 13:25:55.087965 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 13:25:55.088831 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 13:25:55.705428 | 
2025-10-03 13:25:55.705562 | PLAY [localhost]
2025-10-03 13:25:55.726090 | 
2025-10-03 13:25:55.726245 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 13:25:56.289556 | localhost | changed
2025-10-03 13:25:56.298120 | 
2025-10-03 13:25:56.298240 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 13:25:56.326765 | localhost | ok
2025-10-03 13:25:56.335907 | 
2025-10-03 13:25:56.336032 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 13:25:56.814326 | localhost | changed
2025-10-03 13:25:56.826115 | 
2025-10-03 13:25:56.826304 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 13:25:57.907867 | localhost | changed
2025-10-03 13:25:57.913634 | 
2025-10-03 13:25:57.913784 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 13:25:58.412904 | localhost | Identity added: /var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/tmp/ansible.rb6b2lvj (/var/lib/zuul/builds/4cf8d0dce00a445aac1c053002a9091b/work/tmp/ansible.rb6b2lvj)
2025-10-03 13:25:58.413070 | localhost | ok: Runtime: 0:00:00.019715
2025-10-03 13:25:58.418287 | 
2025-10-03 13:25:58.418464 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 13:25:58.762046 | localhost | ok: Runtime: 0:00:00.006041
2025-10-03 13:25:58.766744 | 
2025-10-03 13:25:58.766816 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 13:25:58.834372 | localhost | changed
2025-10-03 13:25:58.845646 | 
2025-10-03 13:25:58.845771 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 13:25:59.538769 | localhost | changed
2025-10-03 13:25:59.564407 | 
2025-10-03 13:25:59.564514 | PLAY [localhost]
2025-10-03 13:25:59.585267 | 
2025-10-03 13:25:59.585372 | TASK [Generate bulk log download script]
2025-10-03 13:25:59.611556 | localhost | ok
2025-10-03 13:25:59.629937 | 
2025-10-03 13:25:59.630044 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 13:25:59.683427 | localhost | ok: All assertions passed
2025-10-03 13:25:59.690140 | 
2025-10-03 13:25:59.690244 | TASK [local-log-download : Create download script]
2025-10-03 13:26:00.322382 | localhost -> localhost | changed
2025-10-03 13:26:00.400127 | 
2025-10-03 13:26:00.400242 | TASK [Register quick-download link]
2025-10-03 13:26:00.422071 | localhost | ok
2025-10-03 13:26:00.440951 | 
2025-10-03 13:26:00.441032 | PLAY [logserver.rdoproject.org]
2025-10-03 13:26:00.451999 | 
2025-10-03 13:26:00.452106 | TASK [Set zuul-log-path fact]
2025-10-03 13:26:00.469317 | logserver.rdoproject.org | ok
2025-10-03 13:26:00.483486 | 
2025-10-03 13:26:00.483598 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 13:26:00.510339 | logserver.rdoproject.org | ok
2025-10-03 13:26:00.516113 | 
2025-10-03 13:26:00.516203 | TASK [upload-logs : Create log directories]
2025-10-03 13:26:01.213045 | logserver.rdoproject.org | changed
2025-10-03 13:26:01.216667 | 
2025-10-03 13:26:01.216764 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 13:26:01.698735 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.014036
2025-10-03 13:26:01.704221 | 
2025-10-03 13:26:01.704303 | TASK [upload-logs : Upload logs to log server]
2025-10-03 13:26:02.621125 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 13:26:02.624197 | 
2025-10-03 13:26:02.624261 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 13:26:02.789631 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:26:02.791149 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:26:02.804074 | 
2025-10-03 13:26:02.804188 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 13:26:02.870143 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:26:02.870557 | 
2025-10-03 13:26:02.871275 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:26:02.884298 | 
2025-10-03 13:26:02.884418 | LOOP [upload-logs : Upload console log and json output]