2025-10-07 15:55:35.727533 | Job console starting... 2025-10-07 15:55:35.735842 | Updating repositories 2025-10-07 15:55:35.775601 | Preparing job workspace 2025-10-07 15:55:39.410155 | Running Ansible setup... 2025-10-07 15:55:43.445033 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 15:55:44.161457 | 2025-10-07 15:55:44.161600 | PLAY [localhost] 2025-10-07 15:55:44.172108 | 2025-10-07 15:55:44.172223 | TASK [Gathering Facts] 2025-10-07 15:55:45.297414 | localhost | ok 2025-10-07 15:55:45.331310 | 2025-10-07 15:55:45.331562 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-07 15:55:45.792672 | localhost -> localhost | changed 2025-10-07 15:55:45.804853 | 2025-10-07 15:55:45.805010 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-07 15:55:46.745769 | localhost -> localhost | changed 2025-10-07 15:55:46.754884 | 2025-10-07 15:55:46.754981 | TASK [Setup log path fact] 2025-10-07 15:55:46.774241 | localhost | ok 2025-10-07 15:55:46.788403 | 2025-10-07 15:55:46.788515 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 15:55:46.816972 | localhost | ok 2025-10-07 15:55:46.825800 | 2025-10-07 15:55:46.825901 | TASK [emit-job-header : Print job information] 2025-10-07 15:55:46.854642 | # Job Information 2025-10-07 15:55:46.854893 | Ansible Version: 2.15.12 2025-10-07 15:55:46.854925 | Job: cifmw-molecule-cifmw_helpers 2025-10-07 15:55:46.854946 | Pipeline: github-check 2025-10-07 15:55:46.854965 | Executor: ze03.softwarefactory-project.io 2025-10-07 15:55:46.854987 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368 2025-10-07 15:55:46.855008 | Log URL (when completed): https://logserver.rdoproject.org/f46/rdoproject.org/f464af9849e2448e8ba7cd241154b9f1/ 2025-10-07 15:55:46.855028 | Event ID: baecefb0-a395-11f0-9567-2a348cffbde7 2025-10-07 15:55:46.859038 | 2025-10-07 15:55:46.859123 | LOOP [emit-job-header : Print node information] 2025-10-07 15:55:46.974372 | localhost | ok: 2025-10-07 15:55:46.974559 | localhost | # Node Information 2025-10-07 15:55:46.974594 | localhost | Inventory Hostname: controller 2025-10-07 15:55:46.974624 | localhost | Hostname: np0005474587 2025-10-07 15:55:46.974653 | localhost | Username: zuul 2025-10-07 15:55:46.974681 | localhost | Distro: CentOS 9 2025-10-07 15:55:46.974704 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-07 15:55:46.974745 | localhost | Region: RegionOne 2025-10-07 15:55:46.974775 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-07 15:55:46.974801 | localhost | Product Name: OpenStack Nova 2025-10-07 15:55:46.974826 | localhost | Interface IP: 38.102.83.145 2025-10-07 15:55:46.998328 | 2025-10-07 15:55:46.998433 | PLAY [all] 2025-10-07 15:55:47.006128 | 2025-10-07 15:55:47.006211 | TASK [Gather network facts] 2025-10-07 15:55:47.491072 | controller | ok 2025-10-07 15:55:47.514375 | 2025-10-07 15:55:47.514525 | TASK [include_role : start-zuul-console] 2025-10-07 15:55:47.538081 | controller | ok 2025-10-07 15:55:47.554489 | 2025-10-07 15:55:47.554637 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-07 15:55:48.043383 | controller | ok 2025-10-07 15:55:48.056769 | 2025-10-07 15:55:48.056896 | TASK [include_role : add-build-sshkey] 2025-10-07 15:55:48.090395 | controller | ok 2025-10-07 15:55:48.109004 | 2025-10-07 15:55:48.109139 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-07 15:55:48.390989 | controller -> localhost | ok 2025-10-07 15:55:48.405640 | 2025-10-07 15:55:48.405873 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-07 15:55:48.444448 | controller | ok 2025-10-07 15:55:48.471088 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-07 15:55:48.480896 | 2025-10-07 15:55:48.481076 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-07 15:55:49.332801 | controller -> localhost | Generating public/private rsa key pair. 2025-10-07 15:55:49.333087 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/f464af9849e2448e8ba7cd241154b9f1_id_rsa. 2025-10-07 15:55:49.333126 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/f464af9849e2448e8ba7cd241154b9f1_id_rsa.pub. 2025-10-07 15:55:49.333154 | controller -> localhost | The key fingerprint is: 2025-10-07 15:55:49.333179 | controller -> localhost | SHA256:4GI1UQZsIXCVPfgKLBNiZCS4BoWl8VtGJ20h3THc9Tw zuul-build-sshkey 2025-10-07 15:55:49.333204 | controller -> localhost | The key's randomart image is: 2025-10-07 15:55:49.333244 | controller -> localhost | +---[RSA 3072]----+ 2025-10-07 15:55:49.333269 | controller -> localhost | |*B+.*=B@=o .. | 2025-10-07 15:55:49.333293 | controller -> localhost | |B=.o =Oo=.. o | 2025-10-07 15:55:49.333316 | controller -> localhost | |+o.ooo+. . E | 2025-10-07 15:55:49.333340 | controller -> localhost | |..o+oo o. . | 2025-10-07 15:55:49.333363 | controller -> localhost | |. .oo...S | 2025-10-07 15:55:49.333385 | controller -> localhost | | . .. | 2025-10-07 15:55:49.333408 | controller -> localhost | | | 2025-10-07 15:55:49.333431 | controller -> localhost | | | 2025-10-07 15:55:49.333454 | controller -> localhost | | | 2025-10-07 15:55:49.333476 | controller -> localhost | +----[SHA256]-----+ 2025-10-07 15:55:49.333548 | controller -> localhost | ok: Runtime: 0:00:00.328780 2025-10-07 15:55:49.340817 | 2025-10-07 15:55:49.340908 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-07 15:55:49.370495 | controller | ok 2025-10-07 15:55:49.381341 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-07 15:55:49.391080 | 2025-10-07 15:55:49.391159 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-07 15:55:49.415631 | controller | skipping: Conditional result was False 2025-10-07 15:55:49.421782 | 2025-10-07 15:55:49.421878 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-07 15:55:49.912916 | controller | changed 2025-10-07 15:55:49.918713 | 2025-10-07 15:55:49.918839 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-07 15:55:50.238308 | controller | ok 2025-10-07 15:55:50.244356 | 2025-10-07 15:55:50.244442 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-07 15:55:51.168116 | controller | changed 2025-10-07 15:55:51.187160 | 2025-10-07 15:55:51.187285 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-07 15:55:52.124919 | controller | changed 2025-10-07 15:55:52.140120 | 2025-10-07 15:55:52.140285 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-07 15:55:52.189096 | controller | skipping: Conditional result was False 2025-10-07 15:55:52.200442 | 2025-10-07 15:55:52.200637 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-07 15:55:52.666954 | controller -> localhost | changed 2025-10-07 15:55:52.689088 | 2025-10-07 15:55:52.689214 | TASK [add-build-sshkey : Add back temp key] 2025-10-07 15:55:52.974782 | controller -> localhost | Identity added: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/f464af9849e2448e8ba7cd241154b9f1_id_rsa (zuul-build-sshkey) 2025-10-07 15:55:52.974988 | controller -> localhost | ok: Runtime: 0:00:00.009300 2025-10-07 15:55:52.986700 | 2025-10-07 15:55:52.987126 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-07 15:55:53.438000 | controller | ok 2025-10-07 15:55:53.452680 | 2025-10-07 15:55:53.452840 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-07 15:55:53.514762 | controller | skipping: Conditional result was False 2025-10-07 15:55:53.534005 | 2025-10-07 15:55:53.534144 | TASK [include_role : validate-host] 2025-10-07 15:55:53.570867 | controller | ok 2025-10-07 15:55:53.598272 | 2025-10-07 15:55:53.598407 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-07 15:55:53.631024 | controller | ok 2025-10-07 15:55:53.638211 | 2025-10-07 15:55:53.638351 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-07 15:55:53.921673 | controller -> localhost | ok 2025-10-07 15:55:53.978501 | 2025-10-07 15:55:53.978652 | TASK [validate-host : Collect information about the host] 2025-10-07 15:55:54.727848 | controller | ok 2025-10-07 15:55:54.753872 | 2025-10-07 15:55:54.754025 | TASK [validate-host : Sanitize hostname] 2025-10-07 15:55:54.826813 | controller | ok 2025-10-07 15:55:54.833280 | 2025-10-07 15:55:54.833423 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-07 15:55:55.356002 | controller -> localhost | changed 2025-10-07 15:55:55.369548 | 2025-10-07 15:55:55.369757 | TASK [validate-host : Collect information about zuul worker] 2025-10-07 15:55:55.821413 | controller | ok 2025-10-07 15:55:55.845935 | 2025-10-07 15:55:55.846090 | TASK [validate-host : Write out all zuul information for each host] 2025-10-07 15:55:56.426777 | controller -> localhost | changed 2025-10-07 15:55:56.436902 | 2025-10-07 15:55:56.436981 | TASK [include_role : prepare-workspace-openshift] 2025-10-07 15:55:56.462172 | controller | skipping: Conditional result was False 2025-10-07 15:55:56.469146 | 2025-10-07 15:55:56.469224 | TASK [include_role : remove-zuul-sshkey] 2025-10-07 15:55:56.494176 | controller | skipping: Conditional result was False 2025-10-07 15:55:56.500367 | 2025-10-07 15:55:56.500453 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 15:55:56.786874 | controller | ok: "logs" 2025-10-07 15:55:56.787141 | controller | ok: All items complete 2025-10-07 15:55:56.787177 | 2025-10-07 15:55:57.004699 | controller | ok: "artifacts" 2025-10-07 15:55:57.207190 | controller | ok: "docs" 2025-10-07 15:55:57.218921 | 2025-10-07 15:55:57.219043 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 15:55:57.560219 | controller | changed: "logs" 2025-10-07 15:55:57.813397 | controller | changed: "artifacts" 2025-10-07 15:55:58.053633 | controller | changed: "docs" 2025-10-07 15:55:58.087068 | 2025-10-07 15:55:58.087169 | PLAY RECAP 2025-10-07 15:55:58.087211 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-07 15:55:58.087238 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 15:55:58.087256 | 2025-10-07 15:55:58.250854 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 15:55:58.252562 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 15:55:58.862558 | 2025-10-07 15:55:58.862743 | PLAY [localhost] 2025-10-07 15:55:58.879991 | 2025-10-07 15:55:58.880091 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-07 15:55:59.304017 | localhost | ok 2025-10-07 15:55:59.313699 | 2025-10-07 15:55:59.313870 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-07 15:56:00.036623 | localhost | changed 2025-10-07 15:56:00.065218 | 2025-10-07 15:56:00.065338 | PLAY [all] 2025-10-07 15:56:00.083674 | 2025-10-07 15:56:00.083826 | TASK [include_role : prepare-workspace] 2025-10-07 15:56:00.106208 | controller | ok 2025-10-07 15:56:00.124549 | 2025-10-07 15:56:00.124719 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-07 15:56:00.582123 | controller | ok 2025-10-07 15:56:00.589020 | 2025-10-07 15:56:00.589090 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-07 15:56:02.608567 | controller | Output suppressed because no_log was given 2025-10-07 15:56:02.620460 | 2025-10-07 15:56:02.620628 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 15:56:02.933879 | controller | changed: "logs" 2025-10-07 15:56:03.203266 | controller | changed: "artifacts" 2025-10-07 15:56:03.472406 | controller | changed: "docs" 2025-10-07 15:56:03.485087 | 2025-10-07 15:56:03.485212 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 15:56:03.765876 | controller | changed: "logs" 2025-10-07 15:56:03.766171 | controller | changed: All items complete 2025-10-07 15:56:03.766206 | 2025-10-07 15:56:03.977438 | controller | changed: "artifacts" 2025-10-07 15:56:04.271380 | controller | changed: "docs" 2025-10-07 15:56:04.302226 | 2025-10-07 15:56:04.302411 | TASK [Check if worker can sudo] 2025-10-07 15:56:04.865963 | controller | ok: Runtime: 0:00:00.061483 2025-10-07 15:56:04.875282 | 2025-10-07 15:56:04.875466 | TASK [configure-mirrors : Gather needed facts] 2025-10-07 15:56:04.942949 | controller | skipping: Conditional result was False 2025-10-07 15:56:04.952535 | 2025-10-07 15:56:04.952659 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-07 15:56:05.017608 | controller | ok 2025-10-07 15:56:05.030570 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-07 15:56:05.071538 | 2025-10-07 15:56:05.071668 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-07 15:56:05.367384 | controller | ok 2025-10-07 15:56:05.373322 | 2025-10-07 15:56:05.373396 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-07 15:56:05.467845 | controller | ok: "/var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-07 15:56:05.484766 | 2025-10-07 15:56:05.484896 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-07 15:56:06.453318 | controller | changed 2025-10-07 15:56:06.461540 | 2025-10-07 15:56:06.461672 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-07 15:56:06.546238 | controller | ok: "/var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-07 15:56:06.546458 | controller | ok: All items complete 2025-10-07 15:56:06.546495 | 2025-10-07 15:56:06.607404 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-07 15:56:06.614635 | 2025-10-07 15:56:06.614755 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-07 15:56:07.581358 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-07 15:56:08.496934 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-07 15:56:08.523540 | 2025-10-07 15:56:08.523769 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-07 15:56:08.991096 | controller | changed: section and option added 2025-10-07 15:56:09.030329 | 2025-10-07 15:56:09.030456 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-07 15:56:09.909646 | controller | 29 files removed 2025-10-07 15:56:09.910052 | controller | ok: Item: dnf clean all Runtime: 0:00:00.501239 2025-10-07 15:56:09.910135 | controller | changed: All items complete 2025-10-07 15:56:09.910182 | 2025-10-07 15:56:20.408486 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-10-07 15:56:20.408634 | controller | DNF version: 4.14.0 2025-10-07 15:56:20.408670 | controller | cachedir: /var/cache/dnf 2025-10-07 15:56:20.408699 | controller | Making cache files for all metadata files. 2025-10-07 15:56:20.408750 | controller | baseos: has expired and will be refreshed. 2025-10-07 15:56:20.408783 | controller | appstream: has expired and will be refreshed. 2025-10-07 15:56:20.408808 | controller | crb: has expired and will be refreshed. 2025-10-07 15:56:20.408844 | controller | extras-common: has expired and will be refreshed. 2025-10-07 15:56:20.408869 | controller | repo: downloading from remote: baseos 2025-10-07 15:56:20.408893 | controller | CentOS Stream 9 - BaseOS 65 MB/s | 8.8 MB 00:00 2025-10-07 15:56:20.408918 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-07 15:56:20.408942 | controller | repo: downloading from remote: appstream 2025-10-07 15:56:20.408965 | controller | CentOS Stream 9 - AppStream 78 MB/s | 25 MB 00:00 2025-10-07 15:56:20.408988 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-07 15:56:20.409011 | controller | repo: downloading from remote: crb 2025-10-07 15:56:20.409035 | controller | CentOS Stream 9 - CRB 50 MB/s | 7.1 MB 00:00 2025-10-07 15:56:20.409059 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-07 15:56:20.409082 | controller | repo: downloading from remote: extras-common 2025-10-07 15:56:20.409106 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-07 15:56:20.409129 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-07 15:56:20.409152 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-07 15:56:20.409176 | controller | Completion plugin: Generating completion cache... 2025-10-07 15:56:20.409200 | controller | Metadata cache created. 2025-10-07 15:56:20.409237 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.201744 2025-10-07 15:56:20.438841 | 2025-10-07 15:56:20.439028 | PLAY RECAP 2025-10-07 15:56:20.439147 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-07 15:56:20.439363 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 15:56:20.439409 | 2025-10-07 15:56:20.601541 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 15:56:20.602377 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 15:56:21.182634 | 2025-10-07 15:56:21.182777 | PLAY [all] 2025-10-07 15:56:21.205011 | 2025-10-07 15:56:21.205145 | TASK [Install binary dependencies] 2025-10-07 15:56:21.276383 | controller | ok 2025-10-07 15:56:21.296547 | 2025-10-07 15:56:21.296670 | TASK [bindep : Include find tasks] 2025-10-07 15:56:21.336712 | controller | ok 2025-10-07 15:56:21.344171 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-07 15:56:21.349933 | 2025-10-07 15:56:21.349995 | TASK [bindep : Look for bindep.txt] 2025-10-07 15:56:21.805148 | controller | ok 2025-10-07 15:56:21.820229 | 2025-10-07 15:56:21.820405 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:56:21.871624 | controller | ok 2025-10-07 15:56:21.884046 | 2025-10-07 15:56:21.884286 | TASK [bindep : Look for other-requirements.txt] 2025-10-07 15:56:21.913818 | controller | skipping: Conditional result was False 2025-10-07 15:56:21.927973 | 2025-10-07 15:56:21.928193 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:56:21.967116 | controller | skipping: Conditional result was False 2025-10-07 15:56:21.975524 | 2025-10-07 15:56:21.975632 | TASK [bindep : Look for bindep fallback file] 2025-10-07 15:56:22.011981 | controller | skipping: Conditional result was False 2025-10-07 15:56:22.020301 | 2025-10-07 15:56:22.020414 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:56:22.046389 | controller | skipping: Conditional result was False 2025-10-07 15:56:22.054900 | 2025-10-07 15:56:22.054999 | TASK [bindep : Include bindep tasks] 2025-10-07 15:56:22.105720 | controller | ok 2025-10-07 15:56:22.120532 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-07 15:56:22.132633 | 2025-10-07 15:56:22.132757 | TASK [bindep : Look for bindep command] 2025-10-07 15:56:22.168828 | controller | skipping: Conditional result was False 2025-10-07 15:56:22.178580 | 2025-10-07 15:56:22.178682 | TASK [bindep : Check for system bindep] 2025-10-07 15:56:22.723796 | controller | ok: Runtime: 0:00:00.007436 2025-10-07 15:56:22.743402 | 2025-10-07 15:56:22.744264 | TASK [bindep : Define bindep_command fact] 2025-10-07 15:56:22.784864 | controller | skipping: Conditional result was False 2025-10-07 15:56:22.802046 | 2025-10-07 15:56:22.802268 | TASK [bindep : Include install tasks] 2025-10-07 15:56:22.861250 | controller | ok 2025-10-07 15:56:22.873079 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-07 15:56:22.888184 | 2025-10-07 15:56:22.888297 | TASK [bindep : Create temp dir for bindep] 2025-10-07 15:56:23.340626 | controller | changed 2025-10-07 15:56:23.354370 | 2025-10-07 15:56:23.354564 | TASK [Ensure we have pip dependencies] 2025-10-07 15:56:23.395945 | controller | ok 2025-10-07 15:56:23.434826 | 2025-10-07 15:56:23.434984 | TASK [ensure-pip : Check if pip is installed] 2025-10-07 11:56:23.762002 | controller | /usr/bin/pip3 2025-10-07 11:56:23.789988 | controller | /usr/bin/python3: No module named wheel 2025-10-07 15:56:23.966929 | controller | ok: Runtime: 0:00:00.039543 2025-10-07 15:56:23.979620 | 2025-10-07 15:56:23.979819 | LOOP [ensure-pip : Install pip from packages] 2025-10-07 15:56:24.021657 | controller | ok: "/var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-07 15:56:24.051637 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-07 15:56:24.073229 | 2025-10-07 15:56:24.073428 | TASK [ensure-pip : Install Python 3 pip] 2025-10-07 15:56:26.798140 | controller | changed 2025-10-07 15:56:26.819028 | 2025-10-07 15:56:26.819182 | TASK [ensure-pip : Check for EPEL repository] 2025-10-07 15:56:26.887026 | controller | skipping: Conditional result was False 2025-10-07 15:56:26.901552 | 2025-10-07 15:56:26.901784 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-07 15:56:26.971002 | controller | skipping: Conditional result was False 2025-10-07 15:56:26.982441 | 2025-10-07 15:56:26.982923 | TASK [ensure-pip : Install Python 2 pip] 2025-10-07 15:56:27.049680 | controller | skipping: Conditional result was False 2025-10-07 15:56:27.060007 | 2025-10-07 15:56:27.060170 | TASK [ensure-pip : Ensure setuptools] 2025-10-07 15:56:27.086919 | controller | skipping: Conditional result was False 2025-10-07 15:56:27.095435 | 2025-10-07 15:56:27.095578 | TASK [ensure-pip : Check for ensurepip module] 2025-10-07 15:56:27.635877 | controller | skipping: Conditional result was False 2025-10-07 15:56:27.652006 | 2025-10-07 15:56:27.652238 | TASK [ensure-pip : Ensure python3-venv] 2025-10-07 15:56:27.670822 | controller | skipping: Conditional result was False 2025-10-07 15:56:27.687538 | 2025-10-07 15:56:27.687760 | TASK [ensure-pip : Install pip from source] 2025-10-07 15:56:27.706443 | controller | skipping: Conditional result was False 2025-10-07 15:56:27.721437 | 2025-10-07 15:56:27.721925 | TASK [ensure-pip : Probe for venv python full path] 2025-10-07 11:56:28.063501 | controller | /usr/bin/python3 2025-10-07 15:56:28.285869 | controller | ok: Runtime: 0:00:00.004627 2025-10-07 15:56:28.300489 | 2025-10-07 15:56:28.300682 | TASK [ensure-pip : Set host default] 2025-10-07 15:56:28.388600 | controller | ok 2025-10-07 15:56:28.398319 | 2025-10-07 15:56:28.398473 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-07 15:56:28.475235 | controller | ok 2025-10-07 15:56:28.486060 | 2025-10-07 15:56:28.486137 | TASK [bindep : Install bindep into temporary venv] 2025-10-07 15:56:32.624810 | controller | changed 2025-10-07 15:56:32.633511 | 2025-10-07 15:56:32.633651 | TASK [bindep : Define bindep_command] 2025-10-07 15:56:32.686556 | controller | ok 2025-10-07 15:56:32.699534 | 2025-10-07 15:56:32.699677 | LOOP [bindep : Include package tasks] 2025-10-07 15:56:32.768359 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-07 15:56:32.768554 | controller | ok: All items complete 2025-10-07 15:56:32.768580 | 2025-10-07 15:56:32.788955 | controller | included: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-07 15:56:32.804276 | 2025-10-07 15:56:32.804370 | TASK [bindep : Define bindep_run fact] 2025-10-07 15:56:32.837373 | controller | ok 2025-10-07 15:56:32.845115 | 2025-10-07 15:56:32.845204 | TASK [bindep : Get list of packages to install from bindep] 2025-10-07 11:56:34.509760 | controller | podman 2025-10-07 11:56:34.555515 | controller | python3-jmespath 2025-10-07 11:56:34.555802 | controller | python3-libvirt 2025-10-07 11:56:34.555831 | controller | python3-lxml 2025-10-07 11:56:34.555857 | controller | python3-netaddr 2025-10-07 15:56:34.889940 | controller | ok: Runtime: 0:00:01.440700 2025-10-07 15:56:34.903449 | 2025-10-07 15:56:34.903611 | TASK [bindep : Install distro packages from bindep] 2025-10-07 15:57:46.386485 | controller | changed 2025-10-07 15:57:46.405588 | 2025-10-07 15:57:46.405769 | TASK [bindep : Check that packages are installed] 2025-10-07 15:57:47.972372 | controller | ok: Runtime: 0:00:01.189036 2025-10-07 15:57:47.980151 | 2025-10-07 15:57:47.980269 | TASK [bindep : Fail if we cannot install all packages] 2025-10-07 15:57:48.025673 | controller | skipping: Conditional result was False 2025-10-07 15:57:48.037039 | 2025-10-07 15:57:48.037166 | TASK [Run test-setup role] 2025-10-07 15:57:48.067391 | controller | ok 2025-10-07 15:57:48.087798 | 2025-10-07 15:57:48.087924 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-07 15:57:48.383366 | controller | ok 2025-10-07 15:57:48.392819 | 2025-10-07 15:57:48.392955 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-07 15:57:48.931959 | controller | skipping: Conditional result was False 2025-10-07 15:57:48.956335 | 2025-10-07 15:57:48.956476 | TASK [bindep : Remove bindep temp dir] 2025-10-07 15:57:49.379588 | controller | ok 2025-10-07 15:57:49.393394 | 2025-10-07 15:57:49.393456 | PLAY RECAP 2025-10-07 15:57:49.393500 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-07 15:57:49.393520 | 2025-10-07 15:57:49.564943 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 15:57:49.565956 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 15:57:50.212088 | 2025-10-07 15:57:50.212202 | PLAY [all] 2025-10-07 15:57:50.232061 | 2025-10-07 15:57:50.232139 | TASK [Abort when test_command variable is undefined] 2025-10-07 15:57:50.277320 | controller | skipping: Conditional result was False 2025-10-07 15:57:50.283437 | 2025-10-07 15:57:50.283512 | TASK [Convert test_command to list] 2025-10-07 15:57:50.329009 | controller | skipping: Conditional result was False 2025-10-07 15:57:50.335665 | 2025-10-07 15:57:50.335766 | TASK [Use test_command list] 2025-10-07 15:57:50.395101 | controller | ok 2025-10-07 15:57:50.411617 | 2025-10-07 15:57:50.411702 | LOOP [Run test_command] 2025-10-07 15:57:50.951553 | controller | no check to run 2025-10-07 15:57:50.953096 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.021245 2025-10-07 15:57:51.008676 | 2025-10-07 15:57:51.008825 | PLAY RECAP 2025-10-07 15:57:51.008881 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 15:57:51.008911 | 2025-10-07 15:57:51.136245 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 15:57:51.138075 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 15:57:51.745149 | 2025-10-07 15:57:51.745263 | PLAY [all] 2025-10-07 15:57:51.766047 | 2025-10-07 15:57:51.766148 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-07 15:57:52.244565 | controller | changed: non-zero return code 2025-10-07 15:57:52.256950 | 2025-10-07 15:57:52.257351 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-07 15:57:52.284506 | controller | skipping: Conditional result was False 2025-10-07 15:57:52.297342 | 2025-10-07 15:57:52.297501 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-07 15:57:52.327533 | 2025-10-07 15:57:52.327722 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-07 15:57:52.368504 | 2025-10-07 15:57:52.368902 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-07 15:57:52.386876 | controller | skipping: Conditional result was False 2025-10-07 15:57:52.403678 | 2025-10-07 15:57:52.403919 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-07 15:57:52.448386 | 2025-10-07 15:57:52.448681 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-07 15:57:52.466626 | controller | skipping: Conditional result was False 2025-10-07 15:57:52.476351 | 2025-10-07 15:57:52.476499 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-07 15:57:52.502220 | controller | skipping: Conditional result was False 2025-10-07 15:57:52.511198 | 2025-10-07 15:57:52.511313 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-07 15:57:52.538034 | controller | skipping: Conditional result was False 2025-10-07 15:57:52.573553 | 2025-10-07 15:57:52.573652 | PLAY RECAP 2025-10-07 15:57:52.573696 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-07 15:57:52.573717 | 2025-10-07 15:57:52.694856 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 15:57:52.696014 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 15:57:53.278046 | 2025-10-07 15:57:53.278169 | PLAY [all] 2025-10-07 15:57:53.298672 | 2025-10-07 15:57:53.298821 | TASK [include_role : fetch-output] 2025-10-07 15:57:53.328434 | controller | ok 2025-10-07 15:57:53.345937 | 2025-10-07 15:57:53.346060 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-07 15:57:53.401313 | controller | skipping: Conditional result was False 2025-10-07 15:57:53.409718 | 2025-10-07 15:57:53.409861 | TASK [fetch-output : Set log path for single node] 2025-10-07 15:57:53.453861 | controller | ok 2025-10-07 15:57:53.462124 | 2025-10-07 15:57:53.462235 | LOOP [fetch-output : Ensure local output dirs] 2025-10-07 15:57:53.936450 | controller -> localhost | ok: "/var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/logs" 2025-10-07 15:57:54.184874 | controller -> localhost | changed: "/var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/artifacts" 2025-10-07 15:57:54.487650 | controller -> localhost | changed: "/var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/docs" 2025-10-07 15:57:54.505141 | 2025-10-07 15:57:54.505319 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-07 15:57:55.360131 | controller | changed: .d..t...... ./ 2025-10-07 15:57:55.360540 | controller | changed: All items complete 2025-10-07 15:57:55.360590 | 2025-10-07 15:57:55.875228 | controller | changed: .d..t...... ./ 2025-10-07 15:57:56.424367 | controller | changed: .d..t...... ./ 2025-10-07 15:57:56.448058 | 2025-10-07 15:57:56.448229 | TASK [include_role : fetch-output-openshift] 2025-10-07 15:57:56.473499 | controller | skipping: Conditional result was False 2025-10-07 15:57:56.485897 | 2025-10-07 15:57:56.486077 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-07 15:57:56.959403 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013858 2025-10-07 15:57:57.202603 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008759 2025-10-07 15:57:57.241245 | 2025-10-07 15:57:57.241378 | PLAY [all] 2025-10-07 15:57:57.257576 | 2025-10-07 15:57:57.257667 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-07 15:57:57.747954 | controller | changed 2025-10-07 15:57:57.802862 | 2025-10-07 15:57:57.803024 | PLAY RECAP 2025-10-07 15:57:57.803100 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 15:57:57.803136 | 2025-10-07 15:57:57.958208 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 15:57:57.959266 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-07 15:57:58.624391 | 2025-10-07 15:57:58.624523 | PLAY [localhost] 2025-10-07 15:57:58.644415 | 2025-10-07 15:57:58.644526 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-07 15:57:59.011529 | localhost | changed 2025-10-07 15:57:59.016653 | 2025-10-07 15:57:59.016804 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-07 15:57:59.049217 | localhost | ok 2025-10-07 15:57:59.058371 | 2025-10-07 15:57:59.058473 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-07 15:57:59.463660 | localhost | changed 2025-10-07 15:57:59.470369 | 2025-10-07 15:57:59.470462 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-07 15:58:00.104815 | localhost | changed 2025-10-07 15:58:00.110728 | 2025-10-07 15:58:00.110866 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-07 15:58:00.569863 | localhost | Identity added: /var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/tmp/ansible.n0etyf_n (/var/lib/zuul/builds/f464af9849e2448e8ba7cd241154b9f1/work/tmp/ansible.n0etyf_n) 2025-10-07 15:58:00.570121 | localhost | ok: Runtime: 0:00:00.019156 2025-10-07 15:58:00.574846 | 2025-10-07 15:58:00.575016 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-07 15:58:00.884468 | localhost | ok: Runtime: 0:00:00.010050 2025-10-07 15:58:00.892711 | 2025-10-07 15:58:00.892963 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-07 15:58:00.959464 | localhost | changed 2025-10-07 15:58:00.965678 | 2025-10-07 15:58:00.965799 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-07 15:58:01.364199 | localhost | changed 2025-10-07 15:58:01.395972 | 2025-10-07 15:58:01.396096 | PLAY [localhost] 2025-10-07 15:58:01.416028 | 2025-10-07 15:58:01.416159 | TASK [Generate bulk log download script] 2025-10-07 15:58:01.437521 | localhost | ok 2025-10-07 15:58:01.455633 | 2025-10-07 15:58:01.455792 | TASK [local-log-download : Check API endpoint is defined] 2025-10-07 15:58:01.484552 | localhost | ok: All assertions passed 2025-10-07 15:58:01.489769 | 2025-10-07 15:58:01.489832 | TASK [local-log-download : Create download script] 2025-10-07 15:58:01.961895 | localhost -> localhost | changed 2025-10-07 15:58:01.972118 | 2025-10-07 15:58:01.972214 | TASK [Register quick-download link] 2025-10-07 15:58:02.002638 | localhost | ok 2025-10-07 15:58:02.047231 | 2025-10-07 15:58:02.047504 | PLAY [logserver.rdoproject.org] 2025-10-07 15:58:02.060101 | 2025-10-07 15:58:02.060189 | TASK [Set zuul-log-path fact] 2025-10-07 15:58:02.077040 | logserver.rdoproject.org | ok 2025-10-07 15:58:02.088116 | 2025-10-07 15:58:02.088209 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 15:58:02.125792 | logserver.rdoproject.org | ok 2025-10-07 15:58:02.131770 | 2025-10-07 15:58:02.131838 | TASK [upload-logs : Create log directories] 2025-10-07 15:58:02.850759 | logserver.rdoproject.org | changed 2025-10-07 15:58:02.854286 | 2025-10-07 15:58:02.854353 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-07 15:58:03.163863 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009704 2025-10-07 15:58:03.170146 | 2025-10-07 15:58:03.170280 | TASK [upload-logs : Upload logs to log server] 2025-10-07 15:58:03.922035 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-07 15:58:03.932825 | 2025-10-07 15:58:03.933003 | LOOP [upload-logs : Compress console log and json output] 2025-10-07 15:58:03.983837 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:58:03.996173 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:58:04.010830 | 2025-10-07 15:58:04.010977 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-07 15:58:04.065359 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:58:04.065621 | 2025-10-07 15:58:04.070783 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:58:04.081160 | 2025-10-07 15:58:04.081254 | LOOP [upload-logs : Upload console log and json output]