2025-11-24 08:34:18.605365 | Job console starting...
2025-11-24 08:34:18.614347 | Updating repositories
2025-11-24 08:34:18.653690 | Preparing job workspace
2025-11-24 08:34:23.900281 | Running Ansible setup...
2025-11-24 08:34:28.295549 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:34:29.089298 | 
2025-11-24 08:34:29.089451 | PLAY [localhost]
2025-11-24 08:34:29.099282 | 
2025-11-24 08:34:29.099380 | TASK [Gathering Facts]
2025-11-24 08:34:30.370169 | localhost | ok
2025-11-24 08:34:30.392914 | 
2025-11-24 08:34:30.393105 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-24 08:34:30.869456 | localhost -> localhost | changed
2025-11-24 08:34:30.885473 | 
2025-11-24 08:34:30.885645 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-24 08:34:31.999683 | localhost -> localhost | changed
2025-11-24 08:34:32.009237 | 
2025-11-24 08:34:32.011852 | TASK [Setup log path fact]
2025-11-24 08:34:32.052960 | localhost | ok
2025-11-24 08:34:32.065500 | 
2025-11-24 08:34:32.065583 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:34:32.109466 | localhost | ok
2025-11-24 08:34:32.122382 | 
2025-11-24 08:34:32.122549 | TASK [emit-job-header : Print job information]
2025-11-24 08:34:32.164249 | # Job Information
2025-11-24 08:34:32.164498 | Ansible Version: 2.15.12
2025-11-24 08:34:32.164527 | Job: cifmw-molecule-cifmw_external_dns
2025-11-24 08:34:32.164547 | Pipeline: github-check
2025-11-24 08:34:32.164565 | Executor: ze01.softwarefactory-project.io
2025-11-24 08:34:32.164582 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451
2025-11-24 08:34:32.164600 | Log URL (when completed): https://logserver.rdoproject.org/e37/rdoproject.org/e374bd7cf16e4094a662a0ca8c32550a/
2025-11-24 08:34:32.164618 | Event ID: 2dae9040-c910-11f0-818a-433f9d14d6bc
2025-11-24 08:34:32.168830 | 
2025-11-24 08:34:32.168903 | LOOP [emit-job-header : Print node information]
2025-11-24 08:34:32.308784 | localhost | ok:
2025-11-24 08:34:32.309060 | localhost | # Node Information
2025-11-24 08:34:32.309094 | localhost | Inventory Hostname: controller
2025-11-24 08:34:32.309120 | localhost | Hostname: np0005533173
2025-11-24 08:34:32.309139 | localhost | Username: zuul
2025-11-24 08:34:32.309159 | localhost | Distro: CentOS 9
2025-11-24 08:34:32.309177 | localhost | Provider: vexxhost-nodepool-tripleo
2025-11-24 08:34:32.309194 | localhost | Region: RegionOne
2025-11-24 08:34:32.309210 | localhost | Label: cloud-centos-9-stream-tripleo
2025-11-24 08:34:32.309228 | localhost | Product Name: OpenStack Nova
2025-11-24 08:34:32.309245 | localhost | Interface IP: 38.129.56.55
2025-11-24 08:34:32.339765 | 
2025-11-24 08:34:32.339926 | PLAY [all]
2025-11-24 08:34:32.348194 | 
2025-11-24 08:34:32.348315 | TASK [Gather network facts]
2025-11-24 08:34:32.862922 | controller | ok
2025-11-24 08:34:32.883854 | 
2025-11-24 08:34:32.883970 | TASK [include_role : start-zuul-console]
2025-11-24 08:34:32.903950 | controller | ok
2025-11-24 08:34:32.916334 | 
2025-11-24 08:34:32.916444 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-24 08:34:33.326596 | controller | ok
2025-11-24 08:34:33.349573 | 
2025-11-24 08:34:33.349708 | TASK [include_role : add-build-sshkey]
2025-11-24 08:34:33.371076 | controller | ok
2025-11-24 08:34:33.386845 | 
2025-11-24 08:34:33.387260 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-24 08:34:33.636679 | controller -> localhost | ok
2025-11-24 08:34:33.642940 | 
2025-11-24 08:34:33.643046 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-24 08:34:33.671356 | controller | ok
2025-11-24 08:34:33.684520 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-24 08:34:33.690936 | 
2025-11-24 08:34:33.691030 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-24 08:34:34.594576 | controller -> localhost | Generating public/private rsa key pair.
2025-11-24 08:34:34.594798 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/e374bd7cf16e4094a662a0ca8c32550a_id_rsa.
2025-11-24 08:34:34.594831 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/e374bd7cf16e4094a662a0ca8c32550a_id_rsa.pub.
2025-11-24 08:34:34.594854 | controller -> localhost | The key fingerprint is:
2025-11-24 08:34:34.594874 | controller -> localhost | SHA256:yMAhElSpwm1XJ5OLA7rDHrCWp1aUrCD8rHtb/rrBYC4 zuul-build-sshkey
2025-11-24 08:34:34.594893 | controller -> localhost | The key's randomart image is:
2025-11-24 08:34:34.594912 | controller -> localhost | +---[RSA 3072]----+
2025-11-24 08:34:34.594929 | controller -> localhost | |+oo.o   .        |
2025-11-24 08:34:34.594948 | controller -> localhost | | . = . = .       |
2025-11-24 08:34:34.594966 | controller -> localhost | |o = = o =        |
2025-11-24 08:34:34.594985 | controller -> localhost | |== * * o         |
2025-11-24 08:34:34.595003 | controller -> localhost | |*.Oo. + S        |
2025-11-24 08:34:34.595050 | controller -> localhost | |.Oo=o            |
2025-11-24 08:34:34.595070 | controller -> localhost | |oEB. +           |
2025-11-24 08:34:34.595091 | controller -> localhost | | =..o .          |
2025-11-24 08:34:34.595110 | controller -> localhost | |..o..++.         |
2025-11-24 08:34:34.595127 | controller -> localhost | +----[SHA256]-----+
2025-11-24 08:34:34.595174 | controller -> localhost | ok: Runtime: 0:00:00.463014
2025-11-24 08:34:34.602385 | 
2025-11-24 08:34:34.602487 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-24 08:34:34.666158 | controller | ok
2025-11-24 08:34:34.680332 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-24 08:34:34.689865 | 
2025-11-24 08:34:34.689946 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-24 08:34:34.723645 | controller | skipping: Conditional result was False
2025-11-24 08:34:34.729932 | 
2025-11-24 08:34:34.730054 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-24 08:34:35.344846 | controller | changed
2025-11-24 08:34:35.354849 | 
2025-11-24 08:34:35.354927 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-24 08:34:35.676840 | controller | ok
2025-11-24 08:34:35.687908 | 
2025-11-24 08:34:35.688048 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-24 08:34:36.506676 | controller | changed
2025-11-24 08:34:36.516529 | 
2025-11-24 08:34:36.516700 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-24 08:34:37.391801 | controller | changed
2025-11-24 08:34:37.402889 | 
2025-11-24 08:34:37.403041 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-24 08:34:37.458788 | controller | skipping: Conditional result was False
2025-11-24 08:34:37.464929 | 
2025-11-24 08:34:37.465088 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-24 08:34:38.073350 | controller -> localhost | changed
2025-11-24 08:34:38.085490 | 
2025-11-24 08:34:38.085580 | TASK [add-build-sshkey : Add back temp key]
2025-11-24 08:34:38.650380 | controller -> localhost | Identity added: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/e374bd7cf16e4094a662a0ca8c32550a_id_rsa (zuul-build-sshkey)
2025-11-24 08:34:38.650560 | controller -> localhost | ok: Runtime: 0:00:00.008091
2025-11-24 08:34:38.656764 | 
2025-11-24 08:34:38.656854 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-24 08:34:39.083577 | controller | ok
2025-11-24 08:34:39.093580 | 
2025-11-24 08:34:39.093704 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-24 08:34:39.118547 | controller | skipping: Conditional result was False
2025-11-24 08:34:39.131306 | 
2025-11-24 08:34:39.131442 | TASK [include_role : validate-host]
2025-11-24 08:34:39.182126 | controller | ok
2025-11-24 08:34:39.206061 | 
2025-11-24 08:34:39.206187 | TASK [validate-host : Define zuul_info_dir fact]
2025-11-24 08:34:39.269750 | controller | ok
2025-11-24 08:34:39.274657 | 
2025-11-24 08:34:39.274739 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-11-24 08:34:39.655999 | controller -> localhost | ok
2025-11-24 08:34:39.687792 | 
2025-11-24 08:34:39.689823 | TASK [validate-host : Collect information about the host]
2025-11-24 08:34:40.521580 | controller | ok
2025-11-24 08:34:40.541391 | 
2025-11-24 08:34:40.541525 | TASK [validate-host : Sanitize hostname]
2025-11-24 08:34:40.590919 | controller | ok
2025-11-24 08:34:40.595923 | 
2025-11-24 08:34:40.595986 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-11-24 08:34:41.101443 | controller -> localhost | changed
2025-11-24 08:34:41.107877 | 
2025-11-24 08:34:41.107953 | TASK [validate-host : Collect information about zuul worker]
2025-11-24 08:34:41.490511 | controller | ok
2025-11-24 08:34:41.496966 | 
2025-11-24 08:34:41.497099 | TASK [validate-host : Write out all zuul information for each host]
2025-11-24 08:34:41.987565 | controller -> localhost | changed
2025-11-24 08:34:41.997641 | 
2025-11-24 08:34:41.997738 | TASK [include_role : prepare-workspace-openshift]
2025-11-24 08:34:42.015493 | controller | skipping: Conditional result was False
2025-11-24 08:34:42.021965 | 
2025-11-24 08:34:42.022106 | TASK [include_role : remove-zuul-sshkey]
2025-11-24 08:34:42.040802 | controller | skipping: Conditional result was False
2025-11-24 08:34:42.047221 | 
2025-11-24 08:34:42.047337 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-24 08:34:42.314411 | controller | ok: "logs"
2025-11-24 08:34:42.314682 | controller | ok: All items complete
2025-11-24 08:34:42.314712 | 
2025-11-24 08:34:42.531738 | controller | ok: "artifacts"
2025-11-24 08:34:42.734858 | controller | ok: "docs"
2025-11-24 08:34:42.748415 | 
2025-11-24 08:34:42.748543 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-24 08:34:42.992373 | controller | changed: "logs"
2025-11-24 08:34:43.253373 | controller | changed: "artifacts"
2025-11-24 08:34:43.484277 | controller | changed: "docs"
2025-11-24 08:34:43.519877 | 
2025-11-24 08:34:43.520108 | PLAY RECAP
2025-11-24 08:34:43.520193 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 08:34:43.520286 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:34:43.520318 | 
2025-11-24 08:34:43.732386 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:34:43.733196 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-11-24 08:34:44.427776 | 
2025-11-24 08:34:44.428962 | PLAY [localhost]
2025-11-24 08:34:44.447573 | 
2025-11-24 08:34:44.447726 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-11-24 08:34:44.969271 | localhost | ok
2025-11-24 08:34:44.976139 | 
2025-11-24 08:34:44.976281 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-11-24 08:34:45.727093 | localhost | changed
2025-11-24 08:34:45.755419 | 
2025-11-24 08:34:45.755531 | PLAY [all]
2025-11-24 08:34:45.776936 | 
2025-11-24 08:34:45.777081 | TASK [include_role : prepare-workspace]
2025-11-24 08:34:45.806640 | controller | ok
2025-11-24 08:34:45.826363 | 
2025-11-24 08:34:45.826492 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-24 08:34:46.254547 | controller | ok
2025-11-24 08:34:46.263009 | 
2025-11-24 08:34:46.263204 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-24 08:34:48.558689 | controller | Output suppressed because no_log was given
2025-11-24 08:34:48.569771 | 
2025-11-24 08:34:48.569859 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-24 08:34:48.784306 | controller | changed: "logs"
2025-11-24 08:34:49.029797 | controller | changed: "artifacts"
2025-11-24 08:34:49.257637 | controller | changed: "docs"
2025-11-24 08:34:49.272402 | 
2025-11-24 08:34:49.272552 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-24 08:34:49.513463 | controller | changed: "logs"
2025-11-24 08:34:49.513746 | controller | changed: All items complete
2025-11-24 08:34:49.513785 | 
2025-11-24 08:34:49.744388 | controller | changed: "artifacts"
2025-11-24 08:34:49.969149 | controller | changed: "docs"
2025-11-24 08:34:49.997606 | 
2025-11-24 08:34:49.997764 | TASK [Check if worker can sudo]
2025-11-24 08:34:51.077979 | controller | ok: Runtime: 0:00:00.036965
2025-11-24 08:34:51.084488 | 
2025-11-24 08:34:51.084560 | TASK [configure-mirrors : Gather needed facts]
2025-11-24 08:34:51.190288 | controller | skipping: Conditional result was False
2025-11-24 08:34:51.196618 | 
2025-11-24 08:34:51.196688 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-11-24 08:34:51.335690 | controller | ok
2025-11-24 08:34:51.344243 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-11-24 08:34:51.350309 | 
2025-11-24 08:34:51.350444 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-11-24 08:34:51.671318 | controller | ok
2025-11-24 08:34:51.677642 | 
2025-11-24 08:34:51.677726 | LOOP [configure-mirrors : Include OS-specific variables]
2025-11-24 08:34:51.818897 | controller | ok: "/var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-11-24 08:34:51.832853 | 
2025-11-24 08:34:51.832988 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-11-24 08:34:52.827624 | controller | changed
2025-11-24 08:34:52.840086 | 
2025-11-24 08:34:52.840226 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-11-24 08:34:52.997914 | controller | ok: "/var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-11-24 08:34:52.998368 | controller | ok: All items complete
2025-11-24 08:34:52.998413 | 
2025-11-24 08:34:53.069973 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-11-24 08:34:53.089886 | 
2025-11-24 08:34:53.090077 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-11-24 08:34:54.075724 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-11-24 08:34:54.896182 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-11-24 08:34:54.910819 | 
2025-11-24 08:34:54.911031 | TASK [configure-mirrors : Disable deltrarpm]
2025-11-24 08:34:55.372932 | controller | changed: section and option added
2025-11-24 08:34:55.393523 | 
2025-11-24 08:34:55.393662 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-11-24 08:34:56.268353 | controller | 29 files removed
2025-11-24 08:34:56.268596 | controller | ok: Item: dnf clean all Runtime: 0:00:00.580693
2025-11-24 08:34:56.268639 | controller | changed: All items complete
2025-11-24 08:34:56.268663 | 
2025-11-24 08:35:07.236163 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-11-24 08:35:07.236322 | controller | DNF version: 4.14.0
2025-11-24 08:35:07.236366 | controller | cachedir: /var/cache/dnf
2025-11-24 08:35:07.236408 | controller | Making cache files for all metadata files.
2025-11-24 08:35:07.236448 | controller | baseos: has expired and will be refreshed.
2025-11-24 08:35:07.236482 | controller | appstream: has expired and will be refreshed.
2025-11-24 08:35:07.236513 | controller | crb: has expired and will be refreshed.
2025-11-24 08:35:07.243140 | controller | extras-common: has expired and will be refreshed.
2025-11-24 08:35:07.243258 | controller | repo: downloading from remote: baseos
2025-11-24 08:35:07.243291 | controller | CentOS Stream 9 - BaseOS                         66 MB/s | 8.8 MB     00:00
2025-11-24 08:35:07.243318 | controller | baseos: using metadata from Mon 17 Nov 2025 10:24:02 AM EST.
2025-11-24 08:35:07.243344 | controller | repo: downloading from remote: appstream
2025-11-24 08:35:07.243369 | controller | CentOS Stream 9 - AppStream                      48 MB/s |  25 MB     00:00
2025-11-24 08:35:07.243393 | controller | appstream: using metadata from Mon 17 Nov 2025 10:27:35 AM EST.
2025-11-24 08:35:07.243416 | controller | repo: downloading from remote: crb
2025-11-24 08:35:07.243440 | controller | CentOS Stream 9 - CRB                            78 MB/s | 7.3 MB     00:00
2025-11-24 08:35:07.243465 | controller | crb: using metadata from Mon 17 Nov 2025 10:32:16 AM EST.
2025-11-24 08:35:07.243489 | controller | repo: downloading from remote: extras-common
2025-11-24 08:35:07.243513 | controller | CentOS Stream 9 - Extras packages               675 kB/s |  20 kB     00:00
2025-11-24 08:35:07.243536 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-11-24 08:35:07.243559 | controller | Last metadata expiration check: 0:00:01 ago on Mon 24 Nov 2025 03:35:05 AM EST.
2025-11-24 08:35:07.243583 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-11-24 08:35:07.243614 | controller | Completion plugin: Generating completion cache...
2025-11-24 08:35:07.243640 | controller | Metadata cache created.
2025-11-24 08:35:07.243683 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.715262
2025-11-24 08:35:07.258154 | 
2025-11-24 08:35:07.258276 | PLAY RECAP
2025-11-24 08:35:07.258319 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 08:35:07.258344 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:35:07.258361 | 
2025-11-24 08:35:07.416517 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-11-24 08:35:07.417493 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-24 08:35:08.057910 | 
2025-11-24 08:35:08.058070 | PLAY [all]
2025-11-24 08:35:08.079962 | 
2025-11-24 08:35:08.080138 | TASK [Install binary dependencies]
2025-11-24 08:35:08.162980 | controller | ok
2025-11-24 08:35:08.202725 | 
2025-11-24 08:35:08.202939 | TASK [bindep : Include find tasks]
2025-11-24 08:35:08.246097 | controller | ok
2025-11-24 08:35:08.273209 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-24 08:35:08.279825 | 
2025-11-24 08:35:08.279902 | TASK [bindep : Look for bindep.txt]
2025-11-24 08:35:08.726650 | controller | ok
2025-11-24 08:35:08.736684 | 
2025-11-24 08:35:08.736859 | TASK [bindep : Define bindep_file fact]
2025-11-24 08:35:08.781659 | controller | ok
2025-11-24 08:35:08.789305 | 
2025-11-24 08:35:08.789471 | TASK [bindep : Look for other-requirements.txt]
2025-11-24 08:35:08.815878 | controller | skipping: Conditional result was False
2025-11-24 08:35:08.825526 | 
2025-11-24 08:35:08.825695 | TASK [bindep : Define bindep_file fact]
2025-11-24 08:35:08.852186 | controller | skipping: Conditional result was False
2025-11-24 08:35:08.864238 | 
2025-11-24 08:35:08.864396 | TASK [bindep : Look for bindep fallback file]
2025-11-24 08:35:08.900612 | controller | skipping: Conditional result was False
2025-11-24 08:35:08.915984 | 
2025-11-24 08:35:08.916227 | TASK [bindep : Define bindep_file fact]
2025-11-24 08:35:08.942893 | controller | skipping: Conditional result was False
2025-11-24 08:35:08.952871 | 
2025-11-24 08:35:08.953077 | TASK [bindep : Include bindep tasks]
2025-11-24 08:35:08.995320 | controller | ok
2025-11-24 08:35:09.005319 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-11-24 08:35:09.014586 | 
2025-11-24 08:35:09.014706 | TASK [bindep : Look for bindep command]
2025-11-24 08:35:09.038822 | controller | skipping: Conditional result was False
2025-11-24 08:35:09.048434 | 
2025-11-24 08:35:09.048608 | TASK [bindep : Check for system bindep]
2025-11-24 08:35:09.594751 | controller | ok: Runtime: 0:00:00.005957
2025-11-24 08:35:09.607139 | 
2025-11-24 08:35:09.607367 | TASK [bindep : Define bindep_command fact]
2025-11-24 08:35:09.635111 | controller | skipping: Conditional result was False
2025-11-24 08:35:09.648088 | 
2025-11-24 08:35:09.648302 | TASK [bindep : Include install tasks]
2025-11-24 08:35:09.687331 | controller | ok
2025-11-24 08:35:09.705738 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-11-24 08:35:09.723085 | 
2025-11-24 08:35:09.723268 | TASK [bindep : Create temp dir for bindep]
2025-11-24 08:35:10.102106 | controller | changed
2025-11-24 08:35:10.107848 | 
2025-11-24 08:35:10.107910 | TASK [Ensure we have pip dependencies]
2025-11-24 08:35:10.128788 | controller | ok
2025-11-24 08:35:10.158045 | 
2025-11-24 08:35:10.158198 | TASK [ensure-pip : Check if pip is installed]
2025-11-24 03:35:10.469818 | controller | /usr/bin/pip3
2025-11-24 03:35:10.493465 | controller | /usr/bin/python3: No module named wheel
2025-11-24 08:35:10.698570 | controller | ok: Runtime: 0:00:00.036010
2025-11-24 08:35:10.704429 | 
2025-11-24 08:35:10.704491 | LOOP [ensure-pip : Install pip from packages]
2025-11-24 08:35:10.735610 | controller | ok: "/var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-11-24 08:35:10.746896 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-11-24 08:35:10.761419 | 
2025-11-24 08:35:10.761549 | TASK [ensure-pip : Install Python 3 pip]
2025-11-24 08:35:13.026769 | controller | changed
2025-11-24 08:35:13.035966 | 
2025-11-24 08:35:13.036167 | TASK [ensure-pip : Check for EPEL repository]
2025-11-24 08:35:13.081312 | controller | skipping: Conditional result was False
2025-11-24 08:35:13.090307 | 
2025-11-24 08:35:13.090445 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-11-24 08:35:13.136671 | controller | skipping: Conditional result was False
2025-11-24 08:35:13.144249 | 
2025-11-24 08:35:13.144385 | TASK [ensure-pip : Install Python 2 pip]
2025-11-24 08:35:13.189539 | controller | skipping: Conditional result was False
2025-11-24 08:35:13.197364 | 
2025-11-24 08:35:13.197455 | TASK [ensure-pip : Ensure setuptools]
2025-11-24 08:35:13.235400 | controller | skipping: Conditional result was False
2025-11-24 08:35:13.242140 | 
2025-11-24 08:35:13.242248 | TASK [ensure-pip : Check for ensurepip module]
2025-11-24 08:35:13.810109 | controller | skipping: Conditional result was False
2025-11-24 08:35:13.817795 | 
2025-11-24 08:35:13.817943 | TASK [ensure-pip : Ensure python3-venv]
2025-11-24 08:35:13.839471 | controller | skipping: Conditional result was False
2025-11-24 08:35:13.855386 | 
2025-11-24 08:35:13.855568 | TASK [ensure-pip : Install pip from source]
2025-11-24 08:35:13.892950 | controller | skipping: Conditional result was False
2025-11-24 08:35:13.906219 | 
2025-11-24 08:35:13.906801 | TASK [ensure-pip : Probe for venv python full path]
2025-11-24 03:35:14.228411 | controller | /usr/bin/python3
2025-11-24 08:35:14.450193 | controller | ok: Runtime: 0:00:00.006620
2025-11-24 08:35:14.456384 | 
2025-11-24 08:35:14.456463 | TASK [ensure-pip : Set host default]
2025-11-24 08:35:14.516071 | controller | ok
2025-11-24 08:35:14.521379 | 
2025-11-24 08:35:14.521443 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-11-24 08:35:14.582667 | controller | ok
2025-11-24 08:35:14.594258 | 
2025-11-24 08:35:14.594344 | TASK [bindep : Install bindep into temporary venv]
2025-11-24 08:35:19.052793 | controller | changed
2025-11-24 08:35:19.058203 | 
2025-11-24 08:35:19.058277 | TASK [bindep : Define bindep_command]
2025-11-24 08:35:19.096826 | controller | ok
2025-11-24 08:35:19.105563 | 
2025-11-24 08:35:19.105691 | LOOP [bindep : Include package tasks]
2025-11-24 08:35:19.187768 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-11-24 08:35:19.188009 | controller | ok: All items complete
2025-11-24 08:35:19.188068 | 
2025-11-24 08:35:19.215220 | controller | included: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-11-24 08:35:19.235276 | 
2025-11-24 08:35:19.235446 | TASK [bindep : Define bindep_run fact]
2025-11-24 08:35:19.278898 | controller | ok
2025-11-24 08:35:19.288407 | 
2025-11-24 08:35:19.288628 | TASK [bindep : Get list of packages to install from bindep]
2025-11-24 03:35:20.934592 | controller | podman
2025-11-24 03:35:20.972007 | controller | python3-jmespath
2025-11-24 03:35:20.972229 | controller | python3-libvirt
2025-11-24 03:35:20.972250 | controller | python3-lxml
2025-11-24 03:35:20.972265 | controller | python3-netaddr
2025-11-24 08:35:21.338756 | controller | ok: Runtime: 0:00:01.375062
2025-11-24 08:35:21.345005 | 
2025-11-24 08:35:21.345113 | TASK [bindep : Install distro packages from bindep]
2025-11-24 08:36:27.675615 | controller | changed
2025-11-24 08:36:27.681136 | 
2025-11-24 08:36:27.681212 | TASK [bindep : Check that packages are installed]
2025-11-24 08:36:29.213856 | controller | ok: Runtime: 0:00:01.131195
2025-11-24 08:36:29.226603 | 
2025-11-24 08:36:29.226790 | TASK [bindep : Fail if we cannot install all packages]
2025-11-24 08:36:29.254282 | controller | skipping: Conditional result was False
2025-11-24 08:36:29.270180 | 
2025-11-24 08:36:29.270328 | TASK [Run test-setup role]
2025-11-24 08:36:29.291528 | controller | ok
2025-11-24 08:36:29.313385 | 
2025-11-24 08:36:29.313531 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-24 08:36:29.531176 | controller | ok
2025-11-24 08:36:29.544098 | 
2025-11-24 08:36:29.544239 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-24 08:36:30.084873 | controller | skipping: Conditional result was False
2025-11-24 08:36:30.133220 | 
2025-11-24 08:36:30.133419 | TASK [bindep : Remove bindep temp dir]
2025-11-24 08:36:30.543510 | controller | ok
2025-11-24 08:36:30.555766 | 
2025-11-24 08:36:30.555868 | PLAY RECAP
2025-11-24 08:36:30.555923 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-11-24 08:36:30.555960 | 
2025-11-24 08:36:30.726070 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-24 08:36:30.728696 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-11-24 08:36:31.399885 | 
2025-11-24 08:36:31.400097 | PLAY [all]
2025-11-24 08:36:31.422311 | 
2025-11-24 08:36:31.422490 | TASK [Abort when test_command variable is undefined]
2025-11-24 08:36:31.448759 | controller | skipping: Conditional result was False
2025-11-24 08:36:31.456364 | 
2025-11-24 08:36:31.456568 | TASK [Convert test_command to list]
2025-11-24 08:36:31.504170 | controller | skipping: Conditional result was False
2025-11-24 08:36:31.515620 | 
2025-11-24 08:36:31.515760 | TASK [Use test_command list]
2025-11-24 08:36:31.601937 | controller | ok
2025-11-24 08:36:31.610009 | 
2025-11-24 08:36:31.610140 | LOOP [Run test_command]
2025-11-24 08:36:32.100969 | controller | no check to run
2025-11-24 08:36:32.101672 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005685
2025-11-24 08:36:32.154993 | 
2025-11-24 08:36:32.155379 | PLAY RECAP
2025-11-24 08:36:32.155438 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-24 08:36:32.155467 | 
2025-11-24 08:36:32.312337 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-11-24 08:36:32.314190 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-24 08:36:33.003349 | 
2025-11-24 08:36:33.003524 | PLAY [all]
2025-11-24 08:36:33.033109 | 
2025-11-24 08:36:33.033280 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-24 08:36:33.425182 | controller | changed: non-zero return code
2025-11-24 08:36:33.431242 | 
2025-11-24 08:36:33.431339 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-24 08:36:33.456450 | controller | skipping: Conditional result was False
2025-11-24 08:36:33.462897 | 
2025-11-24 08:36:33.462981 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-24 08:36:33.494940 | 
2025-11-24 08:36:33.495174 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-24 08:36:33.527879 | 
2025-11-24 08:36:33.528067 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-24 08:36:33.552702 | controller | skipping: Conditional result was False
2025-11-24 08:36:33.559460 | 
2025-11-24 08:36:33.559589 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-24 08:36:33.593480 | 
2025-11-24 08:36:33.593697 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-24 08:36:33.619147 | controller | skipping: Conditional result was False
2025-11-24 08:36:33.628926 | 
2025-11-24 08:36:33.629134 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-24 08:36:33.654535 | controller | skipping: Conditional result was False
2025-11-24 08:36:33.663291 | 
2025-11-24 08:36:33.663413 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-24 08:36:33.688750 | controller | skipping: Conditional result was False
2025-11-24 08:36:33.736754 | 
2025-11-24 08:36:33.736954 | PLAY RECAP
2025-11-24 08:36:33.737055 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-24 08:36:33.737093 | 
2025-11-24 08:36:33.857968 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-24 08:36:33.859741 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:36:34.533706 | 
2025-11-24 08:36:34.533841 | PLAY [all]
2025-11-24 08:36:34.554695 | 
2025-11-24 08:36:34.554818 | TASK [include_role : fetch-output]
2025-11-24 08:36:34.596505 | controller | ok
2025-11-24 08:36:34.616179 | 
2025-11-24 08:36:34.616305 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 08:36:34.671435 | controller | skipping: Conditional result was False
2025-11-24 08:36:34.677422 | 
2025-11-24 08:36:34.677490 | TASK [fetch-output : Set log path for single node]
2025-11-24 08:36:34.717186 | controller | ok
2025-11-24 08:36:34.722492 | 
2025-11-24 08:36:34.722559 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 08:36:35.168276 | controller -> localhost | ok: "/var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/logs"
2025-11-24 08:36:35.389749 | controller -> localhost | changed: "/var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/artifacts"
2025-11-24 08:36:35.637700 | controller -> localhost | changed: "/var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/docs"
2025-11-24 08:36:35.661103 | 
2025-11-24 08:36:35.661259 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 08:36:36.394772 | controller | changed: .d..t...... ./
2025-11-24 08:36:36.395287 | controller | changed: All items complete
2025-11-24 08:36:36.395366 | 
2025-11-24 08:36:36.924789 | controller | changed: .d..t...... ./
2025-11-24 08:36:37.401754 | controller | changed: .d..t...... ./
2025-11-24 08:36:37.422365 | 
2025-11-24 08:36:37.422505 | TASK [include_role : fetch-output-openshift]
2025-11-24 08:36:37.447984 | controller | skipping: Conditional result was False
2025-11-24 08:36:37.457715 | 
2025-11-24 08:36:37.457858 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-24 08:36:37.939927 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012328
2025-11-24 08:36:38.204262 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009282
2025-11-24 08:36:38.236207 | 
2025-11-24 08:36:38.236357 | PLAY [all]
2025-11-24 08:36:38.254458 | 
2025-11-24 08:36:38.254608 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-11-24 08:36:38.729608 | controller | changed
2025-11-24 08:36:38.769488 | 
2025-11-24 08:36:38.769653 | PLAY RECAP
2025-11-24 08:36:38.769719 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-24 08:36:38.769749 | 
2025-11-24 08:36:38.903414 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:36:38.904269 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-11-24 08:36:39.587250 | 
2025-11-24 08:36:39.587389 | PLAY [localhost]
2025-11-24 08:36:39.606401 | 
2025-11-24 08:36:39.606519 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-24 08:36:40.011467 | localhost | changed
2025-11-24 08:36:40.016157 | 
2025-11-24 08:36:40.016232 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-24 08:36:40.045609 | localhost | ok
2025-11-24 08:36:40.053790 | 
2025-11-24 08:36:40.053877 | TASK [add-fileserver : Create SSH private key tempfile]
2025-11-24 08:36:40.450874 | localhost | changed
2025-11-24 08:36:40.455943 | 
2025-11-24 08:36:40.456011 | TASK [add-fileserver : Create SSH private key from secret]
2025-11-24 08:36:41.167639 | localhost | changed
2025-11-24 08:36:41.173069 | 
2025-11-24 08:36:41.173143 | TASK [add-fileserver : Add fileserver ssh key]
2025-11-24 08:36:41.633270 | localhost | Identity added: /var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/tmp/ansible.11yj6pbs (/var/lib/zuul/builds/e374bd7cf16e4094a662a0ca8c32550a/work/tmp/ansible.11yj6pbs)
2025-11-24 08:36:41.633521 | localhost | ok: Runtime: 0:00:00.014125
2025-11-24 08:36:41.639707 | 
2025-11-24 08:36:41.639802 | TASK [add-fileserver : Remove SSH private key from disk]
2025-11-24 08:36:41.924314 | localhost | ok: Runtime: 0:00:00.006372
2025-11-24 08:36:41.930198 | 
2025-11-24 08:36:41.930310 | TASK [add-fileserver : Add fileserver to inventory]
2025-11-24 08:36:42.012090 | localhost | changed
2025-11-24 08:36:42.017961 | 
2025-11-24 08:36:42.018071 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-11-24 08:36:42.454521 | localhost | changed
2025-11-24 08:36:42.486813 | 
2025-11-24 08:36:42.486932 | PLAY [localhost]
2025-11-24 08:36:42.504119 | 
2025-11-24 08:36:42.504217 | TASK [Generate bulk log download script]
2025-11-24 08:36:42.535286 | localhost | ok
2025-11-24 08:36:42.551887 | 
2025-11-24 08:36:42.552010 | TASK [local-log-download : Check API endpoint is defined]
2025-11-24 08:36:42.603102 | localhost | ok: All assertions passed
2025-11-24 08:36:42.609381 | 
2025-11-24 08:36:42.609464 | TASK [local-log-download : Create download script]
2025-11-24 08:36:43.124173 | localhost -> localhost | changed
2025-11-24 08:36:43.152315 | 
2025-11-24 08:36:43.152504 | TASK [Register quick-download link]
2025-11-24 08:36:43.177297 | localhost | ok
2025-11-24 08:36:43.228482 | 
2025-11-24 08:36:43.228590 | PLAY [logserver.rdoproject.org]
2025-11-24 08:36:43.239009 | 
2025-11-24 08:36:43.239138 | TASK [Set zuul-log-path fact]
2025-11-24 08:36:43.257837 | logserver.rdoproject.org | ok
2025-11-24 08:36:43.271624 | 
2025-11-24 08:36:43.271769 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:36:43.316420 | logserver.rdoproject.org | ok
2025-11-24 08:36:43.332555 | 
2025-11-24 08:36:43.332743 | TASK [upload-logs : Create log directories]
2025-11-24 08:36:44.186158 | logserver.rdoproject.org | changed
2025-11-24 08:36:44.193645 | 
2025-11-24 08:36:44.193776 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-11-24 08:36:44.546149 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.025314
2025-11-24 08:36:44.556067 | 
2025-11-24 08:36:44.556264 | TASK [upload-logs : Upload logs to log server]
2025-11-24 08:36:45.299713 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-11-24 08:36:45.304355 | 
2025-11-24 08:36:45.304440 | LOOP [upload-logs : Compress console log and json output]
2025-11-24 08:36:45.363114 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:36:45.373928 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:36:45.387917 | 
2025-11-24 08:36:45.388090 | LOOP [upload-logs : Upload compressed console log and json output]
2025-11-24 08:36:45.446528 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:36:45.446770 | 
2025-11-24 08:36:45.452220 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:36:45.458485 | 
2025-11-24 08:36:45.458682 | LOOP [upload-logs : Upload console log and json output]