2025-11-24 04:42:35.792432 | Job console starting...
2025-11-24 04:42:35.805420 | Updating repositories
2025-11-24 04:42:35.836006 | Preparing job workspace
2025-11-24 04:42:39.657476 | Running Ansible setup...
2025-11-24 04:42:43.671065 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 04:42:44.239201 | 
2025-11-24 04:42:44.239302 | PLAY [localhost]
2025-11-24 04:42:44.247667 | 
2025-11-24 04:42:44.247750 | TASK [Gathering Facts]
2025-11-24 04:42:45.233064 | localhost | ok
2025-11-24 04:42:45.251129 | 
2025-11-24 04:42:45.251242 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-24 04:42:45.663077 | localhost -> localhost | changed
2025-11-24 04:42:45.668370 | 
2025-11-24 04:42:45.668434 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-24 04:42:46.461889 | localhost -> localhost | changed
2025-11-24 04:42:46.481732 | 
2025-11-24 04:42:46.481877 | TASK [Setup log path fact]
2025-11-24 04:42:46.506088 | localhost | ok
2025-11-24 04:42:46.530005 | 
2025-11-24 04:42:46.530134 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 04:42:46.551262 | localhost | ok
2025-11-24 04:42:46.562142 | 
2025-11-24 04:42:46.562256 | TASK [emit-job-header : Print job information]
2025-11-24 04:42:46.591861 | # Job Information
2025-11-24 04:42:46.592037 | Ansible Version: 2.15.12
2025-11-24 04:42:46.592076 | Job: cifmw-molecule-cifmw_setup
2025-11-24 04:42:46.592104 | Pipeline: github-check
2025-11-24 04:42:46.592132 | Executor: ze04.softwarefactory-project.io
2025-11-24 04:42:46.592160 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3497
2025-11-24 04:42:46.592190 | Log URL (when completed): https://logserver.rdoproject.org/b9d/rdoproject.org/b9d85a1c32634671a1c4a55313443972/
2025-11-24 04:42:46.592219 | Event ID: d8977970-c8ef-11f0-804c-624df6c0aa70
2025-11-24 04:42:46.597846 | 
2025-11-24 04:42:46.597934 | LOOP [emit-job-header : Print node information]
2025-11-24 04:42:46.688294 | localhost | ok:
2025-11-24 04:42:46.688650 | localhost | # Node Information
2025-11-24 04:42:46.688739 | localhost | Inventory Hostname: controller
2025-11-24 04:42:46.688794 | localhost | Hostname: np0005532966
2025-11-24 04:42:46.688837 | localhost | Username: zuul
2025-11-24 04:42:46.688881 | localhost | Distro: CentOS 9
2025-11-24 04:42:46.688920 | localhost | Provider: vexxhost-nodepool-tripleo
2025-11-24 04:42:46.688956 | localhost | Region: RegionOne
2025-11-24 04:42:46.688992 | localhost | Label: cloud-centos-9-stream-tripleo
2025-11-24 04:42:46.689027 | localhost | Product Name: OpenStack Nova
2025-11-24 04:42:46.689062 | localhost | Interface IP: 38.102.83.12
2025-11-24 04:42:46.736341 | 
2025-11-24 04:42:46.736459 | PLAY [all]
2025-11-24 04:42:46.750160 | 
2025-11-24 04:42:46.750278 | TASK [Gather network facts]
2025-11-24 04:42:47.256984 | controller | ok
2025-11-24 04:42:47.288273 | 
2025-11-24 04:42:47.288391 | TASK [include_role : start-zuul-console]
2025-11-24 04:42:47.310737 | controller | ok
2025-11-24 04:42:47.327669 | 
2025-11-24 04:42:47.327779 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-24 04:42:47.714861 | controller | ok
2025-11-24 04:42:47.733440 | 
2025-11-24 04:42:47.733563 | TASK [include_role : add-build-sshkey]
2025-11-24 04:42:47.769129 | controller | ok
2025-11-24 04:42:47.796439 | 
2025-11-24 04:42:47.796570 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-24 04:42:48.080425 | controller -> localhost | ok
2025-11-24 04:42:48.091668 | 
2025-11-24 04:42:48.091851 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-24 04:42:48.128360 | controller | ok
2025-11-24 04:42:48.157083 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-24 04:42:48.165927 | 
2025-11-24 04:42:48.166024 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-24 04:42:48.754163 | controller -> localhost | Generating public/private rsa key pair.
2025-11-24 04:42:48.754409 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/b9d85a1c32634671a1c4a55313443972_id_rsa.
2025-11-24 04:42:48.754450 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/b9d85a1c32634671a1c4a55313443972_id_rsa.pub.
2025-11-24 04:42:48.754480 | controller -> localhost | The key fingerprint is:
2025-11-24 04:42:48.754506 | controller -> localhost | SHA256:CIEaTZ8hq+TiI5EgnpQvc2j0qqSmNrpQFm+CGZzmG24 zuul-build-sshkey
2025-11-24 04:42:48.754532 | controller -> localhost | The key's randomart image is:
2025-11-24 04:42:48.754557 | controller -> localhost | +---[RSA 3072]----+
2025-11-24 04:42:48.754582 | controller -> localhost | | oo.o            |
2025-11-24 04:42:48.754608 | controller -> localhost | |o =+ +           |
2025-11-24 04:42:48.754632 | controller -> localhost | |+@o +            |
2025-11-24 04:42:48.754657 | controller -> localhost | |%*=o . .         |
2025-11-24 04:42:48.754686 | controller -> localhost | |B@++o . S        |
2025-11-24 04:42:48.754738 | controller -> localhost | |=+Bo             |
2025-11-24 04:42:48.754764 | controller -> localhost | |oE               |
2025-11-24 04:42:48.754791 | controller -> localhost | |B+.              |
2025-11-24 04:42:48.754815 | controller -> localhost | |@..              |
2025-11-24 04:42:48.754839 | controller -> localhost | +----[SHA256]-----+
2025-11-24 04:42:48.754893 | controller -> localhost | ok: Runtime: 0:00:00.115023
2025-11-24 04:42:48.762444 | 
2025-11-24 04:42:48.762524 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-24 04:42:48.803967 | controller | ok
2025-11-24 04:42:48.816933 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-24 04:42:48.827602 | 
2025-11-24 04:42:48.827685 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-24 04:42:48.852796 | controller | skipping: Conditional result was False
2025-11-24 04:42:48.860650 | 
2025-11-24 04:42:48.860762 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-24 04:42:49.370358 | controller | changed
2025-11-24 04:42:49.380868 | 
2025-11-24 04:42:49.380994 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-24 04:42:49.668633 | controller | ok
2025-11-24 04:42:49.681666 | 
2025-11-24 04:42:49.681859 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-24 04:42:50.675804 | controller | changed
2025-11-24 04:42:50.686947 | 
2025-11-24 04:42:50.687084 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-24 04:42:51.601140 | controller | changed
2025-11-24 04:42:51.610718 | 
2025-11-24 04:42:51.610836 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-24 04:42:51.635377 | controller | skipping: Conditional result was False
2025-11-24 04:42:51.642950 | 
2025-11-24 04:42:51.643093 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-24 04:42:52.066845 | controller -> localhost | changed
2025-11-24 04:42:52.090549 | 
2025-11-24 04:42:52.090761 | TASK [add-build-sshkey : Add back temp key]
2025-11-24 04:42:52.426224 | controller -> localhost | Identity added: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/b9d85a1c32634671a1c4a55313443972_id_rsa (zuul-build-sshkey)
2025-11-24 04:42:52.426575 | controller -> localhost | ok: Runtime: 0:00:00.014135
2025-11-24 04:42:52.438423 | 
2025-11-24 04:42:52.438552 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-24 04:42:52.852627 | controller | ok
2025-11-24 04:42:52.864570 | 
2025-11-24 04:42:52.864757 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-24 04:42:52.902000 | controller | skipping: Conditional result was False
2025-11-24 04:42:52.923464 | 
2025-11-24 04:42:52.923604 | TASK [include_role : validate-host]
2025-11-24 04:42:52.960437 | controller | ok
2025-11-24 04:42:52.994991 | 
2025-11-24 04:42:52.995078 | TASK [validate-host : Define zuul_info_dir fact]
2025-11-24 04:42:53.036133 | controller | ok
2025-11-24 04:42:53.042522 | 
2025-11-24 04:42:53.042607 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-11-24 04:42:53.321258 | controller -> localhost | ok
2025-11-24 04:42:53.329145 | 
2025-11-24 04:42:53.329231 | TASK [validate-host : Collect information about the host]
2025-11-24 04:42:54.175233 | controller | ok
2025-11-24 04:42:54.192883 | 
2025-11-24 04:42:54.193010 | TASK [validate-host : Sanitize hostname]
2025-11-24 04:42:54.264899 | controller | ok
2025-11-24 04:42:54.271368 | 
2025-11-24 04:42:54.271451 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-11-24 04:42:54.794660 | controller -> localhost | changed
2025-11-24 04:42:54.800224 | 
2025-11-24 04:42:54.800284 | TASK [validate-host : Collect information about zuul worker]
2025-11-24 04:42:55.203266 | controller | ok
2025-11-24 04:42:55.214718 | 
2025-11-24 04:42:55.214860 | TASK [validate-host : Write out all zuul information for each host]
2025-11-24 04:42:55.780071 | controller -> localhost | changed
2025-11-24 04:42:55.789393 | 
2025-11-24 04:42:55.789455 | TASK [include_role : prepare-workspace-openshift]
2025-11-24 04:42:55.813401 | controller | skipping: Conditional result was False
2025-11-24 04:42:55.818428 | 
2025-11-24 04:42:55.818486 | TASK [include_role : remove-zuul-sshkey]
2025-11-24 04:42:55.842807 | controller | skipping: Conditional result was False
2025-11-24 04:42:55.847672 | 
2025-11-24 04:42:55.847759 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-24 04:42:56.119728 | controller | ok: "logs"
2025-11-24 04:42:56.119970 | controller | ok: All items complete
2025-11-24 04:42:56.119997 | 
2025-11-24 04:42:56.378344 | controller | ok: "artifacts"
2025-11-24 04:42:56.642871 | controller | ok: "docs"
2025-11-24 04:42:56.664001 | 
2025-11-24 04:42:56.664131 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-24 04:42:56.964331 | controller | changed: "logs"
2025-11-24 04:42:57.188578 | controller | changed: "artifacts"
2025-11-24 04:42:57.410960 | controller | changed: "docs"
2025-11-24 04:42:57.458314 | 
2025-11-24 04:42:57.458474 | PLAY RECAP
2025-11-24 04:42:57.458561 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 04:42:57.458616 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 04:42:57.458657 | 
2025-11-24 04:42:57.594331 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 04:42:57.595895 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-11-24 04:42:58.164375 | 
2025-11-24 04:42:58.164481 | PLAY [localhost]
2025-11-24 04:42:58.180216 | 
2025-11-24 04:42:58.180285 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-11-24 04:42:58.640519 | localhost | ok
2025-11-24 04:42:58.651138 | 
2025-11-24 04:42:58.651296 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-11-24 04:42:59.417873 | localhost | changed
2025-11-24 04:42:59.438345 | 
2025-11-24 04:42:59.438431 | PLAY [all]
2025-11-24 04:42:59.456736 | 
2025-11-24 04:42:59.456819 | TASK [include_role : prepare-workspace]
2025-11-24 04:42:59.486246 | controller | ok
2025-11-24 04:42:59.500199 | 
2025-11-24 04:42:59.500284 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-24 04:42:59.942769 | controller | ok
2025-11-24 04:42:59.956556 | 
2025-11-24 04:42:59.956741 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-24 04:43:01.884321 | controller | Output suppressed because no_log was given
2025-11-24 04:43:01.906122 | 
2025-11-24 04:43:01.906264 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-24 04:43:02.218665 | controller | changed: "logs"
2025-11-24 04:43:02.423554 | controller | changed: "artifacts"
2025-11-24 04:43:02.673622 | controller | changed: "docs"
2025-11-24 04:43:02.688952 | 
2025-11-24 04:43:02.689145 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-24 04:43:02.983041 | controller | changed: "logs"
2025-11-24 04:43:02.983666 | controller | changed: All items complete
2025-11-24 04:43:02.983795 | 
2025-11-24 04:43:03.224393 | controller | changed: "artifacts"
2025-11-24 04:43:03.501841 | controller | changed: "docs"
2025-11-24 04:43:03.530399 | 
2025-11-24 04:43:03.530589 | TASK [Check if worker can sudo]
2025-11-24 04:43:04.101221 | controller | ok: Runtime: 0:00:00.064426
2025-11-24 04:43:04.108816 | 
2025-11-24 04:43:04.108903 | TASK [configure-mirrors : Gather needed facts]
2025-11-24 04:43:04.185398 | controller | skipping: Conditional result was False
2025-11-24 04:43:04.193193 | 
2025-11-24 04:43:04.193279 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-11-24 04:43:04.265821 | controller | ok
2025-11-24 04:43:04.277499 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-11-24 04:43:04.313198 | 
2025-11-24 04:43:04.313342 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-11-24 04:43:04.638405 | controller | ok
2025-11-24 04:43:04.644156 | 
2025-11-24 04:43:04.644215 | LOOP [configure-mirrors : Include OS-specific variables]
2025-11-24 04:43:04.737402 | controller | ok: "/var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-11-24 04:43:04.752452 | 
2025-11-24 04:43:04.752582 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-11-24 04:43:05.793933 | controller | changed
2025-11-24 04:43:05.805831 | 
2025-11-24 04:43:05.805959 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-11-24 04:43:05.888575 | controller | ok: "/var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-11-24 04:43:05.888861 | controller | ok: All items complete
2025-11-24 04:43:05.888917 | 
2025-11-24 04:43:05.968202 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-11-24 04:43:05.976780 | 
2025-11-24 04:43:05.976948 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-11-24 04:43:07.094764 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-11-24 04:43:08.059399 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-11-24 04:43:08.073709 | 
2025-11-24 04:43:08.073842 | TASK [configure-mirrors : Disable deltrarpm]
2025-11-24 04:43:08.592623 | controller | changed: section and option added
2025-11-24 04:43:08.632627 | 
2025-11-24 04:43:08.632732 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-11-24 04:43:09.527882 | controller | 29 files removed
2025-11-24 04:43:09.528313 | controller | ok: Item: dnf clean all Runtime: 0:00:00.510137
2025-11-24 04:43:09.528414 | controller | changed: All items complete
2025-11-24 04:43:09.528462 | 
2025-11-24 04:43:19.803837 | 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 04:43:19.804004 | controller | DNF version: 4.14.0
2025-11-24 04:43:19.804059 | controller | cachedir: /var/cache/dnf
2025-11-24 04:43:19.804103 | controller | Making cache files for all metadata files.
2025-11-24 04:43:19.804144 | controller | baseos: has expired and will be refreshed.
2025-11-24 04:43:19.804183 | controller | appstream: has expired and will be refreshed.
2025-11-24 04:43:19.804221 | controller | crb: has expired and will be refreshed.
2025-11-24 04:43:19.804286 | controller | extras-common: has expired and will be refreshed.
2025-11-24 04:43:19.804326 | controller | repo: downloading from remote: baseos
2025-11-24 04:43:19.804364 | controller | CentOS Stream 9 - BaseOS                         79 MB/s | 8.8 MB     00:00
2025-11-24 04:43:19.804401 | controller | baseos: using metadata from Mon 17 Nov 2025 10:24:02 AM EST.
2025-11-24 04:43:19.804439 | controller | repo: downloading from remote: appstream
2025-11-24 04:43:19.804476 | controller | CentOS Stream 9 - AppStream                     103 MB/s |  25 MB     00:00
2025-11-24 04:43:19.804513 | controller | appstream: using metadata from Mon 17 Nov 2025 10:27:35 AM EST.
2025-11-24 04:43:19.804550 | controller | repo: downloading from remote: crb
2025-11-24 04:43:19.804587 | controller | CentOS Stream 9 - CRB                           105 MB/s | 7.3 MB     00:00
2025-11-24 04:43:19.804624 | controller | crb: using metadata from Mon 17 Nov 2025 10:32:16 AM EST.
2025-11-24 04:43:19.804660 | controller | repo: downloading from remote: extras-common
2025-11-24 04:43:19.804740 | controller | CentOS Stream 9 - Extras packages               340 kB/s |  20 kB     00:00
2025-11-24 04:43:19.804782 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-11-24 04:43:19.804819 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-11-24 04:43:19.804856 | controller | Completion plugin: Generating completion cache...
2025-11-24 04:43:19.804893 | controller | Metadata cache created.
2025-11-24 04:43:19.804947 | controller | ok: Item: dnf makecache -v Runtime: 0:00:09.971038
2025-11-24 04:43:19.827584 | 
2025-11-24 04:43:19.827715 | PLAY RECAP
2025-11-24 04:43:19.827809 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 04:43:19.827864 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 04:43:19.827903 | 
2025-11-24 04:43:19.936592 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-11-24 04:43:19.937382 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-24 04:43:20.473827 | 
2025-11-24 04:43:20.473942 | PLAY [all]
2025-11-24 04:43:20.494338 | 
2025-11-24 04:43:20.494437 | TASK [Install binary dependencies]
2025-11-24 04:43:20.566018 | controller | ok
2025-11-24 04:43:20.591001 | 
2025-11-24 04:43:20.591128 | TASK [bindep : Include find tasks]
2025-11-24 04:43:20.636886 | controller | ok
2025-11-24 04:43:20.651176 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-24 04:43:20.659079 | 
2025-11-24 04:43:20.659180 | TASK [bindep : Look for bindep.txt]
2025-11-24 04:43:21.091859 | controller | ok
2025-11-24 04:43:21.105187 | 
2025-11-24 04:43:21.105325 | TASK [bindep : Define bindep_file fact]
2025-11-24 04:43:21.152769 | controller | ok
2025-11-24 04:43:21.163445 | 
2025-11-24 04:43:21.163584 | TASK [bindep : Look for other-requirements.txt]
2025-11-24 04:43:21.190287 | controller | skipping: Conditional result was False
2025-11-24 04:43:21.203234 | 
2025-11-24 04:43:21.203426 | TASK [bindep : Define bindep_file fact]
2025-11-24 04:43:21.242220 | controller | skipping: Conditional result was False
2025-11-24 04:43:21.253936 | 
2025-11-24 04:43:21.254070 | TASK [bindep : Look for bindep fallback file]
2025-11-24 04:43:21.280955 | controller | skipping: Conditional result was False
2025-11-24 04:43:21.292259 | 
2025-11-24 04:43:21.292405 | TASK [bindep : Define bindep_file fact]
2025-11-24 04:43:21.329196 | controller | skipping: Conditional result was False
2025-11-24 04:43:21.340836 | 
2025-11-24 04:43:21.340967 | TASK [bindep : Include bindep tasks]
2025-11-24 04:43:21.390277 | controller | ok
2025-11-24 04:43:21.404121 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-11-24 04:43:21.418935 | 
2025-11-24 04:43:21.419018 | TASK [bindep : Look for bindep command]
2025-11-24 04:43:21.453762 | controller | skipping: Conditional result was False
2025-11-24 04:43:21.466280 | 
2025-11-24 04:43:21.466409 | TASK [bindep : Check for system bindep]
2025-11-24 04:43:22.014337 | controller | ok: Runtime: 0:00:00.008843
2025-11-24 04:43:22.025609 | 
2025-11-24 04:43:22.025778 | TASK [bindep : Define bindep_command fact]
2025-11-24 04:43:22.062363 | controller | skipping: Conditional result was False
2025-11-24 04:43:22.074224 | 
2025-11-24 04:43:22.074358 | TASK [bindep : Include install tasks]
2025-11-24 04:43:22.121399 | controller | ok
2025-11-24 04:43:22.136857 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-11-24 04:43:22.154419 | 
2025-11-24 04:43:22.154501 | TASK [bindep : Create temp dir for bindep]
2025-11-24 04:43:22.566980 | controller | changed
2025-11-24 04:43:22.578167 | 
2025-11-24 04:43:22.578292 | TASK [Ensure we have pip dependencies]
2025-11-24 04:43:22.606044 | controller | ok
2025-11-24 04:43:22.646008 | 
2025-11-24 04:43:22.646098 | TASK [ensure-pip : Check if pip is installed]
2025-11-23 23:43:22.981166 | controller | /usr/bin/pip3
2025-11-23 23:43:23.023019 | controller | /usr/bin/python3: No module named wheel
2025-11-24 04:43:23.180608 | controller | ok: Runtime: 0:00:00.054269
2025-11-24 04:43:23.192015 | 
2025-11-24 04:43:23.192148 | LOOP [ensure-pip : Install pip from packages]
2025-11-24 04:43:23.241807 | controller | ok: "/var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-11-24 04:43:23.268237 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-11-24 04:43:23.289350 | 
2025-11-24 04:43:23.289483 | TASK [ensure-pip : Install Python 3 pip]
2025-11-24 04:43:25.574311 | controller | changed
2025-11-24 04:43:25.585503 | 
2025-11-24 04:43:25.585631 | TASK [ensure-pip : Check for EPEL repository]
2025-11-24 04:43:25.652334 | controller | skipping: Conditional result was False
2025-11-24 04:43:25.664624 | 
2025-11-24 04:43:25.664793 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-11-24 04:43:25.722299 | controller | skipping: Conditional result was False
2025-11-24 04:43:25.734532 | 
2025-11-24 04:43:25.734668 | TASK [ensure-pip : Install Python 2 pip]
2025-11-24 04:43:25.783321 | controller | skipping: Conditional result was False
2025-11-24 04:43:25.794342 | 
2025-11-24 04:43:25.794480 | TASK [ensure-pip : Ensure setuptools]
2025-11-24 04:43:25.821100 | controller | skipping: Conditional result was False
2025-11-24 04:43:25.833150 | 
2025-11-24 04:43:25.833286 | TASK [ensure-pip : Check for ensurepip module]
2025-11-24 04:43:26.380173 | controller | skipping: Conditional result was False
2025-11-24 04:43:26.393420 | 
2025-11-24 04:43:26.393562 | TASK [ensure-pip : Ensure python3-venv]
2025-11-24 04:43:26.420327 | controller | skipping: Conditional result was False
2025-11-24 04:43:26.432432 | 
2025-11-24 04:43:26.432570 | TASK [ensure-pip : Install pip from source]
2025-11-24 04:43:26.459161 | controller | skipping: Conditional result was False
2025-11-24 04:43:26.470949 | 
2025-11-24 04:43:26.471085 | TASK [ensure-pip : Probe for venv python full path]
2025-11-23 23:43:26.785127 | controller | /usr/bin/python3
2025-11-24 04:43:27.018662 | controller | ok: Runtime: 0:00:00.007483
2025-11-24 04:43:27.030560 | 
2025-11-24 04:43:27.030728 | TASK [ensure-pip : Set host default]
2025-11-24 04:43:27.108975 | controller | ok
2025-11-24 04:43:27.119579 | 
2025-11-24 04:43:27.119740 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-11-24 04:43:27.190084 | controller | ok
2025-11-24 04:43:27.212032 | 
2025-11-24 04:43:27.212162 | TASK [bindep : Install bindep into temporary venv]
2025-11-24 04:43:31.505264 | controller | changed
2025-11-24 04:43:31.518146 | 
2025-11-24 04:43:31.518327 | TASK [bindep : Define bindep_command]
2025-11-24 04:43:31.556726 | controller | ok
2025-11-24 04:43:31.567548 | 
2025-11-24 04:43:31.567754 | LOOP [bindep : Include package tasks]
2025-11-24 04:43:31.642604 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-11-24 04:43:31.642956 | controller | ok: All items complete
2025-11-24 04:43:31.643012 | 
2025-11-24 04:43:31.662097 | controller | included: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-11-24 04:43:31.685222 | 
2025-11-24 04:43:31.685361 | TASK [bindep : Define bindep_run fact]
2025-11-24 04:43:31.718831 | controller | ok
2025-11-24 04:43:31.725387 | 
2025-11-24 04:43:31.725469 | TASK [bindep : Get list of packages to install from bindep]
2025-11-23 23:43:33.234728 | controller | podman
2025-11-23 23:43:33.284020 | controller | python3-jmespath
2025-11-23 23:43:33.284105 | controller | python3-libvirt
2025-11-23 23:43:33.284115 | controller | python3-lxml
2025-11-23 23:43:33.284124 | controller | python3-netaddr
2025-11-24 04:43:33.765854 | controller | ok: Runtime: 0:00:01.252590
2025-11-24 04:43:33.778122 | 
2025-11-24 04:43:33.778265 | TASK [bindep : Install distro packages from bindep]
2025-11-24 04:44:33.605805 | controller | changed
2025-11-24 04:44:33.617195 | 
2025-11-24 04:44:33.617363 | TASK [bindep : Check that packages are installed]
2025-11-24 04:44:35.167284 | controller | ok: Runtime: 0:00:01.183827
2025-11-24 04:44:35.179248 | 
2025-11-24 04:44:35.179389 | TASK [bindep : Fail if we cannot install all packages]
2025-11-24 04:44:35.216752 | controller | skipping: Conditional result was False
2025-11-24 04:44:35.239365 | 
2025-11-24 04:44:35.239510 | TASK [Run test-setup role]
2025-11-24 04:44:35.266822 | controller | ok
2025-11-24 04:44:35.295323 | 
2025-11-24 04:44:35.295413 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-24 04:44:35.588249 | controller | ok
2025-11-24 04:44:35.598969 | 
2025-11-24 04:44:35.599101 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-24 04:44:36.148554 | controller | skipping: Conditional result was False
2025-11-24 04:44:36.189487 | 
2025-11-24 04:44:36.189642 | TASK [bindep : Remove bindep temp dir]
2025-11-24 04:44:36.626563 | controller | ok
2025-11-24 04:44:36.649044 | 
2025-11-24 04:44:36.649175 | PLAY RECAP
2025-11-24 04:44:36.649256 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-11-24 04:44:36.649300 | 
2025-11-24 04:44:36.773718 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-24 04:44:36.775587 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-11-24 04:44:37.304783 | 
2025-11-24 04:44:37.304890 | PLAY [all]
2025-11-24 04:44:37.323600 | 
2025-11-24 04:44:37.323670 | TASK [Abort when test_command variable is undefined]
2025-11-24 04:44:37.357851 | controller | skipping: Conditional result was False
2025-11-24 04:44:37.363280 | 
2025-11-24 04:44:37.363351 | TASK [Convert test_command to list]
2025-11-24 04:44:37.428107 | controller | skipping: Conditional result was False
2025-11-24 04:44:37.441860 | 
2025-11-24 04:44:37.442020 | TASK [Use test_command list]
2025-11-24 04:44:37.511350 | controller | ok
2025-11-24 04:44:37.523506 | 
2025-11-24 04:44:37.523662 | LOOP [Run test_command]
2025-11-24 04:44:37.939668 | controller | no check to run
2025-11-24 04:44:37.940020 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005042
2025-11-24 04:44:37.981998 | 
2025-11-24 04:44:37.982162 | PLAY RECAP
2025-11-24 04:44:37.982246 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-24 04:44:37.982290 | 
2025-11-24 04:44:38.080508 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-11-24 04:44:38.082244 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-24 04:44:38.647011 | 
2025-11-24 04:44:38.647119 | PLAY [all]
2025-11-24 04:44:38.666620 | 
2025-11-24 04:44:38.666715 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-24 04:44:39.118323 | controller | changed: non-zero return code
2025-11-24 04:44:39.129776 | 
2025-11-24 04:44:39.129928 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-24 04:44:39.156432 | controller | skipping: Conditional result was False
2025-11-24 04:44:39.168118 | 
2025-11-24 04:44:39.168260 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-24 04:44:39.207200 | 
2025-11-24 04:44:39.207444 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-24 04:44:39.245463 | 
2025-11-24 04:44:39.245729 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-24 04:44:39.272232 | controller | skipping: Conditional result was False
2025-11-24 04:44:39.284248 | 
2025-11-24 04:44:39.284388 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-24 04:44:39.324825 | 
2025-11-24 04:44:39.325073 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-24 04:44:39.351367 | controller | skipping: Conditional result was False
2025-11-24 04:44:39.362836 | 
2025-11-24 04:44:39.362978 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-24 04:44:39.389366 | controller | skipping: Conditional result was False
2025-11-24 04:44:39.400957 | 
2025-11-24 04:44:39.401089 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-24 04:44:39.427661 | controller | skipping: Conditional result was False
2025-11-24 04:44:39.473346 | 
2025-11-24 04:44:39.473414 | PLAY RECAP
2025-11-24 04:44:39.473471 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-24 04:44:39.473499 | 
2025-11-24 04:44:39.566017 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-24 04:44:39.567717 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 04:44:40.154921 | 
2025-11-24 04:44:40.155022 | PLAY [all]
2025-11-24 04:44:40.173369 | 
2025-11-24 04:44:40.173461 | TASK [include_role : fetch-output]
2025-11-24 04:44:40.213141 | controller | ok
2025-11-24 04:44:40.229212 | 
2025-11-24 04:44:40.229289 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 04:44:40.294051 | controller | skipping: Conditional result was False
2025-11-24 04:44:40.306270 | 
2025-11-24 04:44:40.306409 | TASK [fetch-output : Set log path for single node]
2025-11-24 04:44:40.353237 | controller | ok
2025-11-24 04:44:40.364103 | 
2025-11-24 04:44:40.364238 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 04:44:40.786503 | controller -> localhost | ok: "/var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/logs"
2025-11-24 04:44:41.020598 | controller -> localhost | changed: "/var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/artifacts"
2025-11-24 04:44:41.279756 | controller -> localhost | changed: "/var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/docs"
2025-11-24 04:44:41.301211 | 
2025-11-24 04:44:41.301351 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 04:44:41.982183 | controller | changed: .d..t...... ./
2025-11-24 04:44:41.982529 | controller | changed: All items complete
2025-11-24 04:44:41.982588 | 
2025-11-24 04:44:42.505737 | controller | changed: .d..t...... ./
2025-11-24 04:44:43.051713 | controller | changed: .d..t...... ./
2025-11-24 04:44:43.077275 | 
2025-11-24 04:44:43.077460 | TASK [include_role : fetch-output-openshift]
2025-11-24 04:44:43.104243 | controller | skipping: Conditional result was False
2025-11-24 04:44:43.116625 | 
2025-11-24 04:44:43.116802 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-24 04:44:43.572352 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010919
2025-11-24 04:44:43.857942 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012775
2025-11-24 04:44:43.917041 | 
2025-11-24 04:44:43.917171 | PLAY [all]
2025-11-24 04:44:43.936428 | 
2025-11-24 04:44:43.936530 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-11-24 04:44:44.442860 | controller | changed
2025-11-24 04:44:44.487329 | 
2025-11-24 04:44:44.487401 | PLAY RECAP
2025-11-24 04:44:44.487454 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-24 04:44:44.487481 | 
2025-11-24 04:44:44.585588 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 04:44:44.587187 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-11-24 04:44:45.220360 | 
2025-11-24 04:44:45.220482 | PLAY [localhost]
2025-11-24 04:44:45.238118 | 
2025-11-24 04:44:45.238194 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-24 04:44:45.677527 | localhost | changed
2025-11-24 04:44:45.687426 | 
2025-11-24 04:44:45.687589 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-24 04:44:45.733128 | localhost | ok
2025-11-24 04:44:45.750452 | 
2025-11-24 04:44:45.750591 | TASK [add-fileserver : Create SSH private key tempfile]
2025-11-24 04:44:46.184891 | localhost | changed
2025-11-24 04:44:46.196418 | 
2025-11-24 04:44:46.196566 | TASK [add-fileserver : Create SSH private key from secret]
2025-11-24 04:44:46.913173 | localhost | changed
2025-11-24 04:44:46.923732 | 
2025-11-24 04:44:46.923874 | TASK [add-fileserver : Add fileserver ssh key]
2025-11-24 04:44:47.347193 | localhost | Identity added: /var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/tmp/ansible.1q4c2msm (/var/lib/zuul/builds/b9d85a1c32634671a1c4a55313443972/work/tmp/ansible.1q4c2msm)
2025-11-24 04:44:47.347505 | localhost | ok: Runtime: 0:00:00.007263
2025-11-24 04:44:47.358735 | 
2025-11-24 04:44:47.358934 | TASK [add-fileserver : Remove SSH private key from disk]
2025-11-24 04:44:47.639325 | localhost | ok: Runtime: 0:00:00.005273
2025-11-24 04:44:47.649291 | 
2025-11-24 04:44:47.649425 | TASK [add-fileserver : Add fileserver to inventory]
2025-11-24 04:44:47.716883 | localhost | changed
2025-11-24 04:44:47.725807 | 
2025-11-24 04:44:47.725942 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-11-24 04:44:48.097921 | localhost | changed
2025-11-24 04:44:48.134164 | 
2025-11-24 04:44:48.134239 | PLAY [localhost]
2025-11-24 04:44:48.150541 | 
2025-11-24 04:44:48.150621 | TASK [Generate bulk log download script]
2025-11-24 04:44:48.170807 | localhost | ok
2025-11-24 04:44:48.186061 | 
2025-11-24 04:44:48.186147 | TASK [local-log-download : Check API endpoint is defined]
2025-11-24 04:44:48.215757 | localhost | ok: All assertions passed
2025-11-24 04:44:48.221634 | 
2025-11-24 04:44:48.221738 | TASK [local-log-download : Create download script]
2025-11-24 04:44:48.672546 | localhost -> localhost | changed
2025-11-24 04:44:48.681280 | 
2025-11-24 04:44:48.681342 | TASK [Register quick-download link]
2025-11-24 04:44:48.699141 | localhost | ok
2025-11-24 04:44:48.736417 | 
2025-11-24 04:44:48.736516 | PLAY [logserver.rdoproject.org]
2025-11-24 04:44:48.745445 | 
2025-11-24 04:44:48.745503 | TASK [Set zuul-log-path fact]
2025-11-24 04:44:48.762234 | logserver.rdoproject.org | ok
2025-11-24 04:44:48.770863 | 
2025-11-24 04:44:48.770926 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 04:44:48.808138 | logserver.rdoproject.org | ok
2025-11-24 04:44:48.815524 | 
2025-11-24 04:44:48.815608 | TASK [upload-logs : Create log directories]
2025-11-24 04:44:49.836635 | logserver.rdoproject.org | changed
2025-11-24 04:44:49.843133 | 
2025-11-24 04:44:49.843264 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-11-24 04:44:50.165664 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005862
2025-11-24 04:44:50.171757 | 
2025-11-24 04:44:50.171860 | TASK [upload-logs : Upload logs to log server]
2025-11-24 04:44:50.914442 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-11-24 04:44:50.920486 | 
2025-11-24 04:44:50.920610 | LOOP [upload-logs : Compress console log and json output]
2025-11-24 04:44:50.988813 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 04:44:51.000553 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 04:44:51.018086 | 
2025-11-24 04:44:51.018263 | LOOP [upload-logs : Upload compressed console log and json output]
2025-11-24 04:44:51.068083 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 04:44:51.068385 | 
2025-11-24 04:44:51.071565 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 04:44:51.082428 | 
2025-11-24 04:44:51.082615 | LOOP [upload-logs : Upload console log and json output]