2025-10-03 12:49:45.525304 | Job console starting... 2025-10-03 12:49:45.540914 | Updating repositories 2025-10-03 12:49:45.586678 | Preparing job workspace 2025-10-03 12:49:50.085892 | Running Ansible setup... 2025-10-03 12:49:54.267462 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 12:49:55.025332 | 2025-10-03 12:49:55.025497 | PLAY [localhost] 2025-10-03 12:49:55.037608 | 2025-10-03 12:49:55.037716 | TASK [Gathering Facts] 2025-10-03 12:49:56.736405 | localhost | ok 2025-10-03 12:49:56.762760 | 2025-10-03 12:49:56.762926 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-03 12:49:57.435796 | localhost -> localhost | changed 2025-10-03 12:49:57.442589 | 2025-10-03 12:49:57.442687 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-03 12:49:58.447202 | localhost -> localhost | changed 2025-10-03 12:49:58.457234 | 2025-10-03 12:49:58.457338 | TASK [Setup log path fact] 2025-10-03 12:49:58.478377 | localhost | ok 2025-10-03 12:49:58.501714 | 2025-10-03 12:49:58.501844 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 12:49:58.530581 | localhost | ok 2025-10-03 12:49:58.540131 | 2025-10-03 12:49:58.540242 | TASK [emit-job-header : Print job information] 2025-10-03 12:49:58.582423 | # Job Information 2025-10-03 12:49:58.582813 | Ansible Version: 2.15.12 2025-10-03 12:49:58.582854 | Job: cifmw-molecule-federation 2025-10-03 12:49:58.582881 | Pipeline: github-check 2025-10-03 12:49:58.582908 | Executor: ze02.softwarefactory-project.io 2025-10-03 12:49:58.582931 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3366 2025-10-03 12:49:58.582958 | Log URL (when completed): https://logserver.rdoproject.org/ebc/rdoproject.org/ebc897957458433f91f611716f58d099/ 2025-10-03 12:49:58.582984 | Event ID: 31f0a9e0-a057-11f0-8d04-891189cb7229 2025-10-03 12:49:58.587404 | 2025-10-03 12:49:58.587480 | LOOP [emit-job-header : Print node information] 2025-10-03 12:49:58.737354 | localhost | ok: 2025-10-03 12:49:58.737628 | localhost | # Node Information 2025-10-03 12:49:58.737659 | localhost | Inventory Hostname: controller 2025-10-03 12:49:58.737714 | localhost | Hostname: np0005468961 2025-10-03 12:49:58.737735 | localhost | Username: zuul 2025-10-03 12:49:58.737755 | localhost | Distro: CentOS 9 2025-10-03 12:49:58.737773 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-03 12:49:58.737790 | localhost | Region: RegionOne 2025-10-03 12:49:58.737806 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-03 12:49:58.737822 | localhost | Product Name: OpenStack Nova 2025-10-03 12:49:58.737838 | localhost | Interface IP: 38.102.83.214 2025-10-03 12:49:58.786584 | 2025-10-03 12:49:58.786799 | PLAY [all] 2025-10-03 12:49:58.797694 | 2025-10-03 12:49:58.797869 | TASK [Gather network facts] 2025-10-03 12:49:59.300533 | controller | ok 2025-10-03 12:49:59.332415 | 2025-10-03 12:49:59.332557 | TASK [include_role : start-zuul-console] 2025-10-03 12:49:59.365119 | controller | ok 2025-10-03 12:49:59.382419 | 2025-10-03 12:49:59.382574 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-03 12:49:59.847784 | controller | ok 2025-10-03 12:49:59.857346 | 2025-10-03 12:49:59.857473 | TASK [include_role : add-build-sshkey] 2025-10-03 12:49:59.892761 | controller | ok 2025-10-03 12:49:59.914391 | 2025-10-03 12:49:59.914546 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-03 12:50:00.194436 | controller -> localhost | ok 2025-10-03 12:50:00.200500 | 2025-10-03 12:50:00.200567 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-03 12:50:00.231244 | controller | ok 2025-10-03 12:50:00.256588 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-03 12:50:00.265161 | 2025-10-03 12:50:00.265229 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-03 12:50:01.298830 | controller -> localhost | Generating public/private rsa key pair. 2025-10-03 12:50:01.299123 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/ebc897957458433f91f611716f58d099_id_rsa. 2025-10-03 12:50:01.299155 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/ebc897957458433f91f611716f58d099_id_rsa.pub. 2025-10-03 12:50:01.299177 | controller -> localhost | The key fingerprint is: 2025-10-03 12:50:01.299196 | controller -> localhost | SHA256:6S4QO6XmjuRxjVRpqjMvDof6DabvpHfp7FL1kVAypZM zuul-build-sshkey 2025-10-03 12:50:01.299217 | controller -> localhost | The key's randomart image is: 2025-10-03 12:50:01.299235 | controller -> localhost | +---[RSA 3072]----+ 2025-10-03 12:50:01.299252 | controller -> localhost | | ooo | 2025-10-03 12:50:01.299270 | controller -> localhost | | .* | 2025-10-03 12:50:01.299287 | controller -> localhost | | E. . | 2025-10-03 12:50:01.299305 | controller -> localhost | | .+o.o. | 2025-10-03 12:50:01.299322 | controller -> localhost | | o* .S. | 2025-10-03 12:50:01.299338 | controller -> localhost | | . oBo .. | 2025-10-03 12:50:01.299355 | controller -> localhost | |o @+o+. . | 2025-10-03 12:50:01.299372 | controller -> localhost | |.X+@+ .. | 2025-10-03 12:50:01.299388 | controller -> localhost | |+*BBB .. | 2025-10-03 12:50:01.299404 | controller -> localhost | +----[SHA256]-----+ 2025-10-03 12:50:01.299455 | controller -> localhost | ok: Runtime: 0:00:00.441765 2025-10-03 12:50:01.305896 | 2025-10-03 12:50:01.305960 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-03 12:50:01.348876 | controller | ok 2025-10-03 12:50:01.360952 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-03 12:50:01.376205 | 2025-10-03 12:50:01.376341 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-03 12:50:01.404290 | controller | skipping: Conditional result was False 2025-10-03 12:50:01.410963 | 2025-10-03 12:50:01.411034 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-03 12:50:01.923790 | controller | changed 2025-10-03 12:50:01.929024 | 2025-10-03 12:50:01.929086 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-03 12:50:02.227462 | controller | ok 2025-10-03 12:50:02.239765 | 2025-10-03 12:50:02.239914 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-03 12:50:03.235245 | controller | changed 2025-10-03 12:50:03.244263 | 2025-10-03 12:50:03.244408 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-03 12:50:04.182707 | controller | changed 2025-10-03 12:50:04.188572 | 2025-10-03 12:50:04.188751 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-03 12:50:04.215173 | controller | skipping: Conditional result was False 2025-10-03 12:50:04.224124 | 2025-10-03 12:50:04.224242 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-03 12:50:04.731533 | controller -> localhost | changed 2025-10-03 12:50:04.742163 | 2025-10-03 12:50:04.742228 | TASK [add-build-sshkey : Add back temp key] 2025-10-03 12:50:05.081738 | controller -> localhost | Identity added: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/ebc897957458433f91f611716f58d099_id_rsa (zuul-build-sshkey) 2025-10-03 12:50:05.082073 | controller -> localhost | ok: Runtime: 0:00:00.010115 2025-10-03 12:50:05.088430 | 2025-10-03 12:50:05.088491 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-03 12:50:05.610630 | controller | ok 2025-10-03 12:50:05.623677 | 2025-10-03 12:50:05.623803 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-03 12:50:05.675720 | controller | skipping: Conditional result was False 2025-10-03 12:50:05.693516 | 2025-10-03 12:50:05.693701 | TASK [include_role : validate-host] 2025-10-03 12:50:05.737140 | controller | ok 2025-10-03 12:50:05.793912 | 2025-10-03 12:50:05.794054 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-03 12:50:05.823804 | controller | ok 2025-10-03 12:50:05.828797 | 2025-10-03 12:50:05.828860 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-03 12:50:06.075804 | controller -> localhost | ok 2025-10-03 12:50:06.082257 | 2025-10-03 12:50:06.082387 | TASK [validate-host : Collect information about the host] 2025-10-03 12:50:06.868906 | controller | ok 2025-10-03 12:50:06.907594 | 2025-10-03 12:50:06.907750 | TASK [validate-host : Sanitize hostname] 2025-10-03 12:50:07.030312 | controller | ok 2025-10-03 12:50:07.037635 | 2025-10-03 12:50:07.037816 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-03 12:50:07.967641 | controller -> localhost | changed 2025-10-03 12:50:07.974843 | 2025-10-03 12:50:07.974915 | TASK [validate-host : Collect information about zuul worker] 2025-10-03 12:50:08.488896 | controller | ok 2025-10-03 12:50:08.497291 | 2025-10-03 12:50:08.497366 | TASK [validate-host : Write out all zuul information for each host] 2025-10-03 12:50:09.262809 | controller -> localhost | changed 2025-10-03 12:50:09.272998 | 2025-10-03 12:50:09.273067 | TASK [include_role : prepare-workspace-openshift] 2025-10-03 12:50:09.305835 | controller | skipping: Conditional result was False 2025-10-03 12:50:09.312153 | 2025-10-03 12:50:09.312222 | TASK [include_role : remove-zuul-sshkey] 2025-10-03 12:50:09.349568 | controller | skipping: Conditional result was False 2025-10-03 12:50:09.356049 | 2025-10-03 12:50:09.356133 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 12:50:09.624598 | controller | ok: "logs" 2025-10-03 12:50:09.625456 | controller | ok: All items complete 2025-10-03 12:50:09.625486 | 2025-10-03 12:50:09.839717 | controller | ok: "artifacts" 2025-10-03 12:50:10.137971 | controller | ok: "docs" 2025-10-03 12:50:10.152998 | 2025-10-03 12:50:10.153116 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 12:50:10.447685 | controller | changed: "logs" 2025-10-03 12:50:10.672654 | controller | changed: "artifacts" 2025-10-03 12:50:10.915607 | controller | changed: "docs" 2025-10-03 12:50:10.994900 | 2025-10-03 12:50:10.995250 | PLAY RECAP 2025-10-03 12:50:10.995313 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-03 12:50:10.995340 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 12:50:10.995357 | 2025-10-03 12:50:11.517455 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 12:50:11.519242 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 12:50:12.614430 | 2025-10-03 12:50:12.614580 | PLAY [localhost] 2025-10-03 12:50:12.636476 | 2025-10-03 12:50:12.636626 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-03 12:50:13.251632 | localhost | ok 2025-10-03 12:50:13.282455 | 2025-10-03 12:50:13.283219 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-03 12:50:14.187815 | localhost | changed 2025-10-03 12:50:14.209328 | 2025-10-03 12:50:14.209496 | PLAY [all] 2025-10-03 12:50:14.225305 | 2025-10-03 12:50:14.225381 | TASK [include_role : prepare-workspace] 2025-10-03 12:50:14.246509 | controller | ok 2025-10-03 12:50:14.261998 | 2025-10-03 12:50:14.262068 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-03 12:50:14.700353 | controller | ok 2025-10-03 12:50:14.707260 | 2025-10-03 12:50:14.707322 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-03 12:50:17.834511 | controller | Output suppressed because no_log was given 2025-10-03 12:50:17.855292 | 2025-10-03 12:50:17.855459 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 12:50:18.247036 | controller | changed: "logs" 2025-10-03 12:50:18.460007 | controller | changed: "artifacts" 2025-10-03 12:50:18.714256 | controller | changed: "docs" 2025-10-03 12:50:18.729750 | 2025-10-03 12:50:18.729932 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 12:50:19.041333 | controller | changed: "logs" 2025-10-03 12:50:19.041752 | controller | changed: All items complete 2025-10-03 12:50:19.041789 | 2025-10-03 12:50:19.275065 | controller | changed: "artifacts" 2025-10-03 12:50:19.528682 | controller | changed: "docs" 2025-10-03 12:50:19.557151 | 2025-10-03 12:50:19.557290 | TASK [Check if worker can sudo] 2025-10-03 12:50:20.662032 | controller | ok: Runtime: 0:00:00.092195 2025-10-03 12:50:20.668948 | 2025-10-03 12:50:20.669018 | TASK [configure-mirrors : Gather needed facts] 2025-10-03 12:50:20.943933 | controller | skipping: Conditional result was False 2025-10-03 12:50:20.958388 | 2025-10-03 12:50:20.958478 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-03 12:50:21.082105 | controller | ok 2025-10-03 12:50:21.098640 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-03 12:50:21.124436 | 2025-10-03 12:50:21.124602 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-03 12:50:21.410281 | controller | ok 2025-10-03 12:50:21.428465 | 2025-10-03 12:50:21.428606 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-03 12:50:21.552704 | controller | ok: "/var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-03 12:50:21.565478 | 2025-10-03 12:50:21.565716 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-03 12:50:22.598005 | controller | changed 2025-10-03 12:50:22.606281 | 2025-10-03 12:50:22.606349 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-03 12:50:22.743196 | controller | ok: "/var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-03 12:50:22.743435 | controller | ok: All items complete 2025-10-03 12:50:22.743472 | 2025-10-03 12:50:22.883793 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-03 12:50:22.907225 | 2025-10-03 12:50:22.910836 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-03 12:50:24.065307 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-03 12:50:24.993216 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-03 12:50:25.006350 | 2025-10-03 12:50:25.006517 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-03 12:50:25.629182 | controller | changed: section and option added 2025-10-03 12:50:25.663809 | 2025-10-03 12:50:25.664010 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-03 12:50:26.910301 | controller | 29 files removed 2025-10-03 12:50:26.910631 | controller | ok: Item: dnf clean all Runtime: 0:00:00.929561 2025-10-03 12:50:26.910732 | controller | changed: All items complete 2025-10-03 12:50:26.910765 | 2025-10-03 12:50:38.487193 | 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-03 12:50:38.487350 | controller | DNF version: 4.14.0 2025-10-03 12:50:38.487376 | controller | cachedir: /var/cache/dnf 2025-10-03 12:50:38.487396 | controller | Making cache files for all metadata files. 2025-10-03 12:50:38.487414 | controller | baseos: has expired and will be refreshed. 2025-10-03 12:50:38.487432 | controller | appstream: has expired and will be refreshed. 2025-10-03 12:50:38.487448 | controller | crb: has expired and will be refreshed. 2025-10-03 12:50:38.487476 | controller | extras-common: has expired and will be refreshed. 2025-10-03 12:50:38.487492 | controller | repo: downloading from remote: baseos 2025-10-03 12:50:38.487508 | controller | CentOS Stream 9 - BaseOS 37 MB/s | 8.8 MB 00:00 2025-10-03 12:50:38.487524 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-03 12:50:38.487539 | controller | repo: downloading from remote: appstream 2025-10-03 12:50:38.487555 | controller | CentOS Stream 9 - AppStream 78 MB/s | 25 MB 00:00 2025-10-03 12:50:38.487571 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-03 12:50:38.487586 | controller | repo: downloading from remote: crb 2025-10-03 12:50:38.487601 | controller | CentOS Stream 9 - CRB 40 MB/s | 7.1 MB 00:00 2025-10-03 12:50:38.487617 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-03 12:50:38.487633 | controller | repo: downloading from remote: extras-common 2025-10-03 12:50:38.487649 | controller | CentOS Stream 9 - Extras packages 339 kB/s | 20 kB 00:00 2025-10-03 12:50:38.487686 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-03 12:50:38.487704 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-03 12:50:38.487720 | controller | Completion plugin: Generating completion cache... 2025-10-03 12:50:38.487736 | controller | Metadata cache created. 2025-10-03 12:50:38.487763 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.335794 2025-10-03 12:50:38.514830 | 2025-10-03 12:50:38.518840 | PLAY RECAP 2025-10-03 12:50:38.518934 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-03 12:50:38.518967 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 12:50:38.519030 | 2025-10-03 12:50:38.897494 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 12:50:38.898346 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 12:50:40.390767 | 2025-10-03 12:50:40.390925 | PLAY [all] 2025-10-03 12:50:40.439363 | 2025-10-03 12:50:40.439517 | TASK [Install binary dependencies] 2025-10-03 12:50:40.563824 | controller | ok 2025-10-03 12:50:40.610752 | 2025-10-03 12:50:40.610906 | TASK [bindep : Include find tasks] 2025-10-03 12:50:40.699795 | controller | ok 2025-10-03 12:50:40.708447 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-03 12:50:40.746108 | 2025-10-03 12:50:40.750160 | TASK [bindep : Look for bindep.txt] 2025-10-03 12:50:41.923202 | controller | ok 2025-10-03 12:50:41.946795 | 2025-10-03 12:50:41.946971 | TASK [bindep : Define bindep_file fact] 2025-10-03 12:50:42.039048 | controller | ok 2025-10-03 12:50:42.052205 | 2025-10-03 12:50:42.052329 | TASK [bindep : Look for other-requirements.txt] 2025-10-03 12:50:42.095329 | controller | skipping: Conditional result was False 2025-10-03 12:50:42.101937 | 2025-10-03 12:50:42.102017 | TASK [bindep : Define bindep_file fact] 2025-10-03 12:50:42.126905 | controller | skipping: Conditional result was False 2025-10-03 12:50:42.133207 | 2025-10-03 12:50:42.133279 | TASK [bindep : Look for bindep fallback file] 2025-10-03 12:50:42.158225 | controller | skipping: Conditional result was False 2025-10-03 12:50:42.165688 | 2025-10-03 12:50:42.165758 | TASK [bindep : Define bindep_file fact] 2025-10-03 12:50:42.189657 | controller | skipping: Conditional result was False 2025-10-03 12:50:42.196517 | 2025-10-03 12:50:42.196585 | TASK [bindep : Include bindep tasks] 2025-10-03 12:50:42.226597 | controller | ok 2025-10-03 12:50:42.238894 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-03 12:50:42.247839 | 2025-10-03 12:50:42.248165 | TASK [bindep : Look for bindep command] 2025-10-03 12:50:42.272919 | controller | skipping: Conditional result was False 2025-10-03 12:50:42.280762 | 2025-10-03 12:50:42.280952 | TASK [bindep : Check for system bindep] 2025-10-03 12:50:43.349507 | controller | ok: Runtime: 0:00:00.005652 2025-10-03 12:50:43.356961 | 2025-10-03 12:50:43.357116 | TASK [bindep : Define bindep_command fact] 2025-10-03 12:50:43.418685 | controller | skipping: Conditional result was False 2025-10-03 12:50:43.425542 | 2025-10-03 12:50:43.425638 | TASK [bindep : Include install tasks] 2025-10-03 12:50:43.486706 | controller | ok 2025-10-03 12:50:43.496286 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-03 12:50:43.507189 | 2025-10-03 12:50:43.507323 | TASK [bindep : Create temp dir for bindep] 2025-10-03 12:50:43.888513 | controller | changed 2025-10-03 12:50:43.899244 | 2025-10-03 12:50:43.899374 | TASK [Ensure we have pip dependencies] 2025-10-03 12:50:43.924786 | controller | ok 2025-10-03 12:50:43.954999 | 2025-10-03 12:50:43.955147 | TASK [ensure-pip : Check if pip is installed] 2025-10-03 08:50:44.213069 | controller | /usr/bin/pip3 2025-10-03 08:50:44.233327 | controller | /usr/bin/python3: No module named wheel 2025-10-03 12:50:44.489958 | controller | ok: Runtime: 0:00:00.031042 2025-10-03 12:50:44.495981 | 2025-10-03 12:50:44.496044 | LOOP [ensure-pip : Install pip from packages] 2025-10-03 12:50:44.541593 | controller | ok: "/var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-03 12:50:44.569309 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-03 12:50:44.583630 | 2025-10-03 12:50:44.583822 | TASK [ensure-pip : Install Python 3 pip] 2025-10-03 12:50:48.681102 | controller | changed 2025-10-03 12:50:48.686808 | 2025-10-03 12:50:48.686878 | TASK [ensure-pip : Check for EPEL repository] 2025-10-03 12:50:48.735159 | controller | skipping: Conditional result was False 2025-10-03 12:50:48.742277 | 2025-10-03 12:50:48.742346 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-03 12:50:48.800321 | controller | skipping: Conditional result was False 2025-10-03 12:50:48.808490 | 2025-10-03 12:50:48.808705 | TASK [ensure-pip : Install Python 2 pip] 2025-10-03 12:50:48.852462 | controller | skipping: Conditional result was False 2025-10-03 12:50:48.872030 | 2025-10-03 12:50:48.872174 | TASK [ensure-pip : Ensure setuptools] 2025-10-03 12:50:48.911175 | controller | skipping: Conditional result was False 2025-10-03 12:50:48.920641 | 2025-10-03 12:50:48.920871 | TASK [ensure-pip : Check for ensurepip module] 2025-10-03 12:50:49.485477 | controller | skipping: Conditional result was False 2025-10-03 12:50:49.493541 | 2025-10-03 12:50:49.493637 | TASK [ensure-pip : Ensure python3-venv] 2025-10-03 12:50:49.523461 | controller | skipping: Conditional result was False 2025-10-03 12:50:49.532049 | 2025-10-03 12:50:49.532227 | TASK [ensure-pip : Install pip from source] 2025-10-03 12:50:49.566245 | controller | skipping: Conditional result was False 2025-10-03 12:50:49.574345 | 2025-10-03 12:50:49.574417 | TASK [ensure-pip : Probe for venv python full path] 2025-10-03 08:50:49.830491 | controller | /usr/bin/python3 2025-10-03 12:50:50.117236 | controller | ok: Runtime: 0:00:00.004659 2025-10-03 12:50:50.124654 | 2025-10-03 12:50:50.124770 | TASK [ensure-pip : Set host default] 2025-10-03 12:50:50.192267 | controller | ok 2025-10-03 12:50:50.201478 | 2025-10-03 12:50:50.201611 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-03 12:50:50.288046 | controller | ok 2025-10-03 12:50:50.323626 | 2025-10-03 12:50:50.323809 | TASK [bindep : Install bindep into temporary venv] 2025-10-03 12:50:56.467989 | controller | changed 2025-10-03 12:50:56.475055 | 2025-10-03 12:50:56.475149 | TASK [bindep : Define bindep_command] 2025-10-03 12:50:56.501648 | controller | ok 2025-10-03 12:50:56.508504 | 2025-10-03 12:50:56.508608 | LOOP [bindep : Include package tasks] 2025-10-03 12:50:56.566912 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-03 12:50:56.567200 | controller | ok: All items complete 2025-10-03 12:50:56.567229 | 2025-10-03 12:50:56.582527 | controller | included: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-03 12:50:56.594011 | 2025-10-03 12:50:56.594073 | TASK [bindep : Define bindep_run fact] 2025-10-03 12:50:56.624755 | controller | ok 2025-10-03 12:50:56.635252 | 2025-10-03 12:50:56.635366 | TASK [bindep : Get list of packages to install from bindep] 2025-10-03 08:50:58.226565 | controller | podman 2025-10-03 08:50:58.271107 | controller | python3-jmespath 2025-10-03 08:50:58.271278 | controller | python3-libvirt 2025-10-03 08:50:58.271297 | controller | python3-lxml 2025-10-03 08:50:58.271310 | controller | python3-netaddr 2025-10-03 12:50:58.678243 | controller | ok: Runtime: 0:00:01.340651 2025-10-03 12:50:58.684610 | 2025-10-03 12:50:58.684695 | TASK [bindep : Install distro packages from bindep] 2025-10-03 12:52:23.694454 | controller | changed 2025-10-03 12:52:23.700787 | 2025-10-03 12:52:23.700852 | TASK [bindep : Check that packages are installed] 2025-10-03 12:52:25.241215 | controller | ok: Runtime: 0:00:01.116561 2025-10-03 12:52:25.247237 | 2025-10-03 12:52:25.247302 | TASK [bindep : Fail if we cannot install all packages] 2025-10-03 12:52:25.271250 | controller | skipping: Conditional result was False 2025-10-03 12:52:25.281785 | 2025-10-03 12:52:25.281848 | TASK [Run test-setup role] 2025-10-03 12:52:25.301330 | controller | ok 2025-10-03 12:52:25.319502 | 2025-10-03 12:52:25.319575 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-03 12:52:25.555059 | controller | ok 2025-10-03 12:52:25.567966 | 2025-10-03 12:52:25.568040 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-03 12:52:26.126226 | controller | skipping: Conditional result was False 2025-10-03 12:52:26.151390 | 2025-10-03 12:52:26.151622 | TASK [bindep : Remove bindep temp dir] 2025-10-03 12:52:26.535442 | controller | ok 2025-10-03 12:52:26.547083 | 2025-10-03 12:52:26.547150 | PLAY RECAP 2025-10-03 12:52:26.547193 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-03 12:52:26.547213 | 2025-10-03 12:52:26.670738 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 12:52:26.671764 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 12:52:27.378021 | 2025-10-03 12:52:27.378147 | PLAY [all] 2025-10-03 12:52:27.398339 | 2025-10-03 12:52:27.398472 | TASK [Abort when test_command variable is undefined] 2025-10-03 12:52:27.434156 | controller | skipping: Conditional result was False 2025-10-03 12:52:27.439995 | 2025-10-03 12:52:27.440071 | TASK [Convert test_command to list] 2025-10-03 12:52:27.487772 | controller | skipping: Conditional result was False 2025-10-03 12:52:27.494197 | 2025-10-03 12:52:27.494268 | TASK [Use test_command list] 2025-10-03 12:52:27.544250 | controller | ok 2025-10-03 12:52:27.549845 | 2025-10-03 12:52:27.549923 | LOOP [Run test_command] 2025-10-03 12:52:27.998218 | controller | no check to run 2025-10-03 12:52:27.998409 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008508 2025-10-03 12:52:28.047285 | 2025-10-03 12:52:28.047471 | PLAY RECAP 2025-10-03 12:52:28.047545 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 12:52:28.047573 | 2025-10-03 12:52:28.198471 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 12:52:28.199414 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 12:52:28.750791 | 2025-10-03 12:52:28.750930 | PLAY [all] 2025-10-03 12:52:28.775027 | 2025-10-03 12:52:28.775133 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-03 12:52:29.115780 | controller | changed: non-zero return code 2025-10-03 12:52:29.121454 | 2025-10-03 12:52:29.121530 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-03 12:52:29.146184 | controller | skipping: Conditional result was False 2025-10-03 12:52:29.153621 | 2025-10-03 12:52:29.153721 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-03 12:52:29.183833 | 2025-10-03 12:52:29.184000 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-03 12:52:29.204633 | 2025-10-03 12:52:29.204921 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-03 12:52:29.221816 | controller | skipping: Conditional result was False 2025-10-03 12:52:29.228903 | 2025-10-03 12:52:29.228988 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-03 12:52:29.250914 | 2025-10-03 12:52:29.251206 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-03 12:52:29.278741 | controller | skipping: Conditional result was False 2025-10-03 12:52:29.286793 | 2025-10-03 12:52:29.286875 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-03 12:52:29.310928 | controller | skipping: Conditional result was False 2025-10-03 12:52:29.316856 | 2025-10-03 12:52:29.316936 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-03 12:52:29.331456 | controller | skipping: Conditional result was False 2025-10-03 12:52:29.363146 | 2025-10-03 12:52:29.363252 | PLAY RECAP 2025-10-03 12:52:29.363296 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-03 12:52:29.363316 | 2025-10-03 12:52:29.501460 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 12:52:29.502376 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 12:52:30.126595 | 2025-10-03 12:52:30.126898 | PLAY [all] 2025-10-03 12:52:30.174246 | 2025-10-03 12:52:30.174451 | TASK [include_role : fetch-output] 2025-10-03 12:52:30.230444 | controller | ok 2025-10-03 12:52:30.251460 | 2025-10-03 12:52:30.251705 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-03 12:52:30.300363 | controller | skipping: Conditional result was False 2025-10-03 12:52:30.307072 | 2025-10-03 12:52:30.307157 | TASK [fetch-output : Set log path for single node] 2025-10-03 12:52:30.339842 | controller | ok 2025-10-03 12:52:30.345108 | 2025-10-03 12:52:30.345173 | LOOP [fetch-output : Ensure local output dirs] 2025-10-03 12:52:30.754398 | controller -> localhost | ok: "/var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/logs" 2025-10-03 12:52:30.977082 | controller -> localhost | changed: "/var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/artifacts" 2025-10-03 12:52:31.310033 | controller -> localhost | changed: "/var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/docs" 2025-10-03 12:52:31.325770 | 2025-10-03 12:52:31.325889 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-03 12:52:31.974104 | controller | changed: .d..t...... ./ 2025-10-03 12:52:31.974298 | controller | changed: All items complete 2025-10-03 12:52:31.974324 | 2025-10-03 12:52:32.497757 | controller | changed: .d..t...... ./ 2025-10-03 12:52:33.177002 | controller | changed: .d..t...... ./ 2025-10-03 12:52:33.194002 | 2025-10-03 12:52:33.194129 | TASK [include_role : fetch-output-openshift] 2025-10-03 12:52:33.233239 | controller | skipping: Conditional result was False 2025-10-03 12:52:33.250096 | 2025-10-03 12:52:33.250183 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-03 12:52:34.033358 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.025266 2025-10-03 12:52:34.389038 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007648 2025-10-03 12:52:34.436632 | 2025-10-03 12:52:34.436775 | PLAY [all] 2025-10-03 12:52:34.452273 | 2025-10-03 12:52:34.452352 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-03 12:52:34.949058 | controller | changed 2025-10-03 12:52:35.004144 | 2025-10-03 12:52:35.004259 | PLAY RECAP 2025-10-03 12:52:35.004308 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 12:52:35.004330 | 2025-10-03 12:52:35.172943 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 12:52:35.174005 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-03 12:52:35.978350 | 2025-10-03 12:52:35.978503 | PLAY [localhost] 2025-10-03 12:52:35.997836 | 2025-10-03 12:52:35.997921 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-03 12:52:36.424322 | localhost | changed 2025-10-03 12:52:36.429252 | 2025-10-03 12:52:36.429331 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-03 12:52:36.473407 | localhost | ok 2025-10-03 12:52:36.483707 | 2025-10-03 12:52:36.483776 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-03 12:52:36.990748 | localhost | changed 2025-10-03 12:52:36.998377 | 2025-10-03 12:52:36.998531 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-03 12:52:38.063397 | localhost | changed 2025-10-03 12:52:38.078408 | 2025-10-03 12:52:38.078510 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-03 12:52:38.682080 | localhost | Identity added: /var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/tmp/ansible.iylpd_qx (/var/lib/zuul/builds/ebc897957458433f91f611716f58d099/work/tmp/ansible.iylpd_qx) 2025-10-03 12:52:38.682291 | localhost | ok: Runtime: 0:00:00.019882 2025-10-03 12:52:38.690863 | 2025-10-03 12:52:38.690928 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-03 12:52:39.111603 | localhost | ok: Runtime: 0:00:00.004978 2025-10-03 12:52:39.117149 | 2025-10-03 12:52:39.117221 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-03 12:52:39.191613 | localhost | changed 2025-10-03 12:52:39.196054 | 2025-10-03 12:52:39.196117 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-03 12:52:39.730849 | localhost | changed 2025-10-03 12:52:39.792187 | 2025-10-03 12:52:39.792310 | PLAY [localhost] 2025-10-03 12:52:39.809945 | 2025-10-03 12:52:39.810078 | TASK [Generate bulk log download script] 2025-10-03 12:52:39.858693 | localhost | ok 2025-10-03 12:52:39.877880 | 2025-10-03 12:52:39.877997 | TASK [local-log-download : Check API endpoint is defined] 2025-10-03 12:52:39.981392 | localhost | ok: All assertions passed 2025-10-03 12:52:39.986601 | 2025-10-03 12:52:39.986682 | TASK [local-log-download : Create download script] 2025-10-03 12:52:40.760914 | localhost -> localhost | changed 2025-10-03 12:52:40.797912 | 2025-10-03 12:52:40.798057 | TASK [Register quick-download link] 2025-10-03 12:52:40.817223 | localhost | ok 2025-10-03 12:52:40.833956 | 2025-10-03 12:52:40.834037 | PLAY [logserver.rdoproject.org] 2025-10-03 12:52:40.844836 | 2025-10-03 12:52:40.844921 | TASK [Set zuul-log-path fact] 2025-10-03 12:52:40.863067 | logserver.rdoproject.org | ok 2025-10-03 12:52:40.874054 | 2025-10-03 12:52:40.874123 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 12:52:40.901106 | logserver.rdoproject.org | ok 2025-10-03 12:52:40.906554 | 2025-10-03 12:52:40.906620 | TASK [upload-logs : Create log directories] 2025-10-03 12:52:41.502122 | logserver.rdoproject.org | changed 2025-10-03 12:52:41.507334 | 2025-10-03 12:52:41.507423 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-03 12:52:41.791074 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006902 2025-10-03 12:52:41.798728 | 2025-10-03 12:52:41.798795 | TASK [upload-logs : Upload logs to log server] 2025-10-03 12:52:42.495569 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-03 12:52:42.500079 | 2025-10-03 12:52:42.500146 | LOOP [upload-logs : Compress console log and json output] 2025-10-03 12:52:42.585411 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:52:42.586391 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:52:42.595018 | 2025-10-03 12:52:42.595171 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-03 12:52:42.685180 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:52:42.685539 | 2025-10-03 12:52:42.690096 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 12:52:42.696240 | 2025-10-03 12:52:42.696410 | LOOP [upload-logs : Upload console log and json output]