2025-12-05 15:18:30.024565 | Job console starting...
2025-12-05 15:18:30.033603 | Updating repositories
2025-12-05 15:18:30.055601 | Preparing job workspace
2025-12-05 15:18:33.778607 | Running Ansible setup...
2025-12-05 15:18:37.640346 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:18:38.439007 | 
2025-12-05 15:18:38.439164 | PLAY [localhost]
2025-12-05 15:18:38.448299 | 
2025-12-05 15:18:38.448380 | TASK [Gathering Facts]
2025-12-05 15:18:39.622540 | localhost | ok
2025-12-05 15:18:39.638535 | 
2025-12-05 15:18:39.638752 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-05 15:18:40.015602 | localhost -> localhost | changed
2025-12-05 15:18:40.021492 | 
2025-12-05 15:18:40.021563 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-05 15:18:41.070519 | localhost -> localhost | changed
2025-12-05 15:18:41.079571 | 
2025-12-05 15:18:41.079638 | TASK [Setup log path fact]
2025-12-05 15:18:41.129614 | localhost | ok
2025-12-05 15:18:41.153719 | 
2025-12-05 15:18:41.154381 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:18:41.182714 | localhost | ok
2025-12-05 15:18:41.202951 | 
2025-12-05 15:18:41.203078 | TASK [emit-job-header : Print job information]
2025-12-05 15:18:41.231152 | # Job Information
2025-12-05 15:18:41.231376 | Ansible Version: 2.15.12
2025-12-05 15:18:41.231404 | Job: cifmw-molecule-recognize_ssh_keypair
2025-12-05 15:18:41.231426 | Pipeline: github-check
2025-12-05 15:18:41.231446 | Executor: ze01.softwarefactory-project.io
2025-12-05 15:18:41.231465 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539
2025-12-05 15:18:41.231484 | Log URL (when completed): https://logserver.rdoproject.org/e94/rdoproject.org/e94678a3347445d6bd9cac2d7289aedd/
2025-12-05 15:18:41.231504 | Event ID: 748a4b40-d1ed-11f0-8510-c0ded0ca5b3b
2025-12-05 15:18:41.235345 | 
2025-12-05 15:18:41.235419 | LOOP [emit-job-header : Print node information]
2025-12-05 15:18:41.341934 | localhost | ok:
2025-12-05 15:18:41.342145 | localhost | # Node Information
2025-12-05 15:18:41.342173 | localhost | Inventory Hostname: controller
2025-12-05 15:18:41.342197 | localhost | Hostname: np0005547231
2025-12-05 15:18:41.342216 | localhost | Username: zuul
2025-12-05 15:18:41.342236 | localhost | Distro: CentOS 9
2025-12-05 15:18:41.342253 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-05 15:18:41.342270 | localhost | Region: RegionOne
2025-12-05 15:18:41.342286 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-05 15:18:41.342302 | localhost | Product Name: OpenStack Nova
2025-12-05 15:18:41.342318 | localhost | Interface IP: 38.102.83.151
2025-12-05 15:18:41.386712 | 
2025-12-05 15:18:41.386818 | PLAY [all]
2025-12-05 15:18:41.401852 | 
2025-12-05 15:18:41.401921 | TASK [Gather network facts]
2025-12-05 15:18:41.932998 | controller | ok
2025-12-05 15:18:41.948604 | 
2025-12-05 15:18:41.948676 | TASK [include_role : start-zuul-console]
2025-12-05 15:18:41.978151 | controller | ok
2025-12-05 15:18:41.989961 | 
2025-12-05 15:18:41.990045 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-05 15:18:42.529569 | controller | ok
2025-12-05 15:18:42.541472 | 
2025-12-05 15:18:42.541543 | TASK [include_role : add-build-sshkey]
2025-12-05 15:18:42.592046 | controller | ok
2025-12-05 15:18:42.618798 | 
2025-12-05 15:18:42.618891 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 15:18:43.251475 | controller -> localhost | ok
2025-12-05 15:18:43.265280 | 
2025-12-05 15:18:43.278252 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 15:18:43.363444 | controller | ok
2025-12-05 15:18:43.378413 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 15:18:43.385937 | 
2025-12-05 15:18:43.386049 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 15:18:44.271504 | controller -> localhost | Generating public/private rsa key pair.
2025-12-05 15:18:44.271710 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/e94678a3347445d6bd9cac2d7289aedd_id_rsa.
2025-12-05 15:18:44.271743 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/e94678a3347445d6bd9cac2d7289aedd_id_rsa.pub.
2025-12-05 15:18:44.271767 | controller -> localhost | The key fingerprint is:
2025-12-05 15:18:44.271790 | controller -> localhost | SHA256:wh0+zXuQNLYF+Qb39ZWGxnKOh8AQSCp9YZbAYkokVNA zuul-build-sshkey
2025-12-05 15:18:44.271811 | controller -> localhost | The key's randomart image is:
2025-12-05 15:18:44.271829 | controller -> localhost | +---[RSA 3072]----+
2025-12-05 15:18:44.271847 | controller -> localhost | |++=oo=oo+ ... . .|
2025-12-05 15:18:44.271866 | controller -> localhost | |.+.E+o.  ooo.= oo|
2025-12-05 15:18:44.271884 | controller -> localhost | |+..o .  . =+O...o|
2025-12-05 15:18:44.271902 | controller -> localhost | |. . .. o * Boo. .|
2025-12-05 15:18:44.271919 | controller -> localhost | |      o S *..    |
2025-12-05 15:18:44.271937 | controller -> localhost | |       . . o     |
2025-12-05 15:18:44.271954 | controller -> localhost | |          . .    |
2025-12-05 15:18:44.271975 | controller -> localhost | |           .     |
2025-12-05 15:18:44.271993 | controller -> localhost | |                 |
2025-12-05 15:18:44.272011 | controller -> localhost | +----[SHA256]-----+
2025-12-05 15:18:44.272084 | controller -> localhost | ok: Runtime: 0:00:00.194976
2025-12-05 15:18:44.278204 | 
2025-12-05 15:18:44.278264 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 15:18:44.307215 | controller | ok
2025-12-05 15:18:44.319639 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 15:18:44.327773 | 
2025-12-05 15:18:44.327832 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 15:18:44.372800 | controller | skipping: Conditional result was False
2025-12-05 15:18:44.378751 | 
2025-12-05 15:18:44.378820 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 15:18:44.882181 | controller | changed
2025-12-05 15:18:44.893648 | 
2025-12-05 15:18:44.893722 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 15:18:45.178143 | controller | ok
2025-12-05 15:18:45.183375 | 
2025-12-05 15:18:45.183445 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 15:18:46.037754 | controller | changed
2025-12-05 15:18:46.042796 | 
2025-12-05 15:18:46.042856 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 15:18:46.993009 | controller | changed
2025-12-05 15:18:46.999625 | 
2025-12-05 15:18:46.999690 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 15:18:47.058143 | controller | skipping: Conditional result was False
2025-12-05 15:18:47.063820 | 
2025-12-05 15:18:47.063963 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 15:18:47.816429 | controller -> localhost | changed
2025-12-05 15:18:47.826796 | 
2025-12-05 15:18:47.826862 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 15:18:48.152468 | controller -> localhost | Identity added: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/e94678a3347445d6bd9cac2d7289aedd_id_rsa (zuul-build-sshkey)
2025-12-05 15:18:48.152701 | controller -> localhost | ok: Runtime: 0:00:00.012926
2025-12-05 15:18:48.158540 | 
2025-12-05 15:18:48.158600 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 15:18:48.595785 | controller | ok
2025-12-05 15:18:48.602584 | 
2025-12-05 15:18:48.602671 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 15:18:48.639678 | controller | skipping: Conditional result was False
2025-12-05 15:18:48.650445 | 
2025-12-05 15:18:48.650520 | TASK [include_role : validate-host]
2025-12-05 15:18:48.669606 | controller | ok
2025-12-05 15:18:48.692152 | 
2025-12-05 15:18:48.692252 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-05 15:18:48.776579 | controller | ok
2025-12-05 15:18:48.781234 | 
2025-12-05 15:18:48.781295 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-05 15:18:49.201157 | controller -> localhost | ok
2025-12-05 15:18:49.206872 | 
2025-12-05 15:18:49.206932 | TASK [validate-host : Collect information about the host]
2025-12-05 15:18:50.021565 | controller | ok
2025-12-05 15:18:50.030665 | 
2025-12-05 15:18:50.030809 | TASK [validate-host : Sanitize hostname]
2025-12-05 15:18:50.099930 | controller | ok
2025-12-05 15:18:50.105141 | 
2025-12-05 15:18:50.105218 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-05 15:18:50.561344 | controller -> localhost | changed
2025-12-05 15:18:50.575659 | 
2025-12-05 15:18:50.575761 | TASK [validate-host : Collect information about zuul worker]
2025-12-05 15:18:50.996834 | controller | ok
2025-12-05 15:18:51.002007 | 
2025-12-05 15:18:51.007507 | TASK [validate-host : Write out all zuul information for each host]
2025-12-05 15:18:51.521942 | controller -> localhost | changed
2025-12-05 15:18:51.534407 | 
2025-12-05 15:18:51.534505 | TASK [include_role : prepare-workspace-openshift]
2025-12-05 15:18:51.584208 | controller | skipping: Conditional result was False
2025-12-05 15:18:51.589649 | 
2025-12-05 15:18:51.589957 | TASK [include_role : remove-zuul-sshkey]
2025-12-05 15:18:51.606336 | controller | skipping: Conditional result was False
2025-12-05 15:18:51.614234 | 
2025-12-05 15:18:51.614316 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:18:51.988075 | controller | ok: "logs"
2025-12-05 15:18:51.988298 | controller | ok: All items complete
2025-12-05 15:18:51.988325 | 
2025-12-05 15:18:52.190683 | controller | ok: "artifacts"
2025-12-05 15:18:52.396192 | controller | ok: "docs"
2025-12-05 15:18:52.410587 | 
2025-12-05 15:18:52.410704 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:18:52.726013 | controller | changed: "logs"
2025-12-05 15:18:52.972095 | controller | changed: "artifacts"
2025-12-05 15:18:53.198845 | controller | changed: "docs"
2025-12-05 15:18:53.247457 | 
2025-12-05 15:18:53.247555 | PLAY RECAP
2025-12-05 15:18:53.247598 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-05 15:18:53.247625 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:18:53.247643 | 
2025-12-05 15:18:53.493450 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 15:18:53.494254 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:18:54.520649 | 
2025-12-05 15:18:54.520766 | PLAY [localhost]
2025-12-05 15:18:54.548310 | 
2025-12-05 15:18:54.548417 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-05 15:18:55.122902 | localhost | ok
2025-12-05 15:18:55.128643 | 
2025-12-05 15:18:55.128716 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-05 15:18:55.904428 | localhost | changed
2025-12-05 15:18:55.943822 | 
2025-12-05 15:18:55.943904 | PLAY [all]
2025-12-05 15:18:55.959566 | 
2025-12-05 15:18:55.959629 | TASK [include_role : prepare-workspace]
2025-12-05 15:18:55.978179 | controller | ok
2025-12-05 15:18:55.994319 | 
2025-12-05 15:18:55.994408 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-05 15:18:56.404381 | controller | ok
2025-12-05 15:18:56.412739 | 
2025-12-05 15:18:56.412809 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-05 15:18:58.348467 | controller | Output suppressed because no_log was given
2025-12-05 15:18:58.359544 | 
2025-12-05 15:18:58.359638 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 15:18:58.651267 | controller | changed: "logs"
2025-12-05 15:18:58.906708 | controller | changed: "artifacts"
2025-12-05 15:18:59.143046 | controller | changed: "docs"
2025-12-05 15:18:59.158835 | 
2025-12-05 15:18:59.158963 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 15:18:59.437349 | controller | changed: "logs"
2025-12-05 15:18:59.437569 | controller | changed: All items complete
2025-12-05 15:18:59.437596 | 
2025-12-05 15:18:59.698333 | controller | changed: "artifacts"
2025-12-05 15:18:59.916665 | controller | changed: "docs"
2025-12-05 15:18:59.944153 | 
2025-12-05 15:18:59.944288 | TASK [Check if worker can sudo]
2025-12-05 15:19:00.485198 | controller | ok: Runtime: 0:00:00.036876
2025-12-05 15:19:00.491576 | 
2025-12-05 15:19:00.491640 | TASK [configure-mirrors : Gather needed facts]
2025-12-05 15:19:00.535825 | controller | skipping: Conditional result was False
2025-12-05 15:19:00.541809 | 
2025-12-05 15:19:00.541876 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-05 15:19:00.611181 | controller | ok
2025-12-05 15:19:00.621923 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-05 15:19:00.674141 | 
2025-12-05 15:19:00.674246 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-05 15:19:00.977559 | controller | ok
2025-12-05 15:19:00.992714 | 
2025-12-05 15:19:00.992811 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-05 15:19:01.055840 | controller | ok: "/var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-05 15:19:01.064272 | 
2025-12-05 15:19:01.064384 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-05 15:19:02.079921 | controller | changed
2025-12-05 15:19:02.085580 | 
2025-12-05 15:19:02.085646 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-05 15:19:02.170790 | controller | ok: "/var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-05 15:19:02.171003 | controller | ok: All items complete
2025-12-05 15:19:02.171049 | 
2025-12-05 15:19:02.230169 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-05 15:19:02.239218 | 
2025-12-05 15:19:02.239303 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-05 15:19:13.405525 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-05 15:19:14.272993 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-05 15:19:14.291632 | 
2025-12-05 15:19:14.291799 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-05 15:19:14.790402 | controller | changed: section and option added
2025-12-05 15:19:14.816993 | 
2025-12-05 15:19:14.817244 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-05 15:19:15.516234 | controller | 29 files removed
2025-12-05 15:19:15.516441 | controller | ok: Item: dnf clean all Runtime: 0:00:00.354221
2025-12-05 15:19:15.516484 | controller | changed: All items complete
2025-12-05 15:19:15.516505 | 
2025-12-05 15:19:26.582259 | 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-12-05 15:19:26.582360 | controller | DNF version: 4.14.0
2025-12-05 15:19:26.582385 | controller | cachedir: /var/cache/dnf
2025-12-05 15:19:26.582405 | controller | Making cache files for all metadata files.
2025-12-05 15:19:26.582424 | controller | baseos: has expired and will be refreshed.
2025-12-05 15:19:26.582443 | controller | appstream: has expired and will be refreshed.
2025-12-05 15:19:26.582460 | controller | crb: has expired and will be refreshed.
2025-12-05 15:19:26.582486 | controller | extras-common: has expired and will be refreshed.
2025-12-05 15:19:26.582504 | controller | repo: downloading from remote: baseos
2025-12-05 15:19:26.582521 | controller | CentOS Stream 9 - BaseOS                         60 MB/s | 8.8 MB     00:00
2025-12-05 15:19:26.582539 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-05 15:19:26.582556 | controller | repo: downloading from remote: appstream
2025-12-05 15:19:26.582573 | controller | CentOS Stream 9 - AppStream                      76 MB/s |  25 MB     00:00
2025-12-05 15:19:26.582590 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-05 15:19:26.582608 | controller | repo: downloading from remote: crb
2025-12-05 15:19:26.582625 | controller | CentOS Stream 9 - CRB                            52 MB/s | 7.3 MB     00:00
2025-12-05 15:19:26.582643 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-05 15:19:26.582660 | controller | repo: downloading from remote: extras-common
2025-12-05 15:19:26.582677 | controller | CentOS Stream 9 - Extras packages               1.5 MB/s |  20 kB     00:00
2025-12-05 15:19:26.582695 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-05 15:19:26.582711 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-05 15:19:26.582728 | controller | Completion plugin: Generating completion cache...
2025-12-05 15:19:26.582746 | controller | Metadata cache created.
2025-12-05 15:19:26.582772 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.794615
2025-12-05 15:19:26.601396 | 
2025-12-05 15:19:26.601494 | PLAY RECAP
2025-12-05 15:19:26.601544 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-05 15:19:26.601575 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 15:19:26.601594 | 
2025-12-05 15:19:26.712966 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-05 15:19:26.713916 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:19:27.312130 | 
2025-12-05 15:19:27.312251 | PLAY [all]
2025-12-05 15:19:27.340368 | 
2025-12-05 15:19:27.340514 | TASK [Install binary dependencies]
2025-12-05 15:19:27.380286 | controller | ok
2025-12-05 15:19:27.403095 | 
2025-12-05 15:19:27.403208 | TASK [bindep : Include find tasks]
2025-12-05 15:19:27.441777 | controller | ok
2025-12-05 15:19:27.449556 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-05 15:19:27.455879 | 
2025-12-05 15:19:27.455955 | TASK [bindep : Look for bindep.txt]
2025-12-05 15:19:27.913582 | controller | ok
2025-12-05 15:19:27.920002 | 
2025-12-05 15:19:27.920812 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:19:27.946852 | controller | ok
2025-12-05 15:19:27.955626 | 
2025-12-05 15:19:27.955779 | TASK [bindep : Look for other-requirements.txt]
2025-12-05 15:19:27.969426 | controller | skipping: Conditional result was False
2025-12-05 15:19:27.976050 | 
2025-12-05 15:19:27.976134 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:19:28.003000 | controller | skipping: Conditional result was False
2025-12-05 15:19:28.009099 | 
2025-12-05 15:19:28.009174 | TASK [bindep : Look for bindep fallback file]
2025-12-05 15:19:28.032990 | controller | skipping: Conditional result was False
2025-12-05 15:19:28.039218 | 
2025-12-05 15:19:28.039312 | TASK [bindep : Define bindep_file fact]
2025-12-05 15:19:28.063128 | controller | skipping: Conditional result was False
2025-12-05 15:19:28.069344 | 
2025-12-05 15:19:28.069408 | TASK [bindep : Include bindep tasks]
2025-12-05 15:19:28.109951 | controller | ok
2025-12-05 15:19:28.116312 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-05 15:19:28.130119 | 
2025-12-05 15:19:28.130257 | TASK [bindep : Look for bindep command]
2025-12-05 15:19:28.156100 | controller | skipping: Conditional result was False
2025-12-05 15:19:28.165554 | 
2025-12-05 15:19:28.165643 | TASK [bindep : Check for system bindep]
2025-12-05 15:19:28.707754 | controller | ok: Runtime: 0:00:00.009761
2025-12-05 15:19:28.719985 | 
2025-12-05 15:19:28.720169 | TASK [bindep : Define bindep_command fact]
2025-12-05 15:19:28.758123 | controller | skipping: Conditional result was False
2025-12-05 15:19:28.773104 | 
2025-12-05 15:19:28.773326 | TASK [bindep : Include install tasks]
2025-12-05 15:19:28.817902 | controller | ok
2025-12-05 15:19:28.830197 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-05 15:19:28.842579 | 
2025-12-05 15:19:28.842660 | TASK [bindep : Create temp dir for bindep]
2025-12-05 15:19:29.225666 | controller | changed
2025-12-05 15:19:29.232937 | 
2025-12-05 15:19:29.233037 | TASK [Ensure we have pip dependencies]
2025-12-05 15:19:29.262506 | controller | ok
2025-12-05 15:19:29.296311 | 
2025-12-05 15:19:29.296567 | TASK [ensure-pip : Check if pip is installed]
2025-12-05 10:19:29.578101 | controller | /usr/bin/pip3
2025-12-05 10:19:29.623221 | controller | /usr/bin/python3: No module named wheel
2025-12-05 15:19:29.830511 | controller | ok: Runtime: 0:00:00.059243
2025-12-05 15:19:29.844976 | 
2025-12-05 15:19:29.845230 | LOOP [ensure-pip : Install pip from packages]
2025-12-05 15:19:29.895958 | controller | ok: "/var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-05 15:19:29.914370 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-05 15:19:29.930181 | 
2025-12-05 15:19:29.930281 | TASK [ensure-pip : Install Python 3 pip]
2025-12-05 15:19:31.938695 | controller | changed
2025-12-05 15:19:31.951191 | 
2025-12-05 15:19:31.951271 | TASK [ensure-pip : Check for EPEL repository]
2025-12-05 15:19:31.985876 | controller | skipping: Conditional result was False
2025-12-05 15:19:31.992534 | 
2025-12-05 15:19:31.992618 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-05 15:19:32.039003 | controller | skipping: Conditional result was False
2025-12-05 15:19:32.046747 | 
2025-12-05 15:19:32.046818 | TASK [ensure-pip : Install Python 2 pip]
2025-12-05 15:19:32.091530 | controller | skipping: Conditional result was False
2025-12-05 15:19:32.097740 | 
2025-12-05 15:19:32.097823 | TASK [ensure-pip : Ensure setuptools]
2025-12-05 15:19:32.131999 | controller | skipping: Conditional result was False
2025-12-05 15:19:32.139150 | 
2025-12-05 15:19:32.139240 | TASK [ensure-pip : Check for ensurepip module]
2025-12-05 15:19:32.668682 | controller | skipping: Conditional result was False
2025-12-05 15:19:32.679869 | 
2025-12-05 15:19:32.679994 | TASK [ensure-pip : Ensure python3-venv]
2025-12-05 15:19:32.705283 | controller | skipping: Conditional result was False
2025-12-05 15:19:32.712472 | 
2025-12-05 15:19:32.712540 | TASK [ensure-pip : Install pip from source]
2025-12-05 15:19:32.736609 | controller | skipping: Conditional result was False
2025-12-05 15:19:32.743000 | 
2025-12-05 15:19:32.743078 | TASK [ensure-pip : Probe for venv python full path]
2025-12-05 10:19:33.016637 | controller | /usr/bin/python3
2025-12-05 15:19:33.271984 | controller | ok: Runtime: 0:00:00.005344
2025-12-05 15:19:33.277893 | 
2025-12-05 15:19:33.277956 | TASK [ensure-pip : Set host default]
2025-12-05 15:19:33.360738 | controller | ok
2025-12-05 15:19:33.367700 | 
2025-12-05 15:19:33.367844 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-05 15:19:33.422768 | controller | ok
2025-12-05 15:19:33.435809 | 
2025-12-05 15:19:33.435877 | TASK [bindep : Install bindep into temporary venv]
2025-12-05 15:19:37.621130 | controller | changed
2025-12-05 15:19:37.628821 | 
2025-12-05 15:19:37.628906 | TASK [bindep : Define bindep_command]
2025-12-05 15:19:37.661456 | controller | ok
2025-12-05 15:19:37.668807 | 
2025-12-05 15:19:37.668892 | LOOP [bindep : Include package tasks]
2025-12-05 15:19:37.747370 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-05 15:19:37.747577 | controller | ok: All items complete
2025-12-05 15:19:37.747603 | 
2025-12-05 15:19:37.766913 | controller | included: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-05 15:19:37.783419 | 
2025-12-05 15:19:37.783541 | TASK [bindep : Define bindep_run fact]
2025-12-05 15:19:37.826209 | controller | ok
2025-12-05 15:19:37.833321 | 
2025-12-05 15:19:37.833404 | TASK [bindep : Get list of packages to install from bindep]
2025-12-05 10:19:39.200062 | controller | podman
2025-12-05 10:19:39.245769 | controller | python3-jmespath
2025-12-05 10:19:39.245928 | controller | python3-libvirt
2025-12-05 10:19:39.245947 | controller | python3-lxml
2025-12-05 10:19:39.245966 | controller | python3-netaddr
2025-12-05 15:19:40.406437 | controller | ok: Runtime: 0:00:01.093220
2025-12-05 15:19:40.421634 | 
2025-12-05 15:19:40.421798 | TASK [bindep : Install distro packages from bindep]
2025-12-05 15:20:47.634086 | controller | changed
2025-12-05 15:20:47.647143 | 
2025-12-05 15:20:47.647275 | TASK [bindep : Check that packages are installed]
2025-12-05 15:20:49.205951 | controller | ok: Runtime: 0:00:01.162081
2025-12-05 15:20:49.211797 | 
2025-12-05 15:20:49.211883 | TASK [bindep : Fail if we cannot install all packages]
2025-12-05 15:20:49.237908 | controller | skipping: Conditional result was False
2025-12-05 15:20:49.281609 | 
2025-12-05 15:20:49.281730 | TASK [Run test-setup role]
2025-12-05 15:20:49.312146 | controller | ok
2025-12-05 15:20:49.336470 | 
2025-12-05 15:20:49.336604 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-05 15:20:49.595112 | controller | ok
2025-12-05 15:20:49.603971 | 
2025-12-05 15:20:49.604119 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-05 15:20:50.144644 | controller | skipping: Conditional result was False
2025-12-05 15:20:50.174028 | 
2025-12-05 15:20:50.174135 | TASK [bindep : Remove bindep temp dir]
2025-12-05 15:20:50.542798 | controller | ok
2025-12-05 15:20:50.554299 | 
2025-12-05 15:20:50.554428 | PLAY RECAP
2025-12-05 15:20:50.554486 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-05 15:20:50.554508 | 
2025-12-05 15:20:50.664508 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 15:20:50.665496 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:20:51.234165 | 
2025-12-05 15:20:51.234286 | PLAY [all]
2025-12-05 15:20:51.257334 | 
2025-12-05 15:20:51.257462 | TASK [Abort when test_command variable is undefined]
2025-12-05 15:20:51.292370 | controller | skipping: Conditional result was False
2025-12-05 15:20:51.298555 | 
2025-12-05 15:20:51.298649 | TASK [Convert test_command to list]
2025-12-05 15:20:51.333117 | controller | skipping: Conditional result was False
2025-12-05 15:20:51.340075 | 
2025-12-05 15:20:51.340174 | TASK [Use test_command list]
2025-12-05 15:20:51.392116 | controller | ok
2025-12-05 15:20:51.397560 | 
2025-12-05 15:20:51.397625 | LOOP [Run test_command]
2025-12-05 15:20:51.839400 | controller | no check to run
2025-12-05 15:20:51.839598 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006705
2025-12-05 15:20:51.867919 | 
2025-12-05 15:20:51.867995 | PLAY RECAP
2025-12-05 15:20:51.868090 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:20:51.868114 | 
2025-12-05 15:20:51.967143 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-05 15:20:51.967993 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:20:52.557197 | 
2025-12-05 15:20:52.557325 | PLAY [all]
2025-12-05 15:20:52.579699 | 
2025-12-05 15:20:52.579826 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-05 15:20:53.010437 | controller | changed: non-zero return code
2025-12-05 15:20:53.016597 | 
2025-12-05 15:20:53.016675 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-05 15:20:53.031134 | controller | skipping: Conditional result was False
2025-12-05 15:20:53.037865 | 
2025-12-05 15:20:53.037955 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-05 15:20:53.062089 | 
2025-12-05 15:20:53.062322 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-05 15:20:53.096453 | 
2025-12-05 15:20:53.096615 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-05 15:20:53.128166 | controller | skipping: Conditional result was False
2025-12-05 15:20:53.135094 | 
2025-12-05 15:20:53.135165 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-05 15:20:53.186203 | 
2025-12-05 15:20:53.186368 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-05 15:20:53.210609 | controller | skipping: Conditional result was False
2025-12-05 15:20:53.227310 | 
2025-12-05 15:20:53.227426 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-05 15:20:53.266241 | controller | skipping: Conditional result was False
2025-12-05 15:20:53.272562 | 
2025-12-05 15:20:53.272628 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-05 15:20:53.301914 | controller | skipping: Conditional result was False
2025-12-05 15:20:53.331864 | 
2025-12-05 15:20:53.331961 | PLAY RECAP
2025-12-05 15:20:53.332004 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-05 15:20:53.332047 | 
2025-12-05 15:20:53.439916 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 15:20:53.440955 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:20:54.008647 | 
2025-12-05 15:20:54.008761 | PLAY [all]
2025-12-05 15:20:54.038719 | 
2025-12-05 15:20:54.038845 | TASK [include_role : fetch-output]
2025-12-05 15:20:54.067699 | controller | ok
2025-12-05 15:20:54.084407 | 
2025-12-05 15:20:54.084525 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 15:20:54.128848 | controller | skipping: Conditional result was False
2025-12-05 15:20:54.136757 | 
2025-12-05 15:20:54.136854 | TASK [fetch-output : Set log path for single node]
2025-12-05 15:20:54.168281 | controller | ok
2025-12-05 15:20:54.175218 | 
2025-12-05 15:20:54.175306 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 15:20:54.574502 | controller -> localhost | ok: "/var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/logs"
2025-12-05 15:20:54.786098 | controller -> localhost | changed: "/var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/artifacts"
2025-12-05 15:20:54.985007 | controller -> localhost | changed: "/var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/docs"
2025-12-05 15:20:55.001395 | 
2025-12-05 15:20:55.001504 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 15:20:55.636510 | controller | changed: .d..t...... ./
2025-12-05 15:20:55.636692 | controller | changed: All items complete
2025-12-05 15:20:55.636719 | 
2025-12-05 15:20:56.099726 | controller | changed: .d..t...... ./
2025-12-05 15:20:56.599630 | controller | changed: .d..t...... ./
2025-12-05 15:20:56.628248 | 
2025-12-05 15:20:56.628369 | TASK [include_role : fetch-output-openshift]
2025-12-05 15:20:56.653699 | controller | skipping: Conditional result was False
2025-12-05 15:20:56.662011 | 
2025-12-05 15:20:56.662124 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-05 15:20:57.074675 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.020167
2025-12-05 15:20:57.291658 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.010739
2025-12-05 15:20:57.323952 | 
2025-12-05 15:20:57.324084 | PLAY [all]
2025-12-05 15:20:57.337995 | 
2025-12-05 15:20:57.338072 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-05 15:20:57.772798 | controller | changed
2025-12-05 15:20:57.795718 | 
2025-12-05 15:20:57.795774 | PLAY RECAP
2025-12-05 15:20:57.795814 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 15:20:57.795834 | 
2025-12-05 15:20:57.897396 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 15:20:57.898325 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-05 15:20:58.490620 | 
2025-12-05 15:20:58.490743 | PLAY [localhost]
2025-12-05 15:20:58.509949 | 
2025-12-05 15:20:58.510098 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-05 15:20:58.852794 | localhost | changed
2025-12-05 15:20:58.857420 | 
2025-12-05 15:20:58.857490 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-05 15:20:58.885011 | localhost | ok
2025-12-05 15:20:58.893061 | 
2025-12-05 15:20:58.893129 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-05 15:20:59.237941 | localhost | changed
2025-12-05 15:20:59.242817 | 
2025-12-05 15:20:59.242884 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-05 15:20:59.941383 | localhost | changed
2025-12-05 15:20:59.946760 | 
2025-12-05 15:20:59.946843 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-05 15:21:00.337590 | localhost | Identity added: /var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/tmp/ansible.iqv79gu4 (/var/lib/zuul/builds/e94678a3347445d6bd9cac2d7289aedd/work/tmp/ansible.iqv79gu4)
2025-12-05 15:21:00.337932 | localhost | ok: Runtime: 0:00:00.012922
2025-12-05 15:21:00.348442 | 
2025-12-05 15:21:00.348587 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-05 15:21:00.674327 | localhost | ok: Runtime: 0:00:00.010226
2025-12-05 15:21:00.680506 | 
2025-12-05 15:21:00.680584 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-05 15:21:00.739425 | localhost | changed
2025-12-05 15:21:00.744720 | 
2025-12-05 15:21:00.744821 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-05 15:21:01.099980 | localhost | changed
2025-12-05 15:21:01.122745 | 
2025-12-05 15:21:01.122840 | PLAY [localhost]
2025-12-05 15:21:01.144843 | 
2025-12-05 15:21:01.144947 | TASK [Generate bulk log download script]
2025-12-05 15:21:01.166529 | localhost | ok
2025-12-05 15:21:01.180733 | 
2025-12-05 15:21:01.180855 | TASK [local-log-download : Check API endpoint is defined]
2025-12-05 15:21:01.223106 | localhost | ok: All assertions passed
2025-12-05 15:21:01.227904 | 
2025-12-05 15:21:01.227976 | TASK [local-log-download : Create download script]
2025-12-05 15:21:01.658732 | localhost -> localhost | changed
2025-12-05 15:21:01.670970 | 
2025-12-05 15:21:01.671085 | TASK [Register quick-download link]
2025-12-05 15:21:01.695695 | localhost | ok
2025-12-05 15:21:01.745425 | 
2025-12-05 15:21:01.745525 | PLAY [logserver.rdoproject.org]
2025-12-05 15:21:01.757003 | 
2025-12-05 15:21:01.757079 | TASK [Set zuul-log-path fact]
2025-12-05 15:21:01.773946 | logserver.rdoproject.org | ok
2025-12-05 15:21:01.783716 | 
2025-12-05 15:21:01.783806 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 15:21:01.811968 | logserver.rdoproject.org | ok
2025-12-05 15:21:01.817513 | 
2025-12-05 15:21:01.817599 | TASK [upload-logs : Create log directories]
2025-12-05 15:21:02.413836 | logserver.rdoproject.org | changed
2025-12-05 15:21:02.417244 | 
2025-12-05 15:21:02.417311 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-05 15:21:02.685214 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006232
2025-12-05 15:21:02.690805 | 
2025-12-05 15:21:02.690870 | TASK [upload-logs : Upload logs to log server]
2025-12-05 15:21:03.406542 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-05 15:21:03.416934 | 
2025-12-05 15:21:03.417084 | LOOP [upload-logs : Compress console log and json output]
2025-12-05 15:21:03.476400 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:21:03.486289 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:21:03.502361 | 
2025-12-05 15:21:03.502522 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-05 15:21:03.561917 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:21:03.562199 | 
2025-12-05 15:21:03.565609 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 15:21:03.572629 | 
2025-12-05 15:21:03.572697 | LOOP [upload-logs : Upload console log and json output]