2025-09-30 08:46:55.008608 | Job console starting... 2025-09-30 08:46:55.020293 | Updating repositories 2025-09-30 08:46:55.053104 | Preparing job workspace 2025-09-30 08:47:00.473844 | Running Ansible setup... 2025-09-30 08:47:04.785453 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 08:47:05.356707 | 2025-09-30 08:47:05.356908 | PLAY [localhost] 2025-09-30 08:47:05.365658 | 2025-09-30 08:47:05.365765 | TASK [Gathering Facts] 2025-09-30 08:47:06.287955 | localhost | ok 2025-09-30 08:47:06.316536 | 2025-09-30 08:47:06.316754 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-30 08:47:06.761157 | localhost -> localhost | changed 2025-09-30 08:47:06.772649 | 2025-09-30 08:47:06.772845 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-30 08:47:07.702625 | localhost -> localhost | changed 2025-09-30 08:47:07.723646 | 2025-09-30 08:47:07.723875 | TASK [Setup log path fact] 2025-09-30 08:47:07.748869 | localhost | ok 2025-09-30 08:47:07.774287 | 2025-09-30 08:47:07.774427 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 08:47:07.807936 | localhost | ok 2025-09-30 08:47:07.825135 | 2025-09-30 08:47:07.825273 | TASK [emit-job-header : Print job information] 2025-09-30 08:47:07.880525 | # Job Information 2025-09-30 08:47:07.880810 | Ansible Version: 2.15.12 2025-09-30 08:47:07.880872 | Job: cifmw-molecule-federation 2025-09-30 08:47:07.880921 | Pipeline: github-check 2025-09-30 08:47:07.880966 | Executor: ze03.softwarefactory-project.io 2025-09-30 08:47:07.881010 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3333 2025-09-30 08:47:07.881060 | Log URL (when completed): https://logserver.rdoproject.org/acc/rdoproject.org/acc992e9ceaf4ed99ae1892dcb02885a/ 2025-09-30 08:47:07.881105 | Event ID: d16f57f0-9dd7-11f0-93f3-c9bd7262a814 2025-09-30 08:47:07.889571 | 2025-09-30 08:47:07.889717 | LOOP [emit-job-header : Print node information] 2025-09-30 08:47:08.007845 | localhost | ok: 2025-09-30 08:47:08.008041 | localhost | # Node Information 2025-09-30 08:47:08.008080 | localhost | Inventory Hostname: controller 2025-09-30 08:47:08.008114 | localhost | Hostname: np0005462171 2025-09-30 08:47:08.008144 | localhost | Username: zuul 2025-09-30 08:47:08.008175 | localhost | Distro: CentOS 9 2025-09-30 08:47:08.008202 | localhost | Provider: vexxhost-nodepool-tripleo 2025-09-30 08:47:08.008228 | localhost | Region: RegionOne 2025-09-30 08:47:08.008254 | localhost | Label: cloud-centos-9-stream-tripleo 2025-09-30 08:47:08.008279 | localhost | Product Name: OpenStack Nova 2025-09-30 08:47:08.008304 | localhost | Interface IP: 38.102.83.130 2025-09-30 08:47:08.046946 | 2025-09-30 08:47:08.047092 | PLAY [all] 2025-09-30 08:47:08.060756 | 2025-09-30 08:47:08.060910 | TASK [Gather network facts] 2025-09-30 08:47:09.591095 | controller | ok 2025-09-30 08:47:09.606469 | 2025-09-30 08:47:09.606583 | TASK [include_role : start-zuul-console] 2025-09-30 08:47:09.624182 | controller | ok 2025-09-30 08:47:09.642025 | 2025-09-30 08:47:09.642126 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-30 08:47:10.084555 | controller | ok 2025-09-30 08:47:10.105081 | 2025-09-30 08:47:10.105232 | TASK [include_role : add-build-sshkey] 2025-09-30 08:47:10.142449 | controller | ok 2025-09-30 08:47:10.168772 | 2025-09-30 08:47:10.168899 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-30 08:47:10.450530 | controller -> localhost | ok 2025-09-30 08:47:10.463652 | 2025-09-30 08:47:10.463851 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-30 08:47:10.502182 | controller | ok 2025-09-30 08:47:10.530691 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-30 08:47:10.538659 | 2025-09-30 08:47:10.538764 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-30 08:47:11.204871 | controller -> localhost | Generating public/private rsa key pair. 2025-09-30 08:47:11.205179 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/acc992e9ceaf4ed99ae1892dcb02885a_id_rsa. 2025-09-30 08:47:11.205241 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/acc992e9ceaf4ed99ae1892dcb02885a_id_rsa.pub. 2025-09-30 08:47:11.205278 | controller -> localhost | The key fingerprint is: 2025-09-30 08:47:11.205308 | controller -> localhost | SHA256:IgNNbBcSFUgGXwv+Sa5xhBC729km9aZAF3seBYDgKwI zuul-build-sshkey 2025-09-30 08:47:11.205335 | controller -> localhost | The key's randomart image is: 2025-09-30 08:47:11.205363 | controller -> localhost | +---[RSA 3072]----+ 2025-09-30 08:47:11.205391 | controller -> localhost | | =*B=*+. | 2025-09-30 08:47:11.205428 | controller -> localhost | | . O==.. . | 2025-09-30 08:47:11.205467 | controller -> localhost | |E +.=.= . | 2025-09-30 08:47:11.205503 | controller -> localhost | |. + = + . | 2025-09-30 08:47:11.205530 | controller -> localhost | |o o = X S | 2025-09-30 08:47:11.205556 | controller -> localhost | |.. + @ = . | 2025-09-30 08:47:11.205581 | controller -> localhost | | . * o + | 2025-09-30 08:47:11.205612 | controller -> localhost | | + o | 2025-09-30 08:47:11.205638 | controller -> localhost | | . | 2025-09-30 08:47:11.205663 | controller -> localhost | +----[SHA256]-----+ 2025-09-30 08:47:11.205939 | controller -> localhost | ok: Runtime: 0:00:00.234707 2025-09-30 08:47:11.216411 | 2025-09-30 08:47:11.216541 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-30 08:47:11.247520 | controller | ok 2025-09-30 08:47:11.271550 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-30 08:47:11.291790 | 2025-09-30 08:47:11.291914 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-30 08:47:11.316332 | controller | skipping: Conditional result was False 2025-09-30 08:47:11.323043 | 2025-09-30 08:47:11.323176 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-30 08:47:11.850414 | controller | changed 2025-09-30 08:47:11.861991 | 2025-09-30 08:47:11.862152 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-30 08:47:12.165097 | controller | ok 2025-09-30 08:47:12.176446 | 2025-09-30 08:47:12.176583 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-30 08:47:13.209287 | controller | changed 2025-09-30 08:47:13.221872 | 2025-09-30 08:47:13.222024 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-30 08:47:14.297311 | controller | changed 2025-09-30 08:47:14.307874 | 2025-09-30 08:47:14.308003 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-30 08:47:14.334379 | controller | skipping: Conditional result was False 2025-09-30 08:47:14.346160 | 2025-09-30 08:47:14.346318 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-30 08:47:14.780859 | controller -> localhost | changed 2025-09-30 08:47:14.790456 | 2025-09-30 08:47:14.790519 | TASK [add-build-sshkey : Add back temp key] 2025-09-30 08:47:15.144138 | controller -> localhost | Identity added: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/acc992e9ceaf4ed99ae1892dcb02885a_id_rsa (zuul-build-sshkey) 2025-09-30 08:47:15.144337 | controller -> localhost | ok: Runtime: 0:00:00.007836 2025-09-30 08:47:15.150185 | 2025-09-30 08:47:15.150314 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-30 08:47:15.573434 | controller | ok 2025-09-30 08:47:15.578226 | 2025-09-30 08:47:15.578286 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-30 08:47:15.612637 | controller | skipping: Conditional result was False 2025-09-30 08:47:15.622309 | 2025-09-30 08:47:15.622367 | TASK [include_role : validate-host] 2025-09-30 08:47:15.650603 | controller | ok 2025-09-30 08:47:15.693232 | 2025-09-30 08:47:15.693354 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-30 08:47:15.731957 | controller | ok 2025-09-30 08:47:15.736355 | 2025-09-30 08:47:15.736413 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-30 08:47:16.024148 | controller -> localhost | ok 2025-09-30 08:47:16.030397 | 2025-09-30 08:47:16.030467 | TASK [validate-host : Collect information about the host] 2025-09-30 08:47:16.897970 | controller | ok 2025-09-30 08:47:16.920804 | 2025-09-30 08:47:16.921002 | TASK [validate-host : Sanitize hostname] 2025-09-30 08:47:16.995638 | controller | ok 2025-09-30 08:47:17.003965 | 2025-09-30 08:47:17.004101 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-30 08:47:17.488677 | controller -> localhost | changed 2025-09-30 08:47:17.501649 | 2025-09-30 08:47:17.501855 | TASK [validate-host : Collect information about zuul worker] 2025-09-30 08:47:17.987168 | controller | ok 2025-09-30 08:47:17.998531 | 2025-09-30 08:47:17.998679 | TASK [validate-host : Write out all zuul information for each host] 2025-09-30 08:47:18.472584 | controller -> localhost | changed 2025-09-30 08:47:18.482719 | 2025-09-30 08:47:18.482806 | TASK [include_role : prepare-workspace-openshift] 2025-09-30 08:47:18.507374 | controller | skipping: Conditional result was False 2025-09-30 08:47:18.514659 | 2025-09-30 08:47:18.514791 | TASK [include_role : remove-zuul-sshkey] 2025-09-30 08:47:18.539236 | controller | skipping: Conditional result was False 2025-09-30 08:47:18.544753 | 2025-09-30 08:47:18.544827 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-09-30 08:47:18.860020 | controller | ok: "logs" 2025-09-30 08:47:18.860448 | controller | ok: All items complete 2025-09-30 08:47:18.860507 | 2025-09-30 08:47:19.131003 | controller | ok: "artifacts" 2025-09-30 08:47:19.395075 | controller | ok: "docs" 2025-09-30 08:47:19.410683 | 2025-09-30 08:47:19.410783 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-09-30 08:47:19.701212 | controller | changed: "logs" 2025-09-30 08:47:19.982325 | controller | changed: "artifacts" 2025-09-30 08:47:20.289175 | controller | changed: "docs" 2025-09-30 08:47:20.338895 | 2025-09-30 08:47:20.338976 | PLAY RECAP 2025-09-30 08:47:20.339027 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 08:47:20.339063 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 08:47:20.339087 | 2025-09-30 08:47:20.445996 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 08:47:20.447582 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-09-30 08:47:21.047224 | 2025-09-30 08:47:21.047360 | PLAY [localhost] 2025-09-30 08:47:21.063977 | 2025-09-30 08:47:21.064107 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-09-30 08:47:21.473610 | localhost | ok 2025-09-30 08:47:21.480296 | 2025-09-30 08:47:21.480393 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-09-30 08:47:22.186963 | localhost | changed 2025-09-30 08:47:22.225122 | 2025-09-30 08:47:22.225306 | PLAY [all] 2025-09-30 08:47:22.246668 | 2025-09-30 08:47:22.246784 | TASK [include_role : prepare-workspace] 2025-09-30 08:47:22.268637 | controller | ok 2025-09-30 08:47:22.290378 | 2025-09-30 08:47:22.290476 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-09-30 08:47:22.714489 | controller | ok 2025-09-30 08:47:22.730679 | 2025-09-30 08:47:22.730856 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-09-30 08:47:24.733108 | controller | Output suppressed because no_log was given 2025-09-30 08:47:24.753590 | 2025-09-30 08:47:24.754101 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-09-30 08:47:25.054836 | controller | changed: "logs" 2025-09-30 08:47:25.303914 | controller | changed: "artifacts" 2025-09-30 08:47:25.536867 | controller | changed: "docs" 2025-09-30 08:47:25.553132 | 2025-09-30 08:47:25.553304 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-09-30 08:47:25.828077 | controller | changed: "logs" 2025-09-30 08:47:25.828368 | controller | changed: All items complete 2025-09-30 08:47:25.828401 | 2025-09-30 08:47:26.119042 | controller | changed: "artifacts" 2025-09-30 08:47:26.380558 | controller | changed: "docs" 2025-09-30 08:47:26.402746 | 2025-09-30 08:47:26.402838 | TASK [Check if worker can sudo] 2025-09-30 08:47:26.935493 | controller | ok: Runtime: 0:00:00.054142 2025-09-30 08:47:26.947216 | 2025-09-30 08:47:26.947338 | TASK [configure-mirrors : Gather needed facts] 2025-09-30 08:47:27.004932 | controller | skipping: Conditional result was False 2025-09-30 08:47:27.014419 | 2025-09-30 08:47:27.014573 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-09-30 08:47:27.158875 | controller | ok 2025-09-30 08:47:27.208084 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-09-30 08:47:27.214417 | 2025-09-30 08:47:27.214495 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-09-30 08:47:27.526987 | controller | ok 2025-09-30 08:47:27.532719 | 2025-09-30 08:47:27.532799 | LOOP [configure-mirrors : Include OS-specific variables] 2025-09-30 08:47:27.629223 | controller | ok: "/var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-09-30 08:47:27.654708 | 2025-09-30 08:47:27.654938 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-09-30 08:47:28.624419 | controller | changed 2025-09-30 08:47:28.630151 | 2025-09-30 08:47:28.630220 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-09-30 08:47:28.704390 | controller | ok: "/var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-09-30 08:47:28.704564 | controller | ok: All items complete 2025-09-30 08:47:28.704590 | 2025-09-30 08:47:28.749911 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-09-30 08:47:28.759588 | 2025-09-30 08:47:28.759709 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-09-30 08:47:29.845453 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-09-30 08:47:30.845141 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-09-30 08:47:30.861655 | 2025-09-30 08:47:30.861804 | TASK [configure-mirrors : Disable deltrarpm] 2025-09-30 08:47:31.344226 | controller | changed: section and option added 2025-09-30 08:47:31.363331 | 2025-09-30 08:47:31.363439 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-09-30 08:47:32.214841 | controller | 29 files removed 2025-09-30 08:47:32.215085 | controller | ok: Item: dnf clean all Runtime: 0:00:00.486292 2025-09-30 08:47:32.215129 | controller | changed: All items complete 2025-09-30 08:47:32.215156 | 2025-09-30 08:47:42.336281 | 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-09-30 08:47:42.337198 | controller | DNF version: 4.14.0 2025-09-30 08:47:42.337309 | controller | cachedir: /var/cache/dnf 2025-09-30 08:47:42.337355 | controller | Making cache files for all metadata files. 2025-09-30 08:47:42.337391 | controller | baseos: has expired and will be refreshed. 2025-09-30 08:47:42.337422 | controller | appstream: has expired and will be refreshed. 2025-09-30 08:47:42.337449 | controller | crb: has expired and will be refreshed. 2025-09-30 08:47:42.337485 | controller | extras-common: has expired and will be refreshed. 2025-09-30 08:47:42.337514 | controller | repo: downloading from remote: baseos 2025-09-30 08:47:42.337541 | controller | CentOS Stream 9 - BaseOS 73 MB/s | 8.8 MB 00:00 2025-09-30 08:47:42.337568 | controller | baseos: using metadata from Mon 22 Sep 2025 10:29:43 AM EDT. 2025-09-30 08:47:42.337598 | controller | repo: downloading from remote: appstream 2025-09-30 08:47:42.337629 | controller | CentOS Stream 9 - AppStream 88 MB/s | 25 MB 00:00 2025-09-30 08:47:42.337660 | controller | appstream: using metadata from Mon 22 Sep 2025 10:33:24 AM EDT. 2025-09-30 08:47:42.337688 | controller | repo: downloading from remote: crb 2025-09-30 08:47:42.337715 | controller | CentOS Stream 9 - CRB 88 MB/s | 7.1 MB 00:00 2025-09-30 08:47:42.337773 | controller | crb: using metadata from Mon 22 Sep 2025 10:37:51 AM EDT. 2025-09-30 08:47:42.337805 | controller | repo: downloading from remote: extras-common 2025-09-30 08:47:42.337837 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-09-30 08:47:42.337869 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-09-30 08:47:42.337899 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-09-30 08:47:42.337928 | controller | Completion plugin: Generating completion cache... 2025-09-30 08:47:42.337959 | controller | Metadata cache created. 2025-09-30 08:47:42.338006 | controller | ok: Item: dnf makecache -v Runtime: 0:00:09.847433 2025-09-30 08:47:42.357671 | 2025-09-30 08:47:42.357785 | PLAY RECAP 2025-09-30 08:47:42.357828 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-09-30 08:47:42.357854 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 08:47:42.357871 | 2025-09-30 08:47:42.450229 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-09-30 08:47:42.451155 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-09-30 08:47:43.057507 | 2025-09-30 08:47:43.057608 | PLAY [all] 2025-09-30 08:47:43.077504 | 2025-09-30 08:47:43.077583 | TASK [Install binary dependencies] 2025-09-30 08:47:43.162974 | controller | ok 2025-09-30 08:47:43.205575 | 2025-09-30 08:47:43.205742 | TASK [bindep : Include find tasks] 2025-09-30 08:47:43.241006 | controller | ok 2025-09-30 08:47:43.255610 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-09-30 08:47:43.263548 | 2025-09-30 08:47:43.263633 | TASK [bindep : Look for bindep.txt] 2025-09-30 08:47:43.745781 | controller | ok 2025-09-30 08:47:43.752139 | 2025-09-30 08:47:43.752263 | TASK [bindep : Define bindep_file fact] 2025-09-30 08:47:43.782492 | controller | ok 2025-09-30 08:47:43.787995 | 2025-09-30 08:47:43.788089 | TASK [bindep : Look for other-requirements.txt] 2025-09-30 08:47:43.802448 | controller | skipping: Conditional result was False 2025-09-30 08:47:43.809720 | 2025-09-30 08:47:43.809880 | TASK [bindep : Define bindep_file fact] 2025-09-30 08:47:43.836584 | controller | skipping: Conditional result was False 2025-09-30 08:47:43.842282 | 2025-09-30 08:47:43.842378 | TASK [bindep : Look for bindep fallback file] 2025-09-30 08:47:43.866384 | controller | skipping: Conditional result was False 2025-09-30 08:47:43.872100 | 2025-09-30 08:47:43.872199 | TASK [bindep : Define bindep_file fact] 2025-09-30 08:47:43.895356 | controller | skipping: Conditional result was False 2025-09-30 08:47:43.902523 | 2025-09-30 08:47:43.902591 | TASK [bindep : Include bindep tasks] 2025-09-30 08:47:43.931976 | controller | ok 2025-09-30 08:47:43.939151 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-09-30 08:47:43.947093 | 2025-09-30 08:47:43.947154 | TASK [bindep : Look for bindep command] 2025-09-30 08:47:43.971055 | controller | skipping: Conditional result was False 2025-09-30 08:47:43.977817 | 2025-09-30 08:47:43.977883 | TASK [bindep : Check for system bindep] 2025-09-30 08:47:44.509563 | controller | ok: Runtime: 0:00:00.009271 2025-09-30 08:47:44.524457 | 2025-09-30 08:47:44.524621 | TASK [bindep : Define bindep_command fact] 2025-09-30 08:47:44.564988 | controller | skipping: Conditional result was False 2025-09-30 08:47:44.577643 | 2025-09-30 08:47:44.577837 | TASK [bindep : Include install tasks] 2025-09-30 08:47:44.628043 | controller | ok 2025-09-30 08:47:44.642063 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-09-30 08:47:44.655595 | 2025-09-30 08:47:44.655748 | TASK [bindep : Create temp dir for bindep] 2025-09-30 08:47:45.076245 | controller | changed 2025-09-30 08:47:45.081559 | 2025-09-30 08:47:45.081628 | TASK [Ensure we have pip dependencies] 2025-09-30 08:47:45.116255 | controller | ok 2025-09-30 08:47:45.143604 | 2025-09-30 08:47:45.143794 | TASK [ensure-pip : Check if pip is installed] 2025-09-30 04:47:45.479675 | controller | /usr/bin/pip3 2025-09-30 04:47:45.522922 | controller | /usr/bin/python3: No module named wheel 2025-09-30 08:47:45.676960 | controller | ok: Runtime: 0:00:00.059405 2025-09-30 08:47:45.690241 | 2025-09-30 08:47:45.690505 | LOOP [ensure-pip : Install pip from packages] 2025-09-30 08:47:45.726288 | controller | ok: "/var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-09-30 08:47:45.746756 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-09-30 08:47:45.769435 | 2025-09-30 08:47:45.769546 | TASK [ensure-pip : Install Python 3 pip] 2025-09-30 08:47:48.410122 | controller | changed 2025-09-30 08:47:48.417333 | 2025-09-30 08:47:48.417489 | TASK [ensure-pip : Check for EPEL repository] 2025-09-30 08:47:48.475534 | controller | skipping: Conditional result was False 2025-09-30 08:47:48.482141 | 2025-09-30 08:47:48.482210 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-09-30 08:47:48.537577 | controller | skipping: Conditional result was False 2025-09-30 08:47:48.543975 | 2025-09-30 08:47:48.544038 | TASK [ensure-pip : Install Python 2 pip] 2025-09-30 08:47:48.578325 | controller | skipping: Conditional result was False 2025-09-30 08:47:48.584713 | 2025-09-30 08:47:48.584811 | TASK [ensure-pip : Ensure setuptools] 2025-09-30 08:47:48.598760 | controller | skipping: Conditional result was False 2025-09-30 08:47:48.605129 | 2025-09-30 08:47:48.605193 | TASK [ensure-pip : Check for ensurepip module] 2025-09-30 08:47:49.137103 | controller | skipping: Conditional result was False 2025-09-30 08:47:49.143792 | 2025-09-30 08:47:49.143862 | TASK [ensure-pip : Ensure python3-venv] 2025-09-30 08:47:49.168024 | controller | skipping: Conditional result was False 2025-09-30 08:47:49.174002 | 2025-09-30 08:47:49.174125 | TASK [ensure-pip : Install pip from source] 2025-09-30 08:47:49.197379 | controller | skipping: Conditional result was False 2025-09-30 08:47:49.203164 | 2025-09-30 08:47:49.203228 | TASK [ensure-pip : Probe for venv python full path] 2025-09-30 04:47:49.543981 | controller | /usr/bin/python3 2025-09-30 08:47:49.733267 | controller | ok: Runtime: 0:00:00.008508 2025-09-30 08:47:49.747699 | 2025-09-30 08:47:49.747915 | TASK [ensure-pip : Set host default] 2025-09-30 08:47:49.797932 | controller | ok 2025-09-30 08:47:49.810403 | 2025-09-30 08:47:49.810533 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-09-30 08:47:49.863956 | controller | ok 2025-09-30 08:47:49.890371 | 2025-09-30 08:47:49.890536 | TASK [bindep : Install bindep into temporary venv] 2025-09-30 08:47:54.303148 | controller | changed 2025-09-30 08:47:54.315125 | 2025-09-30 08:47:54.315277 | TASK [bindep : Define bindep_command] 2025-09-30 08:47:54.362914 | controller | ok 2025-09-30 08:47:54.374477 | 2025-09-30 08:47:54.374613 | LOOP [bindep : Include package tasks] 2025-09-30 08:47:54.451979 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-09-30 08:47:54.452325 | controller | ok: All items complete 2025-09-30 08:47:54.452396 | 2025-09-30 08:47:54.485652 | controller | included: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-09-30 08:47:54.517235 | 2025-09-30 08:47:54.517384 | TASK [bindep : Define bindep_run fact] 2025-09-30 08:47:54.559230 | controller | ok 2025-09-30 08:47:54.566153 | 2025-09-30 08:47:54.566235 | TASK [bindep : Get list of packages to install from bindep] 2025-09-30 04:47:56.168628 | controller | podman 2025-09-30 04:47:56.225901 | controller | python3-jmespath 2025-09-30 04:47:56.226012 | controller | python3-libvirt 2025-09-30 04:47:56.226029 | controller | python3-lxml 2025-09-30 04:47:56.226043 | controller | python3-netaddr 2025-09-30 08:47:56.608887 | controller | ok: Runtime: 0:00:01.317545 2025-09-30 08:47:56.621009 | 2025-09-30 08:47:56.621138 | TASK [bindep : Install distro packages from bindep] 2025-09-30 08:48:59.365705 | controller | changed 2025-09-30 08:48:59.378704 | 2025-09-30 08:48:59.378872 | TASK [bindep : Check that packages are installed] 2025-09-30 08:49:01.432666 | controller | ok: Runtime: 0:00:01.505985 2025-09-30 08:49:01.446200 | 2025-09-30 08:49:01.446357 | TASK [bindep : Fail if we cannot install all packages] 2025-09-30 08:49:01.485776 | controller | skipping: Conditional result was False 2025-09-30 08:49:01.512613 | 2025-09-30 08:49:01.512835 | TASK [Run test-setup role] 2025-09-30 08:49:01.544210 | controller | ok 2025-09-30 08:49:01.577570 | 2025-09-30 08:49:01.577679 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-09-30 08:49:01.861872 | controller | ok 2025-09-30 08:49:01.874142 | 2025-09-30 08:49:01.874294 | TASK [test-setup : Run tools/test-setup.sh] 2025-09-30 08:49:02.427348 | controller | skipping: Conditional result was False 2025-09-30 08:49:02.470035 | 2025-09-30 08:49:02.470139 | TASK [bindep : Remove bindep temp dir] 2025-09-30 08:49:02.821436 | controller | ok 2025-09-30 08:49:02.847159 | 2025-09-30 08:49:02.847267 | PLAY RECAP 2025-09-30 08:49:02.847347 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-09-30 08:49:02.847391 | 2025-09-30 08:49:02.956721 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-09-30 08:49:02.957557 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-09-30 08:49:03.615307 | 2025-09-30 08:49:03.615422 | PLAY [all] 2025-09-30 08:49:03.636076 | 2025-09-30 08:49:03.636180 | TASK [Abort when test_command variable is undefined] 2025-09-30 08:49:03.671525 | controller | skipping: Conditional result was False 2025-09-30 08:49:03.676978 | 2025-09-30 08:49:03.677052 | TASK [Convert test_command to list] 2025-09-30 08:49:03.710867 | controller | skipping: Conditional result was False 2025-09-30 08:49:03.717388 | 2025-09-30 08:49:03.717465 | TASK [Use test_command list] 2025-09-30 08:49:03.766813 | controller | ok 2025-09-30 08:49:03.772163 | 2025-09-30 08:49:03.772223 | LOOP [Run test_command] 2025-09-30 08:49:04.221632 | controller | no check to run 2025-09-30 08:49:04.221822 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008616 2025-09-30 08:49:04.263155 | 2025-09-30 08:49:04.263282 | PLAY RECAP 2025-09-30 08:49:04.263335 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 08:49:04.263365 | 2025-09-30 08:49:04.371423 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-09-30 08:49:04.372274 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-30 08:49:04.943037 | 2025-09-30 08:49:04.943153 | PLAY [all] 2025-09-30 08:49:04.963792 | 2025-09-30 08:49:04.963903 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-09-30 08:49:05.443099 | controller | changed: non-zero return code 2025-09-30 08:49:05.456261 | 2025-09-30 08:49:05.456442 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-09-30 08:49:05.483892 | controller | skipping: Conditional result was False 2025-09-30 08:49:05.497944 | 2025-09-30 08:49:05.498136 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-09-30 08:49:05.546082 | 2025-09-30 08:49:05.546451 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-09-30 08:49:05.590184 | 2025-09-30 08:49:05.590598 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-09-30 08:49:05.620269 | controller | skipping: Conditional result was False 2025-09-30 08:49:05.640459 | 2025-09-30 08:49:05.640661 | LOOP [fetch-subunit-output : Generate subunit file] 2025-09-30 08:49:05.682649 | 2025-09-30 08:49:05.682968 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-09-30 08:49:05.710470 | controller | skipping: Conditional result was False 2025-09-30 08:49:05.716451 | 2025-09-30 08:49:05.716541 | TASK [fetch-subunit-output : Remove the temporary file] 2025-09-30 08:49:05.740954 | controller | skipping: Conditional result was False 2025-09-30 08:49:05.747362 | 2025-09-30 08:49:05.747462 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-09-30 08:49:05.771572 | controller | skipping: Conditional result was False 2025-09-30 08:49:05.811910 | 2025-09-30 08:49:05.812049 | PLAY RECAP 2025-09-30 08:49:05.812125 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-09-30 08:49:05.812163 | 2025-09-30 08:49:05.907806 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-30 08:49:05.908578 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 08:49:06.513572 | 2025-09-30 08:49:06.513710 | PLAY [all] 2025-09-30 08:49:06.532395 | 2025-09-30 08:49:06.532478 | TASK [include_role : fetch-output] 2025-09-30 08:49:06.561148 | controller | ok 2025-09-30 08:49:06.579352 | 2025-09-30 08:49:06.579436 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 08:49:06.654553 | controller | skipping: Conditional result was False 2025-09-30 08:49:06.666611 | 2025-09-30 08:49:06.666802 | TASK [fetch-output : Set log path for single node] 2025-09-30 08:49:06.706974 | controller | ok 2025-09-30 08:49:06.719132 | 2025-09-30 08:49:06.719329 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 08:49:07.152148 | controller -> localhost | ok: "/var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/logs" 2025-09-30 08:49:07.391720 | controller -> localhost | changed: "/var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/artifacts" 2025-09-30 08:49:07.607647 | controller -> localhost | changed: "/var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/docs" 2025-09-30 08:49:07.624241 | 2025-09-30 08:49:07.624332 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 08:49:08.348981 | controller | changed: .d..t...... ./ 2025-09-30 08:49:08.349316 | controller | changed: All items complete 2025-09-30 08:49:08.349376 | 2025-09-30 08:49:08.933287 | controller | changed: .d..t...... ./ 2025-09-30 08:49:09.463804 | controller | changed: .d..t...... ./ 2025-09-30 08:49:09.488924 | 2025-09-30 08:49:09.489050 | TASK [include_role : fetch-output-openshift] 2025-09-30 08:49:09.513938 | controller | skipping: Conditional result was False 2025-09-30 08:49:09.521294 | 2025-09-30 08:49:09.521403 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-09-30 08:49:09.922804 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008135 2025-09-30 08:49:10.209702 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.010139 2025-09-30 08:49:10.251016 | 2025-09-30 08:49:10.251238 | PLAY [all] 2025-09-30 08:49:10.274011 | 2025-09-30 08:49:10.274137 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-30 08:49:10.775673 | controller | changed 2025-09-30 08:49:10.823584 | 2025-09-30 08:49:10.823697 | PLAY RECAP 2025-09-30 08:49:10.823781 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 08:49:10.823815 | 2025-09-30 08:49:10.943656 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 08:49:10.945429 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-09-30 08:49:11.571073 | 2025-09-30 08:49:11.571193 | PLAY [localhost] 2025-09-30 08:49:11.589985 | 2025-09-30 08:49:11.590107 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-30 08:49:11.947506 | localhost | changed 2025-09-30 08:49:11.953938 | 2025-09-30 08:49:11.954048 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-30 08:49:11.997910 | localhost | ok 2025-09-30 08:49:12.010686 | 2025-09-30 08:49:12.010853 | TASK [add-fileserver : Create SSH private key tempfile] 2025-09-30 08:49:12.449718 | localhost | changed 2025-09-30 08:49:12.454567 | 2025-09-30 08:49:12.454637 | TASK [add-fileserver : Create SSH private key from secret] 2025-09-30 08:49:13.156050 | localhost | changed 2025-09-30 08:49:13.162135 | 2025-09-30 08:49:13.162239 | TASK [add-fileserver : Add fileserver ssh key] 2025-09-30 08:49:13.601702 | localhost | Identity added: /var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/tmp/ansible.3_6rdl5y (/var/lib/zuul/builds/acc992e9ceaf4ed99ae1892dcb02885a/work/tmp/ansible.3_6rdl5y) 2025-09-30 08:49:13.602041 | localhost | ok: Runtime: 0:00:00.014714 2025-09-30 08:49:13.608322 | 2025-09-30 08:49:13.608396 | TASK [add-fileserver : Remove SSH private key from disk] 2025-09-30 08:49:13.942602 | localhost | ok: Runtime: 0:00:00.009421 2025-09-30 08:49:13.948083 | 2025-09-30 08:49:13.948148 | TASK [add-fileserver : Add fileserver to inventory] 2025-09-30 08:49:13.998050 | localhost | changed 2025-09-30 08:49:14.002333 | 2025-09-30 08:49:14.002496 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-09-30 08:49:14.463062 | localhost | changed 2025-09-30 08:49:14.492762 | 2025-09-30 08:49:14.492917 | PLAY [localhost] 2025-09-30 08:49:14.510219 | 2025-09-30 08:49:14.510333 | TASK [Generate bulk log download script] 2025-09-30 08:49:14.528519 | localhost | ok 2025-09-30 08:49:14.540785 | 2025-09-30 08:49:14.540865 | TASK [local-log-download : Check API endpoint is defined] 2025-09-30 08:49:14.568680 | localhost | ok: All assertions passed 2025-09-30 08:49:14.573330 | 2025-09-30 08:49:14.573474 | TASK [local-log-download : Create download script] 2025-09-30 08:49:15.014849 | localhost -> localhost | changed 2025-09-30 08:49:15.023870 | 2025-09-30 08:49:15.023989 | TASK [Register quick-download link] 2025-09-30 08:49:15.060256 | localhost | ok 2025-09-30 08:49:15.122216 | 2025-09-30 08:49:15.122332 | PLAY [logserver.rdoproject.org] 2025-09-30 08:49:15.137268 | 2025-09-30 08:49:15.137360 | TASK [Set zuul-log-path fact] 2025-09-30 08:49:15.156001 | logserver.rdoproject.org | ok 2025-09-30 08:49:15.169707 | 2025-09-30 08:49:15.169863 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 08:49:15.198457 | logserver.rdoproject.org | ok 2025-09-30 08:49:15.206846 | 2025-09-30 08:49:15.206936 | TASK [upload-logs : Create log directories] 2025-09-30 08:49:15.946702 | logserver.rdoproject.org | changed 2025-09-30 08:49:15.955628 | 2025-09-30 08:49:15.955861 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-30 08:49:16.257890 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.010741 2025-09-30 08:49:16.268774 | 2025-09-30 08:49:16.268961 | TASK [upload-logs : Upload logs to log server] 2025-09-30 08:49:17.019649 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-09-30 08:49:17.026193 | 2025-09-30 08:49:17.026326 | LOOP [upload-logs : Compress console log and json output] 2025-09-30 08:49:17.067076 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 08:49:17.075408 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 08:49:17.090914 | 2025-09-30 08:49:17.091097 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-30 08:49:17.155964 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 08:49:17.156226 | 2025-09-30 08:49:17.156714 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 08:49:17.165749 | 2025-09-30 08:49:17.165891 | LOOP [upload-logs : Upload console log and json output]