2025-10-13 06:27:05.809651 | Job console starting...
2025-10-13 06:27:05.831089 | Updating repositories
2025-10-13 06:27:05.857244 | Preparing job workspace
2025-10-13 06:27:09.542689 | Running Ansible setup...
2025-10-13 06:27:13.268784 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:27:13.868830 | 
2025-10-13 06:27:13.868945 | PLAY [localhost]
2025-10-13 06:27:13.879270 | 
2025-10-13 06:27:13.879337 | TASK [Gathering Facts]
2025-10-13 06:27:14.824397 | localhost | ok
2025-10-13 06:27:14.840597 | 
2025-10-13 06:27:14.840953 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 06:27:15.260289 | localhost -> localhost | changed
2025-10-13 06:27:15.266409 | 
2025-10-13 06:27:15.266479 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 06:27:16.087044 | localhost -> localhost | changed
2025-10-13 06:27:16.095389 | 
2025-10-13 06:27:16.095455 | TASK [Setup log path fact]
2025-10-13 06:27:16.115937 | localhost | ok
2025-10-13 06:27:16.131571 | 
2025-10-13 06:27:16.131702 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:27:16.159286 | localhost | ok
2025-10-13 06:27:16.167326 | 
2025-10-13 06:27:16.167393 | TASK [emit-job-header : Print job information]
2025-10-13 06:27:16.214278 | # Job Information
2025-10-13 06:27:16.214434 | Ansible Version: 2.15.12
2025-10-13 06:27:16.214459 | Job: cifmw-molecule-cifmw_nfs
2025-10-13 06:27:16.214478 | Pipeline: github-check
2025-10-13 06:27:16.214495 | Executor: ze02.softwarefactory-project.io
2025-10-13 06:27:16.214512 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-13 06:27:16.214530 | Log URL (when completed): https://logserver.rdoproject.org/b3e/rdoproject.org/b3e63d60abc74061ac0115458432bc2c/
2025-10-13 06:27:16.214548 | Event ID: 676d34a0-a7fd-11f0-9cd7-9163a14421b5
2025-10-13 06:27:16.221709 | 
2025-10-13 06:27:16.221776 | LOOP [emit-job-header : Print node information]
2025-10-13 06:27:16.371727 | localhost | ok:
2025-10-13 06:27:16.372168 | localhost | # Node Information
2025-10-13 06:27:16.372204 | localhost | Inventory Hostname: controller
2025-10-13 06:27:16.372227 | localhost | Hostname: np0005482322
2025-10-13 06:27:16.372247 | localhost | Username: zuul
2025-10-13 06:27:16.372267 | localhost | Distro: CentOS 9
2025-10-13 06:27:16.372285 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-13 06:27:16.372302 | localhost | Region: RegionOne
2025-10-13 06:27:16.372319 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-13 06:27:16.372335 | localhost | Product Name: OpenStack Nova
2025-10-13 06:27:16.372352 | localhost | Interface IP: 38.102.83.5
2025-10-13 06:27:16.399225 | 
2025-10-13 06:27:16.399318 | PLAY [all]
2025-10-13 06:27:16.414456 | 
2025-10-13 06:27:16.414514 | TASK [Gather network facts]
2025-10-13 06:27:16.923351 | controller | ok
2025-10-13 06:27:16.941286 | 
2025-10-13 06:27:16.941374 | TASK [include_role : start-zuul-console]
2025-10-13 06:27:16.961145 | controller | ok
2025-10-13 06:27:16.997951 | 
2025-10-13 06:27:16.998064 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 06:27:17.448218 | controller | ok
2025-10-13 06:27:17.464602 | 
2025-10-13 06:27:17.464708 | TASK [include_role : add-build-sshkey]
2025-10-13 06:27:17.494754 | controller | ok
2025-10-13 06:27:17.525014 | 
2025-10-13 06:27:17.525141 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 06:27:17.742392 | controller -> localhost | ok
2025-10-13 06:27:17.747894 | 
2025-10-13 06:27:17.747961 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 06:27:17.776468 | controller | ok
2025-10-13 06:27:17.788860 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 06:27:17.794464 | 
2025-10-13 06:27:17.794520 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 06:27:18.447275 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 06:27:18.447477 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/b3e63d60abc74061ac0115458432bc2c_id_rsa.
2025-10-13 06:27:18.447508 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/b3e63d60abc74061ac0115458432bc2c_id_rsa.pub.
2025-10-13 06:27:18.447531 | controller -> localhost | The key fingerprint is:
2025-10-13 06:27:18.447550 | controller -> localhost | SHA256:J9HEnkInIkZzc9dw8L9d/Ebgt0ioNg6BN/sr2/wr+5U zuul-build-sshkey
2025-10-13 06:27:18.447569 | controller -> localhost | The key's randomart image is:
2025-10-13 06:27:18.447587 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 06:27:18.447605 | controller -> localhost | |   .o o ..=+.    |
2025-10-13 06:27:18.447624 | controller -> localhost | |    oo.oo+oo.    |
2025-10-13 06:27:18.447643 | controller -> localhost | |   . . o.+... .  |
2025-10-13 06:27:18.447678 | controller -> localhost | |      . ..o .o o |
2025-10-13 06:27:18.447702 | controller -> localhost | |     . +S... .o =|
2025-10-13 06:27:18.447721 | controller -> localhost | |      . +o. . o=+|
2025-10-13 06:27:18.447739 | controller -> localhost | |       o +   E..+|
2025-10-13 06:27:18.447756 | controller -> localhost | |       .B.. .  . |
2025-10-13 06:27:18.447774 | controller -> localhost | |       .oB*+.    |
2025-10-13 06:27:18.447791 | controller -> localhost | +----[SHA256]-----+
2025-10-13 06:27:18.447836 | controller -> localhost | ok: Runtime: 0:00:00.244931
2025-10-13 06:27:18.453298 | 
2025-10-13 06:27:18.453355 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 06:27:18.482308 | controller | ok
2025-10-13 06:27:18.491920 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 06:27:18.499615 | 
2025-10-13 06:27:18.499697 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 06:27:18.523304 | controller | skipping: Conditional result was False
2025-10-13 06:27:18.528631 | 
2025-10-13 06:27:18.528726 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 06:27:19.018589 | controller | changed
2025-10-13 06:27:19.023410 | 
2025-10-13 06:27:19.023479 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 06:27:19.297954 | controller | ok
2025-10-13 06:27:19.302834 | 
2025-10-13 06:27:19.302895 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 06:27:20.119848 | controller | changed
2025-10-13 06:27:20.127371 | 
2025-10-13 06:27:20.127469 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 06:27:20.964786 | controller | changed
2025-10-13 06:27:20.971755 | 
2025-10-13 06:27:20.971922 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 06:27:20.996632 | controller | skipping: Conditional result was False
2025-10-13 06:27:21.004429 | 
2025-10-13 06:27:21.004503 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 06:27:21.380138 | controller -> localhost | changed
2025-10-13 06:27:21.390083 | 
2025-10-13 06:27:21.390150 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 06:27:21.655911 | controller -> localhost | Identity added: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/b3e63d60abc74061ac0115458432bc2c_id_rsa (zuul-build-sshkey)
2025-10-13 06:27:21.656094 | controller -> localhost | ok: Runtime: 0:00:00.008291
2025-10-13 06:27:21.661395 | 
2025-10-13 06:27:21.661493 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 06:27:22.029214 | controller | ok
2025-10-13 06:27:22.034704 | 
2025-10-13 06:27:22.034764 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 06:27:22.062220 | controller | skipping: Conditional result was False
2025-10-13 06:27:22.075264 | 
2025-10-13 06:27:22.075329 | TASK [include_role : validate-host]
2025-10-13 06:27:22.113962 | controller | ok
2025-10-13 06:27:22.141409 | 
2025-10-13 06:27:22.141506 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 06:27:22.180719 | controller | ok
2025-10-13 06:27:22.185455 | 
2025-10-13 06:27:22.185514 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 06:27:22.491932 | controller -> localhost | ok
2025-10-13 06:27:22.497687 | 
2025-10-13 06:27:22.497747 | TASK [validate-host : Collect information about the host]
2025-10-13 06:27:23.296831 | controller | ok
2025-10-13 06:27:23.306116 | 
2025-10-13 06:27:23.306184 | TASK [validate-host : Sanitize hostname]
2025-10-13 06:27:23.355628 | controller | ok
2025-10-13 06:27:23.360765 | 
2025-10-13 06:27:23.360828 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 06:27:23.827759 | controller -> localhost | changed
2025-10-13 06:27:23.833380 | 
2025-10-13 06:27:23.833440 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 06:27:24.267206 | controller | ok
2025-10-13 06:27:24.272065 | 
2025-10-13 06:27:24.272132 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 06:27:24.746847 | controller -> localhost | changed
2025-10-13 06:27:24.763533 | 
2025-10-13 06:27:24.763685 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 06:27:24.777534 | controller | skipping: Conditional result was False
2025-10-13 06:27:24.784196 | 
2025-10-13 06:27:24.784271 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 06:27:24.800070 | controller | skipping: Conditional result was False
2025-10-13 06:27:24.806767 | 
2025-10-13 06:27:24.806857 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:27:25.102865 | controller | ok: "logs"
2025-10-13 06:27:25.103086 | controller | ok: All items complete
2025-10-13 06:27:25.103115 | 
2025-10-13 06:27:25.332234 | controller | ok: "artifacts"
2025-10-13 06:27:25.541913 | controller | ok: "docs"
2025-10-13 06:27:25.551972 | 
2025-10-13 06:27:25.552108 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:27:25.828320 | controller | changed: "logs"
2025-10-13 06:27:26.059971 | controller | changed: "artifacts"
2025-10-13 06:27:26.302414 | controller | changed: "docs"
2025-10-13 06:27:26.333632 | 
2025-10-13 06:27:26.333716 | PLAY RECAP
2025-10-13 06:27:26.333757 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 06:27:26.333782 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:27:26.333799 | 
2025-10-13 06:27:26.432272 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 06:27:26.433087 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:27:27.103338 | 
2025-10-13 06:27:27.103455 | PLAY [localhost]
2025-10-13 06:27:27.119914 | 
2025-10-13 06:27:27.119989 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-13 06:27:27.501215 | localhost | ok
2025-10-13 06:27:27.510642 | 
2025-10-13 06:27:27.510767 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-13 06:27:28.248531 | localhost | changed
2025-10-13 06:27:28.269287 | 
2025-10-13 06:27:28.269437 | PLAY [all]
2025-10-13 06:27:28.285289 | 
2025-10-13 06:27:28.285352 | TASK [include_role : prepare-workspace]
2025-10-13 06:27:28.304707 | controller | ok
2025-10-13 06:27:28.319979 | 
2025-10-13 06:27:28.320047 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 06:27:28.753448 | controller | ok
2025-10-13 06:27:28.764962 | 
2025-10-13 06:27:28.765147 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 06:27:30.507163 | controller | Output suppressed because no_log was given
2025-10-13 06:27:30.533126 | 
2025-10-13 06:27:30.533273 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 06:27:30.822694 | controller | changed: "logs"
2025-10-13 06:27:31.068168 | controller | changed: "artifacts"
2025-10-13 06:27:31.325514 | controller | changed: "docs"
2025-10-13 06:27:31.339920 | 
2025-10-13 06:27:31.340151 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 06:27:31.681210 | controller | changed: "logs"
2025-10-13 06:27:31.681730 | controller | changed: All items complete
2025-10-13 06:27:31.681763 | 
2025-10-13 06:27:31.911520 | controller | changed: "artifacts"
2025-10-13 06:27:32.117115 | controller | changed: "docs"
2025-10-13 06:27:32.135722 | 
2025-10-13 06:27:32.135841 | TASK [Check if worker can sudo]
2025-10-13 06:27:32.680527 | controller | ok: Runtime: 0:00:00.059722
2025-10-13 06:27:32.686034 | 
2025-10-13 06:27:32.686098 | TASK [configure-mirrors : Gather needed facts]
2025-10-13 06:27:32.730366 | controller | skipping: Conditional result was False
2025-10-13 06:27:32.736326 | 
2025-10-13 06:27:32.736397 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-13 06:27:32.841164 | controller | ok
2025-10-13 06:27:32.850589 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-13 06:27:32.861691 | 
2025-10-13 06:27:32.861761 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-13 06:27:33.201512 | controller | ok
2025-10-13 06:27:33.207300 | 
2025-10-13 06:27:33.207365 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-13 06:27:33.354408 | controller | ok: "/var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-13 06:27:33.377986 | 
2025-10-13 06:27:33.378118 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-13 06:27:34.297412 | controller | changed
2025-10-13 06:27:34.304582 | 
2025-10-13 06:27:34.304647 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-13 06:27:34.375263 | controller | ok: "/var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-13 06:27:34.375438 | controller | ok: All items complete
2025-10-13 06:27:34.375463 | 
2025-10-13 06:27:34.465497 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-13 06:27:34.484235 | 
2025-10-13 06:27:34.485141 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-13 06:27:35.536373 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-13 06:27:36.380267 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-13 06:27:36.388366 | 
2025-10-13 06:27:36.388479 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-13 06:27:36.957636 | controller | changed: section and option added
2025-10-13 06:27:36.981633 | 
2025-10-13 06:27:36.981742 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-13 06:27:37.840157 | controller | 29 files removed
2025-10-13 06:27:37.840525 | controller | ok: Item: dnf clean all Runtime: 0:00:00.514093
2025-10-13 06:27:37.840608 | controller | changed: All items complete
2025-10-13 06:27:37.840653 | 
2025-10-13 06:27:48.426806 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-10-13 06:27:48.426982 | controller | DNF version: 4.14.0
2025-10-13 06:27:48.427035 | controller | cachedir: /var/cache/dnf
2025-10-13 06:27:48.427077 | controller | Making cache files for all metadata files.
2025-10-13 06:27:48.427117 | controller | baseos: has expired and will be refreshed.
2025-10-13 06:27:48.427154 | controller | appstream: has expired and will be refreshed.
2025-10-13 06:27:48.427190 | controller | crb: has expired and will be refreshed.
2025-10-13 06:27:48.427243 | controller | extras-common: has expired and will be refreshed.
2025-10-13 06:27:48.427280 | controller | repo: downloading from remote: baseos
2025-10-13 06:27:48.427316 | controller | CentOS Stream 9 - BaseOS                         93 MB/s | 8.8 MB     00:00
2025-10-13 06:27:48.427352 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT.
2025-10-13 06:27:48.427388 | controller | repo: downloading from remote: appstream
2025-10-13 06:27:48.427423 | controller | CentOS Stream 9 - AppStream                     113 MB/s |  25 MB     00:00
2025-10-13 06:27:48.427460 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT.
2025-10-13 06:27:48.427495 | controller | repo: downloading from remote: crb
2025-10-13 06:27:48.427530 | controller | CentOS Stream 9 - CRB                            47 MB/s | 7.2 MB     00:00
2025-10-13 06:27:48.427566 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT.
2025-10-13 06:27:48.427602 | controller | repo: downloading from remote: extras-common
2025-10-13 06:27:48.427638 | controller | CentOS Stream 9 - Extras packages               1.2 MB/s |  20 kB     00:00
2025-10-13 06:27:48.427712 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-13 06:27:48.427754 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-13 06:27:48.427790 | controller | Completion plugin: Generating completion cache...
2025-10-13 06:27:48.427846 | controller | Metadata cache created.
2025-10-13 06:27:48.427903 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.289289
2025-10-13 06:27:48.453461 | 
2025-10-13 06:27:48.453566 | PLAY RECAP
2025-10-13 06:27:48.453648 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 06:27:48.453752 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 06:27:48.453794 | 
2025-10-13 06:27:48.569860 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-13 06:27:48.571048 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:27:49.163940 | 
2025-10-13 06:27:49.164039 | PLAY [all]
2025-10-13 06:27:49.184749 | 
2025-10-13 06:27:49.184835 | TASK [Install binary dependencies]
2025-10-13 06:27:49.224931 | controller | ok
2025-10-13 06:27:49.243604 | 
2025-10-13 06:27:49.243722 | TASK [bindep : Include find tasks]
2025-10-13 06:27:49.273079 | controller | ok
2025-10-13 06:27:49.280631 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-13 06:27:49.286575 | 
2025-10-13 06:27:49.286638 | TASK [bindep : Look for bindep.txt]
2025-10-13 06:27:49.724375 | controller | ok
2025-10-13 06:27:49.740553 | 
2025-10-13 06:27:49.740703 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:27:49.780957 | controller | ok
2025-10-13 06:27:49.788679 | 
2025-10-13 06:27:49.788744 | TASK [bindep : Look for other-requirements.txt]
2025-10-13 06:27:49.813674 | controller | skipping: Conditional result was False
2025-10-13 06:27:49.820551 | 
2025-10-13 06:27:49.820628 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:27:49.856221 | controller | skipping: Conditional result was False
2025-10-13 06:27:49.871219 | 
2025-10-13 06:27:49.871290 | TASK [bindep : Look for bindep fallback file]
2025-10-13 06:27:49.892835 | controller | skipping: Conditional result was False
2025-10-13 06:27:49.899023 | 
2025-10-13 06:27:49.899094 | TASK [bindep : Define bindep_file fact]
2025-10-13 06:27:49.923158 | controller | skipping: Conditional result was False
2025-10-13 06:27:49.928943 | 
2025-10-13 06:27:49.929009 | TASK [bindep : Include bindep tasks]
2025-10-13 06:27:49.958791 | controller | ok
2025-10-13 06:27:49.965563 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-13 06:27:49.973884 | 
2025-10-13 06:27:49.973948 | TASK [bindep : Look for bindep command]
2025-10-13 06:27:49.997761 | controller | skipping: Conditional result was False
2025-10-13 06:27:50.003856 | 
2025-10-13 06:27:50.003925 | TASK [bindep : Check for system bindep]
2025-10-13 06:27:50.532769 | controller | ok: Runtime: 0:00:00.005876
2025-10-13 06:27:50.544619 | 
2025-10-13 06:27:50.544932 | TASK [bindep : Define bindep_command fact]
2025-10-13 06:27:50.571299 | controller | skipping: Conditional result was False
2025-10-13 06:27:50.583423 | 
2025-10-13 06:27:50.583562 | TASK [bindep : Include install tasks]
2025-10-13 06:27:50.620241 | controller | ok
2025-10-13 06:27:50.636123 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-13 06:27:50.650801 | 
2025-10-13 06:27:50.650884 | TASK [bindep : Create temp dir for bindep]
2025-10-13 06:27:51.008559 | controller | changed
2025-10-13 06:27:51.016008 | 
2025-10-13 06:27:51.016092 | TASK [Ensure we have pip dependencies]
2025-10-13 06:27:51.039275 | controller | ok
2025-10-13 06:27:51.071934 | 
2025-10-13 06:27:51.072043 | TASK [ensure-pip : Check if pip is installed]
2025-10-13 02:27:51.394609 | controller | /usr/bin/pip3
2025-10-13 02:27:51.442682 | controller | /usr/bin/python3: No module named wheel
2025-10-13 06:27:51.603993 | controller | ok: Runtime: 0:00:00.063513
2025-10-13 06:27:51.618085 | 
2025-10-13 06:27:51.618367 | LOOP [ensure-pip : Install pip from packages]
2025-10-13 06:27:51.662894 | controller | ok: "/var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-13 06:27:51.682381 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-13 06:27:51.704800 | 
2025-10-13 06:27:51.704913 | TASK [ensure-pip : Install Python 3 pip]
2025-10-13 06:27:54.294281 | controller | changed
2025-10-13 06:27:54.306080 | 
2025-10-13 06:27:54.306214 | TASK [ensure-pip : Check for EPEL repository]
2025-10-13 06:27:54.364410 | controller | skipping: Conditional result was False
2025-10-13 06:27:54.377451 | 
2025-10-13 06:27:54.377590 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-13 06:27:54.436726 | controller | skipping: Conditional result was False
2025-10-13 06:27:54.445863 | 
2025-10-13 06:27:54.445960 | TASK [ensure-pip : Install Python 2 pip]
2025-10-13 06:27:54.481869 | controller | skipping: Conditional result was False
2025-10-13 06:27:54.491260 | 
2025-10-13 06:27:54.491354 | TASK [ensure-pip : Ensure setuptools]
2025-10-13 06:27:54.519474 | controller | skipping: Conditional result was False
2025-10-13 06:27:54.525456 | 
2025-10-13 06:27:54.525520 | TASK [ensure-pip : Check for ensurepip module]
2025-10-13 06:27:55.057109 | controller | skipping: Conditional result was False
2025-10-13 06:27:55.071121 | 
2025-10-13 06:27:55.071267 | TASK [ensure-pip : Ensure python3-venv]
2025-10-13 06:27:55.087520 | controller | skipping: Conditional result was False
2025-10-13 06:27:55.096016 | 
2025-10-13 06:27:55.096101 | TASK [ensure-pip : Install pip from source]
2025-10-13 06:27:55.121093 | controller | skipping: Conditional result was False
2025-10-13 06:27:55.129039 | 
2025-10-13 06:27:55.129129 | TASK [ensure-pip : Probe for venv python full path]
2025-10-13 02:27:55.431822 | controller | /usr/bin/python3
2025-10-13 06:27:55.667814 | controller | ok: Runtime: 0:00:00.008118
2025-10-13 06:27:55.679872 | 
2025-10-13 06:27:55.680006 | TASK [ensure-pip : Set host default]
2025-10-13 06:27:55.758217 | controller | ok
2025-10-13 06:27:55.769590 | 
2025-10-13 06:27:55.769763 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-13 06:27:55.833678 | controller | ok
2025-10-13 06:27:55.848600 | 
2025-10-13 06:27:55.848700 | TASK [bindep : Install bindep into temporary venv]
2025-10-13 06:28:00.206558 | controller | changed
2025-10-13 06:28:00.223499 | 
2025-10-13 06:28:00.223569 | TASK [bindep : Define bindep_command]
2025-10-13 06:28:00.257954 | controller | ok
2025-10-13 06:28:00.263064 | 
2025-10-13 06:28:00.263139 | LOOP [bindep : Include package tasks]
2025-10-13 06:28:00.321241 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-13 06:28:00.321418 | controller | ok: All items complete
2025-10-13 06:28:00.321444 | 
2025-10-13 06:28:00.336812 | controller | included: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-13 06:28:00.347257 | 
2025-10-13 06:28:00.347320 | TASK [bindep : Define bindep_run fact]
2025-10-13 06:28:00.376862 | controller | ok
2025-10-13 06:28:00.381888 | 
2025-10-13 06:28:00.381951 | TASK [bindep : Get list of packages to install from bindep]
2025-10-13 02:28:01.858122 | controller | podman
2025-10-13 02:28:01.887517 | controller | python3-jmespath
2025-10-13 02:28:01.887749 | controller | python3-libvirt
2025-10-13 02:28:01.887764 | controller | python3-lxml
2025-10-13 02:28:01.887773 | controller | python3-netaddr
2025-10-13 06:28:01.928578 | controller | ok: Runtime: 0:00:01.222893
2025-10-13 06:28:01.940435 | 
2025-10-13 06:28:01.940568 | TASK [bindep : Install distro packages from bindep]
2025-10-13 06:29:05.780993 | controller | changed
2025-10-13 06:29:05.794782 | 
2025-10-13 06:29:05.794923 | TASK [bindep : Check that packages are installed]
2025-10-13 06:29:07.847733 | controller | ok: Runtime: 0:00:01.257215
2025-10-13 06:29:07.862054 | 
2025-10-13 06:29:07.862202 | TASK [bindep : Fail if we cannot install all packages]
2025-10-13 06:29:07.900184 | controller | skipping: Conditional result was False
2025-10-13 06:29:07.923919 | 
2025-10-13 06:29:07.924063 | TASK [Run test-setup role]
2025-10-13 06:29:07.955371 | controller | ok
2025-10-13 06:29:07.983050 | 
2025-10-13 06:29:07.983154 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-13 06:29:08.248988 | controller | ok
2025-10-13 06:29:08.255835 | 
2025-10-13 06:29:08.255932 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-13 06:29:08.791459 | controller | skipping: Conditional result was False
2025-10-13 06:29:08.838284 | 
2025-10-13 06:29:08.838514 | TASK [bindep : Remove bindep temp dir]
2025-10-13 06:29:09.227066 | controller | ok
2025-10-13 06:29:09.237878 | 
2025-10-13 06:29:09.237933 | PLAY RECAP
2025-10-13 06:29:09.237975 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-13 06:29:09.237995 | 
2025-10-13 06:29:09.332338 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-13 06:29:09.334182 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:29:09.934959 | 
2025-10-13 06:29:09.935082 | PLAY [all]
2025-10-13 06:29:09.954243 | 
2025-10-13 06:29:09.954355 | TASK [Abort when test_command variable is undefined]
2025-10-13 06:29:09.998813 | controller | skipping: Conditional result was False
2025-10-13 06:29:10.004482 | 
2025-10-13 06:29:10.004556 | TASK [Convert test_command to list]
2025-10-13 06:29:10.048878 | controller | skipping: Conditional result was False
2025-10-13 06:29:10.055595 | 
2025-10-13 06:29:10.055733 | TASK [Use test_command list]
2025-10-13 06:29:10.124882 | controller | ok
2025-10-13 06:29:10.130078 | 
2025-10-13 06:29:10.130139 | LOOP [Run test_command]
2025-10-13 06:29:10.519630 | controller | no check to run
2025-10-13 06:29:10.519974 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008277
2025-10-13 06:29:10.540631 | 
2025-10-13 06:29:10.540756 | PLAY RECAP
2025-10-13 06:29:10.540868 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:29:10.540894 | 
2025-10-13 06:29:10.635863 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-13 06:29:10.637739 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:29:11.274223 | 
2025-10-13 06:29:11.274338 | PLAY [all]
2025-10-13 06:29:11.295131 | 
2025-10-13 06:29:11.295219 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-13 06:29:11.690805 | controller | changed: non-zero return code
2025-10-13 06:29:11.705405 | 
2025-10-13 06:29:11.705749 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-13 06:29:11.734473 | controller | skipping: Conditional result was False
2025-10-13 06:29:11.747608 | 
2025-10-13 06:29:11.747801 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-13 06:29:11.788849 | 
2025-10-13 06:29:11.789110 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-13 06:29:11.824087 | 
2025-10-13 06:29:11.824276 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-13 06:29:11.848898 | controller | skipping: Conditional result was False
2025-10-13 06:29:11.855390 | 
2025-10-13 06:29:11.855454 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-13 06:29:11.885075 | 
2025-10-13 06:29:11.885205 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-13 06:29:11.898747 | controller | skipping: Conditional result was False
2025-10-13 06:29:11.904522 | 
2025-10-13 06:29:11.904584 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-13 06:29:11.918494 | controller | skipping: Conditional result was False
2025-10-13 06:29:11.924132 | 
2025-10-13 06:29:11.924192 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-13 06:29:11.937907 | controller | skipping: Conditional result was False
2025-10-13 06:29:11.962808 | 
2025-10-13 06:29:11.962864 | PLAY RECAP
2025-10-13 06:29:11.962903 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-13 06:29:11.962922 | 
2025-10-13 06:29:12.054160 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-13 06:29:12.055019 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:29:12.637852 | 
2025-10-13 06:29:12.637958 | PLAY [all]
2025-10-13 06:29:12.656486 | 
2025-10-13 06:29:12.656562 | TASK [include_role : fetch-output]
2025-10-13 06:29:12.685178 | controller | ok
2025-10-13 06:29:12.701757 | 
2025-10-13 06:29:12.701834 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 06:29:12.766509 | controller | skipping: Conditional result was False
2025-10-13 06:29:12.774185 | 
2025-10-13 06:29:12.774274 | TASK [fetch-output : Set log path for single node]
2025-10-13 06:29:12.820211 | controller | ok
2025-10-13 06:29:12.831803 | 
2025-10-13 06:29:12.831941 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 06:29:13.298335 | controller -> localhost | ok: "/var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/logs"
2025-10-13 06:29:13.554859 | controller -> localhost | changed: "/var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/artifacts"
2025-10-13 06:29:13.799693 | controller -> localhost | changed: "/var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/docs"
2025-10-13 06:29:13.828878 | 
2025-10-13 06:29:13.829140 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 06:29:14.562399 | controller | changed: .d..t...... ./
2025-10-13 06:29:14.562995 | controller | changed: All items complete
2025-10-13 06:29:14.563076 | 
2025-10-13 06:29:15.088807 | controller | changed: .d..t...... ./
2025-10-13 06:29:15.551608 | controller | changed: .d..t...... ./
2025-10-13 06:29:15.584190 | 
2025-10-13 06:29:15.584340 | TASK [include_role : fetch-output-openshift]
2025-10-13 06:29:15.598895 | controller | skipping: Conditional result was False
2025-10-13 06:29:15.607566 | 
2025-10-13 06:29:15.607689 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 06:29:16.023054 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.027538
2025-10-13 06:29:16.249389 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007990
2025-10-13 06:29:16.280340 | 
2025-10-13 06:29:16.280445 | PLAY [all]
2025-10-13 06:29:16.294957 | 
2025-10-13 06:29:16.295024 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 06:29:16.761647 | controller | changed
2025-10-13 06:29:16.805252 | 
2025-10-13 06:29:16.805344 | PLAY RECAP
2025-10-13 06:29:16.805383 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 06:29:16.805404 | 
2025-10-13 06:29:16.982529 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 06:29:16.983372 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 06:29:17.593954 | 
2025-10-13 06:29:17.594068 | PLAY [localhost]
2025-10-13 06:29:17.612540 | 
2025-10-13 06:29:17.612625 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 06:29:17.983164 | localhost | changed
2025-10-13 06:29:17.987929 | 
2025-10-13 06:29:17.988003 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 06:29:18.019894 | localhost | ok
2025-10-13 06:29:18.029404 | 
2025-10-13 06:29:18.029480 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 06:29:18.356825 | localhost | changed
2025-10-13 06:29:18.363984 | 
2025-10-13 06:29:18.364119 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 06:29:18.985032 | localhost | changed
2025-10-13 06:29:18.990166 | 
2025-10-13 06:29:18.990231 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 06:29:19.347454 | localhost | Identity added: /var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/tmp/ansible.2vczeyo5 (/var/lib/zuul/builds/b3e63d60abc74061ac0115458432bc2c/work/tmp/ansible.2vczeyo5)
2025-10-13 06:29:19.347632 | localhost | ok: Runtime: 0:00:00.008017
2025-10-13 06:29:19.352311 | 
2025-10-13 06:29:19.352376 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 06:29:19.615191 | localhost | ok: Runtime: 0:00:00.017887
2025-10-13 06:29:19.621655 | 
2025-10-13 06:29:19.621797 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 06:29:19.681532 | localhost | changed
2025-10-13 06:29:19.686716 | 
2025-10-13 06:29:19.686846 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 06:29:20.059283 | localhost | changed
2025-10-13 06:29:20.079553 | 
2025-10-13 06:29:20.079612 | PLAY [localhost]
2025-10-13 06:29:20.091168 | 
2025-10-13 06:29:20.091286 | TASK [Generate bulk log download script]
2025-10-13 06:29:20.114626 | localhost | ok
2025-10-13 06:29:20.126691 | 
2025-10-13 06:29:20.126757 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 06:29:20.155633 | localhost | ok: All assertions passed
2025-10-13 06:29:20.160199 | 
2025-10-13 06:29:20.160259 | TASK [local-log-download : Create download script]
2025-10-13 06:29:20.579510 | localhost -> localhost | changed
2025-10-13 06:29:20.588196 | 
2025-10-13 06:29:20.588254 | TASK [Register quick-download link]
2025-10-13 06:29:20.605392 | localhost | ok
2025-10-13 06:29:20.645994 | 
2025-10-13 06:29:20.646097 | PLAY [logserver.rdoproject.org]
2025-10-13 06:29:20.661146 | 
2025-10-13 06:29:20.661219 | TASK [Set zuul-log-path fact]
2025-10-13 06:29:20.687909 | logserver.rdoproject.org | ok
2025-10-13 06:29:20.698601 | 
2025-10-13 06:29:20.698699 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 06:29:20.724590 | logserver.rdoproject.org | ok
2025-10-13 06:29:20.730194 | 
2025-10-13 06:29:20.730256 | TASK [upload-logs : Create log directories]
2025-10-13 06:29:21.414605 | logserver.rdoproject.org | changed
2025-10-13 06:29:21.422904 | 
2025-10-13 06:29:21.423010 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 06:29:21.733809 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.013002
2025-10-13 06:29:21.739607 | 
2025-10-13 06:29:21.739840 | TASK [upload-logs : Upload logs to log server]
2025-10-13 06:29:22.373597 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 06:29:22.377043 | 
2025-10-13 06:29:22.377108 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 06:29:22.427047 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:29:22.427838 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:29:22.442161 | 
2025-10-13 06:29:22.442277 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 06:29:22.484768 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:29:22.485032 | 
2025-10-13 06:29:22.485543 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 06:29:22.489651 | 
2025-10-13 06:29:22.489791 | LOOP [upload-logs : Upload console log and json output]