2025-10-08 08:33:13.234846 | Job console starting...
2025-10-08 08:33:13.246872 | Updating repositories
2025-10-08 08:33:13.276828 | Preparing job workspace
2025-10-08 08:33:16.917083 | Running Ansible setup...
2025-10-08 08:33:20.733554 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 08:33:21.329001 | 
2025-10-08 08:33:21.329127 | PLAY [localhost]
2025-10-08 08:33:21.338813 | 
2025-10-08 08:33:21.338920 | TASK [Gathering Facts]
2025-10-08 08:33:22.353601 | localhost | ok
2025-10-08 08:33:22.373562 | 
2025-10-08 08:33:22.373753 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-08 08:33:22.747857 | localhost -> localhost | changed
2025-10-08 08:33:22.754101 | 
2025-10-08 08:33:22.754231 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-08 08:33:23.645878 | localhost -> localhost | changed
2025-10-08 08:33:23.655268 | 
2025-10-08 08:33:23.655395 | TASK [Setup log path fact]
2025-10-08 08:33:23.675684 | localhost | ok
2025-10-08 08:33:23.689061 | 
2025-10-08 08:33:23.689178 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 08:33:23.717316 | localhost | ok
2025-10-08 08:33:23.724895 | 
2025-10-08 08:33:23.724978 | TASK [emit-job-header : Print job information]
2025-10-08 08:33:23.774843 | # Job Information
2025-10-08 08:33:23.775046 | Ansible Version: 2.15.12
2025-10-08 08:33:23.775084 | Job: cifmw-molecule-cifmw_external_dns
2025-10-08 08:33:23.775113 | Pipeline: github-check
2025-10-08 08:33:23.775140 | Executor: ze03.softwarefactory-project.io
2025-10-08 08:33:23.775166 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3373
2025-10-08 08:33:23.775193 | Log URL (when completed): https://logserver.rdoproject.org/c2e/rdoproject.org/c2e14fa6c7a8476f92443cc827b1dc94/
2025-10-08 08:33:23.775219 | Event ID: 3a070520-a421-11f0-9b5a-2d6f635919d0
2025-10-08 08:33:23.780748 | 
2025-10-08 08:33:23.780864 | LOOP [emit-job-header : Print node information]
2025-10-08 08:33:23.921282 | localhost | ok:
2025-10-08 08:33:23.921509 | localhost | # Node Information
2025-10-08 08:33:23.921555 | localhost | Inventory Hostname: controller
2025-10-08 08:33:23.921588 | localhost | Hostname: np0005475440
2025-10-08 08:33:23.921617 | localhost | Username: zuul
2025-10-08 08:33:23.921644 | localhost | Distro: CentOS 9
2025-10-08 08:33:23.921663 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-08 08:33:23.921681 | localhost | Region: RegionOne
2025-10-08 08:33:23.921698 | localhost | Label: cloud-centos-9-stream-tripleo
2025-10-08 08:33:23.921715 | localhost | Product Name: OpenStack Nova
2025-10-08 08:33:23.921739 | localhost | Interface IP: 38.102.83.213
2025-10-08 08:33:23.949901 | 
2025-10-08 08:33:23.950041 | PLAY [all]
2025-10-08 08:33:23.969422 | 
2025-10-08 08:33:23.969549 | TASK [Gather network facts]
2025-10-08 08:33:24.503220 | controller | ok
2025-10-08 08:33:24.524681 | 
2025-10-08 08:33:24.524834 | TASK [include_role : start-zuul-console]
2025-10-08 08:33:24.545796 | controller | ok
2025-10-08 08:33:24.560958 | 
2025-10-08 08:33:24.561068 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-08 08:33:24.993417 | controller | ok
2025-10-08 08:33:25.015362 | 
2025-10-08 08:33:25.015518 | TASK [include_role : add-build-sshkey]
2025-10-08 08:33:25.047515 | controller | ok
2025-10-08 08:33:25.066197 | 
2025-10-08 08:33:25.066337 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-08 08:33:25.287873 | controller -> localhost | ok
2025-10-08 08:33:25.293455 | 
2025-10-08 08:33:25.293543 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-08 08:33:25.322534 | controller | ok
2025-10-08 08:33:25.335349 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-08 08:33:25.341043 | 
2025-10-08 08:33:25.341129 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-08 08:33:25.886327 | controller -> localhost | Generating public/private rsa key pair.
2025-10-08 08:33:25.886506 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/c2e14fa6c7a8476f92443cc827b1dc94_id_rsa.
2025-10-08 08:33:25.886538 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/c2e14fa6c7a8476f92443cc827b1dc94_id_rsa.pub.
2025-10-08 08:33:25.886561 | controller -> localhost | The key fingerprint is:
2025-10-08 08:33:25.886581 | controller -> localhost | SHA256:gWiFIbvQMkPjV2Ax2NUKXBUJNX8doJTzCdRuT7uUPuk zuul-build-sshkey
2025-10-08 08:33:25.886601 | controller -> localhost | The key's randomart image is:
2025-10-08 08:33:25.886621 | controller -> localhost | +---[RSA 3072]----+
2025-10-08 08:33:25.886639 | controller -> localhost | | o==*B*=+oo...   |
2025-10-08 08:33:25.886659 | controller -> localhost | |ooo*+o +++... .  |
2025-10-08 08:33:25.886677 | controller -> localhost | |=.o.+ o .o=...   |
2025-10-08 08:33:25.886696 | controller -> localhost | | =.o .   ..= .   |
2025-10-08 08:33:25.886714 | controller -> localhost | |  .     S . o o  |
2025-10-08 08:33:25.886736 | controller -> localhost | |             =   |
2025-10-08 08:33:25.886773 | controller -> localhost | |            o o  |
2025-10-08 08:33:25.886793 | controller -> localhost | |             =   |
2025-10-08 08:33:25.886811 | controller -> localhost | |            .E.  |
2025-10-08 08:33:25.886829 | controller -> localhost | +----[SHA256]-----+
2025-10-08 08:33:25.886870 | controller -> localhost | ok: Runtime: 0:00:00.092369
2025-10-08 08:33:25.892591 | 
2025-10-08 08:33:25.892678 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-08 08:33:25.911361 | controller | ok
2025-10-08 08:33:25.924516 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-08 08:33:25.932913 | 
2025-10-08 08:33:25.933029 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-08 08:33:25.946496 | controller | skipping: Conditional result was False
2025-10-08 08:33:25.952691 | 
2025-10-08 08:33:25.952837 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-08 08:33:26.431669 | controller | changed
2025-10-08 08:33:26.436509 | 
2025-10-08 08:33:26.436582 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-08 08:33:26.702453 | controller | ok
2025-10-08 08:33:26.707907 | 
2025-10-08 08:33:26.707968 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-08 08:33:27.543402 | controller | changed
2025-10-08 08:33:27.566223 | 
2025-10-08 08:33:27.566388 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-08 08:33:28.472577 | controller | changed
2025-10-08 08:33:28.480237 | 
2025-10-08 08:33:28.480346 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-08 08:33:28.506068 | controller | skipping: Conditional result was False
2025-10-08 08:33:28.513092 | 
2025-10-08 08:33:28.513199 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-08 08:33:28.904393 | controller -> localhost | changed
2025-10-08 08:33:28.914733 | 
2025-10-08 08:33:28.914848 | TASK [add-build-sshkey : Add back temp key]
2025-10-08 08:33:29.184200 | controller -> localhost | Identity added: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/c2e14fa6c7a8476f92443cc827b1dc94_id_rsa (zuul-build-sshkey)
2025-10-08 08:33:29.184429 | controller -> localhost | ok: Runtime: 0:00:00.008509
2025-10-08 08:33:29.190048 | 
2025-10-08 08:33:29.190108 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-08 08:33:29.592899 | controller | ok
2025-10-08 08:33:29.606196 | 
2025-10-08 08:33:29.606361 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-08 08:33:29.643700 | controller | skipping: Conditional result was False
2025-10-08 08:33:29.658589 | 
2025-10-08 08:33:29.658702 | TASK [include_role : validate-host]
2025-10-08 08:33:29.691350 | controller | ok
2025-10-08 08:33:29.719369 | 
2025-10-08 08:33:29.719476 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-08 08:33:29.776584 | controller | ok
2025-10-08 08:33:29.787510 | 
2025-10-08 08:33:29.787640 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-08 08:33:30.029411 | controller -> localhost | ok
2025-10-08 08:33:30.037905 | 
2025-10-08 08:33:30.038002 | TASK [validate-host : Collect information about the host]
2025-10-08 08:33:30.905681 | controller | ok
2025-10-08 08:33:30.918417 | 
2025-10-08 08:33:30.918524 | TASK [validate-host : Sanitize hostname]
2025-10-08 08:33:30.981059 | controller | ok
2025-10-08 08:33:30.988445 | 
2025-10-08 08:33:30.988564 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-08 08:33:31.474034 | controller -> localhost | changed
2025-10-08 08:33:31.487185 | 
2025-10-08 08:33:31.487807 | TASK [validate-host : Collect information about zuul worker]
2025-10-08 08:33:31.881396 | controller | ok
2025-10-08 08:33:31.894446 | 
2025-10-08 08:33:31.894608 | TASK [validate-host : Write out all zuul information for each host]
2025-10-08 08:33:32.364838 | controller -> localhost | changed
2025-10-08 08:33:32.383707 | 
2025-10-08 08:33:32.383830 | TASK [include_role : prepare-workspace-openshift]
2025-10-08 08:33:32.428061 | controller | skipping: Conditional result was False
2025-10-08 08:33:32.435932 | 
2025-10-08 08:33:32.436038 | TASK [include_role : remove-zuul-sshkey]
2025-10-08 08:33:32.449157 | controller | skipping: Conditional result was False
2025-10-08 08:33:32.460620 | 
2025-10-08 08:33:32.460753 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-08 08:33:32.746946 | controller | ok: "logs"
2025-10-08 08:33:32.747171 | controller | ok: All items complete
2025-10-08 08:33:32.747200 | 
2025-10-08 08:33:32.978374 | controller | ok: "artifacts"
2025-10-08 08:33:33.217805 | controller | ok: "docs"
2025-10-08 08:33:33.237777 | 
2025-10-08 08:33:33.237948 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-08 08:33:33.504932 | controller | changed: "logs"
2025-10-08 08:33:33.770357 | controller | changed: "artifacts"
2025-10-08 08:33:34.009795 | controller | changed: "docs"
2025-10-08 08:33:34.071325 | 
2025-10-08 08:33:34.071472 | PLAY RECAP
2025-10-08 08:33:34.071556 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 08:33:34.071612 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 08:33:34.071650 | 
2025-10-08 08:33:34.193899 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 08:33:34.194700 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-08 08:33:34.872635 | 
2025-10-08 08:33:34.872780 | PLAY [localhost]
2025-10-08 08:33:34.892334 | 
2025-10-08 08:33:34.892441 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-08 08:33:35.341338 | localhost | ok
2025-10-08 08:33:35.349402 | 
2025-10-08 08:33:35.349552 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-08 08:33:35.989069 | localhost | changed
2025-10-08 08:33:36.011162 | 
2025-10-08 08:33:36.011265 | PLAY [all]
2025-10-08 08:33:36.027177 | 
2025-10-08 08:33:36.027289 | TASK [include_role : prepare-workspace]
2025-10-08 08:33:36.056024 | controller | ok
2025-10-08 08:33:36.070490 | 
2025-10-08 08:33:36.070598 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-08 08:33:36.490190 | controller | ok
2025-10-08 08:33:36.505395 | 
2025-10-08 08:33:36.505571 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-08 08:33:38.206853 | controller | Output suppressed because no_log was given
2025-10-08 08:33:38.225140 | 
2025-10-08 08:33:38.225273 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-08 08:33:38.442976 | controller | changed: "logs"
2025-10-08 08:33:38.669609 | controller | changed: "artifacts"
2025-10-08 08:33:38.912043 | controller | changed: "docs"
2025-10-08 08:33:38.923714 | 
2025-10-08 08:33:38.923850 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-08 08:33:39.188501 | controller | changed: "logs"
2025-10-08 08:33:39.188938 | controller | changed: All items complete
2025-10-08 08:33:39.188996 | 
2025-10-08 08:33:39.396934 | controller | changed: "artifacts"
2025-10-08 08:33:39.653420 | controller | changed: "docs"
2025-10-08 08:33:39.686711 | 
2025-10-08 08:33:39.686860 | TASK [Check if worker can sudo]
2025-10-08 08:33:40.219273 | controller | ok: Runtime: 0:00:00.040704
2025-10-08 08:33:40.225253 | 
2025-10-08 08:33:40.225330 | TASK [configure-mirrors : Gather needed facts]
2025-10-08 08:33:40.320522 | controller | skipping: Conditional result was False
2025-10-08 08:33:40.326675 | 
2025-10-08 08:33:40.326774 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-08 08:33:40.396703 | controller | ok
2025-10-08 08:33:40.408390 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-08 08:33:40.414304 | 
2025-10-08 08:33:40.414429 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-08 08:33:40.863143 | controller | ok
2025-10-08 08:33:40.868622 | 
2025-10-08 08:33:40.868726 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-08 08:33:40.937487 | controller | ok: "/var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-10-08 08:33:40.954086 | 
2025-10-08 08:33:40.954239 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-08 08:33:41.843888 | controller | changed
2025-10-08 08:33:41.854183 | 
2025-10-08 08:33:41.854250 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-08 08:33:41.902644 | controller | ok: "/var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-10-08 08:33:41.902824 | controller | ok: All items complete
2025-10-08 08:33:41.902852 | 
2025-10-08 08:33:41.960235 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-10-08 08:33:41.977014 | 
2025-10-08 08:33:41.977133 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-10-08 08:33:42.803081 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-10-08 08:33:43.529433 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-10-08 08:33:43.545178 | 
2025-10-08 08:33:43.545303 | TASK [configure-mirrors : Disable deltrarpm]
2025-10-08 08:33:44.016560 | controller | changed: section and option added
2025-10-08 08:33:44.036123 | 
2025-10-08 08:33:44.036247 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-10-08 08:33:44.798858 | controller | 29 files removed
2025-10-08 08:33:44.799081 | controller | ok: Item: dnf clean all Runtime: 0:00:00.453883
2025-10-08 08:33:44.799120 | controller | changed: All items complete
2025-10-08 08:33:44.799140 | 
2025-10-08 08:33:55.554010 | 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-08 08:33:55.554131 | controller | DNF version: 4.14.0
2025-10-08 08:33:55.554166 | controller | cachedir: /var/cache/dnf
2025-10-08 08:33:55.554194 | controller | Making cache files for all metadata files.
2025-10-08 08:33:55.554221 | controller | baseos: has expired and will be refreshed.
2025-10-08 08:33:55.554246 | controller | appstream: has expired and will be refreshed.
2025-10-08 08:33:55.554269 | controller | crb: has expired and will be refreshed.
2025-10-08 08:33:55.554304 | controller | extras-common: has expired and will be refreshed.
2025-10-08 08:33:55.554329 | controller | repo: downloading from remote: baseos
2025-10-08 08:33:55.554353 | controller | CentOS Stream 9 - BaseOS                         80 MB/s | 8.8 MB     00:00
2025-10-08 08:33:55.554377 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT.
2025-10-08 08:33:55.554400 | controller | repo: downloading from remote: appstream
2025-10-08 08:33:55.554422 | controller | CentOS Stream 9 - AppStream                     109 MB/s |  25 MB     00:00
2025-10-08 08:33:55.554445 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT.
2025-10-08 08:33:55.554468 | controller | repo: downloading from remote: crb
2025-10-08 08:33:55.554507 | controller | CentOS Stream 9 - CRB                            64 MB/s | 7.1 MB     00:00
2025-10-08 08:33:55.554534 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT.
2025-10-08 08:33:55.554925 | controller | repo: downloading from remote: extras-common
2025-10-08 08:33:55.554990 | controller | CentOS Stream 9 - Extras packages               1.6 MB/s |  20 kB     00:00
2025-10-08 08:33:55.555025 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT.
2025-10-08 08:33:55.555058 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-10-08 08:33:55.555280 | controller | Completion plugin: Generating completion cache...
2025-10-08 08:33:55.555315 | controller | Metadata cache created.
2025-10-08 08:33:55.555353 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.488549
2025-10-08 08:33:55.585088 | 
2025-10-08 08:33:55.585231 | PLAY RECAP
2025-10-08 08:33:55.585304 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 08:33:55.585357 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 08:33:55.585387 | 
2025-10-08 08:33:55.705608 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-08 08:33:55.706824 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-08 08:33:56.292851 | 
2025-10-08 08:33:56.292978 | PLAY [all]
2025-10-08 08:33:56.315076 | 
2025-10-08 08:33:56.315201 | TASK [Install binary dependencies]
2025-10-08 08:33:56.395052 | controller | ok
2025-10-08 08:33:56.413967 | 
2025-10-08 08:33:56.414088 | TASK [bindep : Include find tasks]
2025-10-08 08:33:56.456110 | controller | ok
2025-10-08 08:33:56.467184 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-08 08:33:56.476105 | 
2025-10-08 08:33:56.476204 | TASK [bindep : Look for bindep.txt]
2025-10-08 08:33:56.933442 | controller | ok
2025-10-08 08:33:56.943406 | 
2025-10-08 08:33:56.943530 | TASK [bindep : Define bindep_file fact]
2025-10-08 08:33:56.998108 | controller | ok
2025-10-08 08:33:57.009355 | 
2025-10-08 08:33:57.009469 | TASK [bindep : Look for other-requirements.txt]
2025-10-08 08:33:57.034265 | controller | skipping: Conditional result was False
2025-10-08 08:33:57.042125 | 
2025-10-08 08:33:57.042241 | TASK [bindep : Define bindep_file fact]
2025-10-08 08:33:57.067708 | controller | skipping: Conditional result was False
2025-10-08 08:33:57.076336 | 
2025-10-08 08:33:57.076482 | TASK [bindep : Look for bindep fallback file]
2025-10-08 08:33:57.102929 | controller | skipping: Conditional result was False
2025-10-08 08:33:57.111726 | 
2025-10-08 08:33:57.111873 | TASK [bindep : Define bindep_file fact]
2025-10-08 08:33:57.138835 | controller | skipping: Conditional result was False
2025-10-08 08:33:57.147382 | 
2025-10-08 08:33:57.147502 | TASK [bindep : Include bindep tasks]
2025-10-08 08:33:57.189887 | controller | ok
2025-10-08 08:33:57.196902 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-10-08 08:33:57.205398 | 
2025-10-08 08:33:57.205501 | TASK [bindep : Look for bindep command]
2025-10-08 08:33:57.240523 | controller | skipping: Conditional result was False
2025-10-08 08:33:57.247339 | 
2025-10-08 08:33:57.247427 | TASK [bindep : Check for system bindep]
2025-10-08 08:33:57.779208 | controller | ok: Runtime: 0:00:00.009008
2025-10-08 08:33:57.792372 | 
2025-10-08 08:33:57.792597 | TASK [bindep : Define bindep_command fact]
2025-10-08 08:33:57.829622 | controller | skipping: Conditional result was False
2025-10-08 08:33:57.843316 | 
2025-10-08 08:33:57.843495 | TASK [bindep : Include install tasks]
2025-10-08 08:33:57.887728 | controller | ok
2025-10-08 08:33:57.899303 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-10-08 08:33:57.913981 | 
2025-10-08 08:33:57.914139 | TASK [bindep : Create temp dir for bindep]
2025-10-08 08:33:58.301834 | controller | changed
2025-10-08 08:33:58.307311 | 
2025-10-08 08:33:58.307375 | TASK [Ensure we have pip dependencies]
2025-10-08 08:33:58.336622 | controller | ok
2025-10-08 08:33:58.361202 | 
2025-10-08 08:33:58.361304 | TASK [ensure-pip : Check if pip is installed]
2025-10-08 04:33:58.650479 | controller | /usr/bin/pip3
2025-10-08 04:33:58.702224 | controller | /usr/bin/python3: No module named wheel
2025-10-08 08:33:58.893197 | controller | ok: Runtime: 0:00:00.068533
2025-10-08 08:33:58.905985 | 
2025-10-08 08:33:58.906158 | LOOP [ensure-pip : Install pip from packages]
2025-10-08 08:33:58.963622 | controller | ok: "/var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-10-08 08:33:58.993318 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-10-08 08:33:59.016461 | 
2025-10-08 08:33:59.016598 | TASK [ensure-pip : Install Python 3 pip]
2025-10-08 08:34:01.364858 | controller | changed
2025-10-08 08:34:01.373483 | 
2025-10-08 08:34:01.373562 | TASK [ensure-pip : Check for EPEL repository]
2025-10-08 08:34:01.417530 | controller | skipping: Conditional result was False
2025-10-08 08:34:01.423567 | 
2025-10-08 08:34:01.423659 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-10-08 08:34:01.457573 | controller | skipping: Conditional result was False
2025-10-08 08:34:01.464273 | 
2025-10-08 08:34:01.464343 | TASK [ensure-pip : Install Python 2 pip]
2025-10-08 08:34:01.499189 | controller | skipping: Conditional result was False
2025-10-08 08:34:01.506411 | 
2025-10-08 08:34:01.506485 | TASK [ensure-pip : Ensure setuptools]
2025-10-08 08:34:01.531079 | controller | skipping: Conditional result was False
2025-10-08 08:34:01.536941 | 
2025-10-08 08:34:01.537009 | TASK [ensure-pip : Check for ensurepip module]
2025-10-08 08:34:02.070824 | controller | skipping: Conditional result was False
2025-10-08 08:34:02.079547 | 
2025-10-08 08:34:02.079670 | TASK [ensure-pip : Ensure python3-venv]
2025-10-08 08:34:02.118458 | controller | skipping: Conditional result was False
2025-10-08 08:34:02.125640 | 
2025-10-08 08:34:02.125762 | TASK [ensure-pip : Install pip from source]
2025-10-08 08:34:02.140069 | controller | skipping: Conditional result was False
2025-10-08 08:34:02.149707 | 
2025-10-08 08:34:02.149857 | TASK [ensure-pip : Probe for venv python full path]
2025-10-08 04:34:02.443993 | controller | /usr/bin/python3
2025-10-08 08:34:02.726083 | controller | ok: Runtime: 0:00:00.006034
2025-10-08 08:34:02.733233 | 
2025-10-08 08:34:02.733340 | TASK [ensure-pip : Set host default]
2025-10-08 08:34:02.787383 | controller | ok
2025-10-08 08:34:02.796229 | 
2025-10-08 08:34:02.796358 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-10-08 08:34:02.858330 | controller | ok
2025-10-08 08:34:02.870341 | 
2025-10-08 08:34:02.870466 | TASK [bindep : Install bindep into temporary venv]
2025-10-08 08:34:07.232099 | controller | changed
2025-10-08 08:34:07.240534 | 
2025-10-08 08:34:07.240660 | TASK [bindep : Define bindep_command]
2025-10-08 08:34:07.283524 | controller | ok
2025-10-08 08:34:07.291372 | 
2025-10-08 08:34:07.291474 | LOOP [bindep : Include package tasks]
2025-10-08 08:34:07.363362 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-10-08 08:34:07.363669 | controller | ok: All items complete
2025-10-08 08:34:07.363758 | 
2025-10-08 08:34:07.386009 | controller | included: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-10-08 08:34:07.405461 | 
2025-10-08 08:34:07.405572 | TASK [bindep : Define bindep_run fact]
2025-10-08 08:34:07.435795 | controller | ok
2025-10-08 08:34:07.441077 | 
2025-10-08 08:34:07.441139 | TASK [bindep : Get list of packages to install from bindep]
2025-10-08 04:34:08.900708 | controller | podman
2025-10-08 04:34:08.939916 | controller | python3-jmespath
2025-10-08 04:34:08.940160 | controller | python3-libvirt
2025-10-08 04:34:08.940229 | controller | python3-lxml
2025-10-08 04:34:08.940239 | controller | python3-netaddr
2025-10-08 08:34:08.976645 | controller | ok: Runtime: 0:00:01.239321
2025-10-08 08:34:08.984130 | 
2025-10-08 08:34:08.984216 | TASK [bindep : Install distro packages from bindep]
2025-10-08 08:35:13.471788 | controller | changed
2025-10-08 08:35:13.479281 | 
2025-10-08 08:35:13.479372 | TASK [bindep : Check that packages are installed]
2025-10-08 08:35:15.017342 | controller | ok: Runtime: 0:00:01.217063
2025-10-08 08:35:15.025496 | 
2025-10-08 08:35:15.025600 | TASK [bindep : Fail if we cannot install all packages]
2025-10-08 08:35:15.061045 | controller | skipping: Conditional result was False
2025-10-08 08:35:15.076813 | 
2025-10-08 08:35:15.076969 | TASK [Run test-setup role]
2025-10-08 08:35:15.100795 | controller | ok
2025-10-08 08:35:15.130618 | 
2025-10-08 08:35:15.130801 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-08 08:35:15.372283 | controller | ok
2025-10-08 08:35:15.383846 | 
2025-10-08 08:35:15.384004 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-08 08:35:15.932754 | controller | skipping: Conditional result was False
2025-10-08 08:35:15.981210 | 
2025-10-08 08:35:15.981444 | TASK [bindep : Remove bindep temp dir]
2025-10-08 08:35:16.342381 | controller | ok
2025-10-08 08:35:16.357844 | 
2025-10-08 08:35:16.357966 | PLAY RECAP
2025-10-08 08:35:16.358027 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-10-08 08:35:16.358065 | 
2025-10-08 08:35:16.470812 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-08 08:35:16.471661 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-08 08:35:17.080592 | 
2025-10-08 08:35:17.080706 | PLAY [all]
2025-10-08 08:35:17.101503 | 
2025-10-08 08:35:17.101628 | TASK [Abort when test_command variable is undefined]
2025-10-08 08:35:17.127247 | controller | skipping: Conditional result was False
2025-10-08 08:35:17.133145 | 
2025-10-08 08:35:17.133242 | TASK [Convert test_command to list]
2025-10-08 08:35:17.167989 | controller | skipping: Conditional result was False
2025-10-08 08:35:17.175791 | 
2025-10-08 08:35:17.175914 | TASK [Use test_command list]
2025-10-08 08:35:17.225763 | controller | ok
2025-10-08 08:35:17.231915 | 
2025-10-08 08:35:17.232017 | LOOP [Run test_command]
2025-10-08 08:35:17.622602 | controller | no check to run
2025-10-08 08:35:17.622856 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006853
2025-10-08 08:35:17.672005 | 
2025-10-08 08:35:17.672129 | PLAY RECAP
2025-10-08 08:35:17.672191 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-08 08:35:17.672224 | 
2025-10-08 08:35:17.794601 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-10-08 08:35:17.795696 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-08 08:35:18.420849 | 
2025-10-08 08:35:18.420958 | PLAY [all]
2025-10-08 08:35:18.441099 | 
2025-10-08 08:35:18.441197 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-08 08:35:18.806829 | controller | changed: non-zero return code
2025-10-08 08:35:18.812261 | 
2025-10-08 08:35:18.812338 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-08 08:35:18.837205 | controller | skipping: Conditional result was False
2025-10-08 08:35:18.843317 | 
2025-10-08 08:35:18.843391 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-08 08:35:18.874426 | 
2025-10-08 08:35:18.874564 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-08 08:35:18.904863 | 
2025-10-08 08:35:18.905014 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-08 08:35:18.930016 | controller | skipping: Conditional result was False
2025-10-08 08:35:18.935936 | 
2025-10-08 08:35:18.936018 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-08 08:35:18.965326 | 
2025-10-08 08:35:18.965461 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-08 08:35:18.989984 | controller | skipping: Conditional result was False
2025-10-08 08:35:18.995150 | 
2025-10-08 08:35:18.995216 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-08 08:35:19.010109 | controller | skipping: Conditional result was False
2025-10-08 08:35:19.016229 | 
2025-10-08 08:35:19.016317 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-08 08:35:19.040785 | controller | skipping: Conditional result was False
2025-10-08 08:35:19.076880 | 
2025-10-08 08:35:19.077008 | PLAY RECAP
2025-10-08 08:35:19.077069 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-08 08:35:19.077099 | 
2025-10-08 08:35:19.176693 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-08 08:35:19.178357 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 08:35:19.778951 | 
2025-10-08 08:35:19.779065 | PLAY [all]
2025-10-08 08:35:19.798368 | 
2025-10-08 08:35:19.798478 | TASK [include_role : fetch-output]
2025-10-08 08:35:19.827701 | controller | ok
2025-10-08 08:35:19.844605 | 
2025-10-08 08:35:19.844693 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 08:35:19.909758 | controller | skipping: Conditional result was False
2025-10-08 08:35:19.915554 | 
2025-10-08 08:35:19.915625 | TASK [fetch-output : Set log path for single node]
2025-10-08 08:35:19.956475 | controller | ok
2025-10-08 08:35:19.961706 | 
2025-10-08 08:35:19.961829 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 08:35:20.404156 | controller -> localhost | ok: "/var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/logs"
2025-10-08 08:35:20.751013 | controller -> localhost | changed: "/var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/artifacts"
2025-10-08 08:35:21.002829 | controller -> localhost | changed: "/var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/docs"
2025-10-08 08:35:21.015953 | 
2025-10-08 08:35:21.016071 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 08:35:21.718245 | controller | changed: .d..t...... ./
2025-10-08 08:35:21.718585 | controller | changed: All items complete
2025-10-08 08:35:21.718644 | 
2025-10-08 08:35:22.229549 | controller | changed: .d..t...... ./
2025-10-08 08:35:22.738254 | controller | changed: .d..t...... ./
2025-10-08 08:35:22.757841 | 
2025-10-08 08:35:22.758013 | TASK [include_role : fetch-output-openshift]
2025-10-08 08:35:22.783977 | controller | skipping: Conditional result was False
2025-10-08 08:35:22.794150 | 
2025-10-08 08:35:22.794322 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-08 08:35:23.262979 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013051
2025-10-08 08:35:23.531672 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013683
2025-10-08 08:35:23.587680 | 
2025-10-08 08:35:23.587869 | PLAY [all]
2025-10-08 08:35:23.614179 | 
2025-10-08 08:35:23.614381 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-08 08:35:24.174347 | controller | changed
2025-10-08 08:35:24.219576 | 
2025-10-08 08:35:24.219700 | PLAY RECAP
2025-10-08 08:35:24.219781 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-08 08:35:24.219815 | 
2025-10-08 08:35:24.329128 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 08:35:24.329964 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-08 08:35:24.993146 | 
2025-10-08 08:35:24.993280 | PLAY [localhost]
2025-10-08 08:35:25.013014 | 
2025-10-08 08:35:25.013146 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-08 08:35:25.372824 | localhost | changed
2025-10-08 08:35:25.378172 | 
2025-10-08 08:35:25.378256 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-08 08:35:25.406612 | localhost | ok
2025-10-08 08:35:25.414863 | 
2025-10-08 08:35:25.414931 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-08 08:35:25.782880 | localhost | changed
2025-10-08 08:35:25.790893 | 
2025-10-08 08:35:25.791082 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-08 08:35:26.386316 | localhost | changed
2025-10-08 08:35:26.395518 | 
2025-10-08 08:35:26.395618 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-08 08:35:26.808448 | localhost | Identity added: /var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/tmp/ansible.ej1fu0sm (/var/lib/zuul/builds/c2e14fa6c7a8476f92443cc827b1dc94/work/tmp/ansible.ej1fu0sm)
2025-10-08 08:35:26.808689 | localhost | ok: Runtime: 0:00:00.010134
2025-10-08 08:35:26.816796 | 
2025-10-08 08:35:26.816934 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-08 08:35:27.118799 | localhost | ok: Runtime: 0:00:00.004311
2025-10-08 08:35:27.125970 | 
2025-10-08 08:35:27.126114 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-08 08:35:27.189828 | localhost | changed
2025-10-08 08:35:27.197106 | 
2025-10-08 08:35:27.197201 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-08 08:35:27.625236 | localhost | changed
2025-10-08 08:35:27.666280 | 
2025-10-08 08:35:27.666411 | PLAY [localhost]
2025-10-08 08:35:27.687063 | 
2025-10-08 08:35:27.687198 | TASK [Generate bulk log download script]
2025-10-08 08:35:27.711062 | localhost | ok
2025-10-08 08:35:27.728861 | 
2025-10-08 08:35:27.728997 | TASK [local-log-download : Check API endpoint is defined]
2025-10-08 08:35:27.758991 | localhost | ok: All assertions passed
2025-10-08 08:35:27.764280 | 
2025-10-08 08:35:27.764381 | TASK [local-log-download : Create download script]
2025-10-08 08:35:28.230352 | localhost -> localhost | changed
2025-10-08 08:35:28.252012 | 
2025-10-08 08:35:28.252193 | TASK [Register quick-download link]
2025-10-08 08:35:28.289275 | localhost | ok
2025-10-08 08:35:28.352599 | 
2025-10-08 08:35:28.352710 | PLAY [logserver.rdoproject.org]
2025-10-08 08:35:28.363272 | 
2025-10-08 08:35:28.363386 | TASK [Set zuul-log-path fact]
2025-10-08 08:35:28.381179 | logserver.rdoproject.org | ok
2025-10-08 08:35:28.390063 | 
2025-10-08 08:35:28.390167 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 08:35:28.417082 | logserver.rdoproject.org | ok
2025-10-08 08:35:28.422540 | 
2025-10-08 08:35:28.422630 | TASK [upload-logs : Create log directories]
2025-10-08 08:35:29.097718 | logserver.rdoproject.org | changed
2025-10-08 08:35:29.105618 | 
2025-10-08 08:35:29.105866 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-08 08:35:29.388964 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005208
2025-10-08 08:35:29.399457 | 
2025-10-08 08:35:29.399618 | TASK [upload-logs : Upload logs to log server]
2025-10-08 08:35:30.084076 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-08 08:35:30.087301 | 
2025-10-08 08:35:30.087375 | LOOP [upload-logs : Compress console log and json output]
2025-10-08 08:35:30.161442 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 08:35:30.175329 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 08:35:30.187796 | 
2025-10-08 08:35:30.187935 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-08 08:35:30.241262 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 08:35:30.241673 | 
2025-10-08 08:35:30.243950 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 08:35:30.262074 | 
2025-10-08 08:35:30.262256 | LOOP [upload-logs : Upload console log and json output]