2025-10-07 15:37:01.285828 | Job console starting... 2025-10-07 15:37:01.299880 | Updating repositories 2025-10-07 15:37:01.331672 | Preparing job workspace 2025-10-07 15:37:04.928078 | Running Ansible setup... 2025-10-07 15:37:08.800316 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 15:37:09.393407 | 2025-10-07 15:37:09.393546 | PLAY [localhost] 2025-10-07 15:37:09.402172 | 2025-10-07 15:37:09.402243 | TASK [Gathering Facts] 2025-10-07 15:37:10.428434 | localhost | ok 2025-10-07 15:37:10.443003 | 2025-10-07 15:37:10.443085 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-07 15:37:11.037484 | localhost -> localhost | changed 2025-10-07 15:37:11.044154 | 2025-10-07 15:37:11.044223 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-07 15:37:12.044841 | localhost -> localhost | changed 2025-10-07 15:37:12.057974 | 2025-10-07 15:37:12.058045 | TASK [Setup log path fact] 2025-10-07 15:37:12.076007 | localhost | ok 2025-10-07 15:37:12.095230 | 2025-10-07 15:37:12.095371 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 15:37:12.123257 | localhost | ok 2025-10-07 15:37:12.131051 | 2025-10-07 15:37:12.131117 | TASK [emit-job-header : Print job information] 2025-10-07 15:37:12.158010 | # Job Information 2025-10-07 15:37:12.158183 | Ansible Version: 2.15.12 2025-10-07 15:37:12.158212 | Job: cifmw-molecule-ci_dcn_site 2025-10-07 15:37:12.158232 | Pipeline: github-check 2025-10-07 15:37:12.158250 | Executor: ze02.softwarefactory-project.io 2025-10-07 15:37:12.158267 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368 2025-10-07 15:37:12.158285 | Log URL (when completed): https://logserver.rdoproject.org/3ac/rdoproject.org/3ac75f3e8bd240158cd4e584f445b035/ 2025-10-07 15:37:12.158303 | Event ID: 3bf07620-a393-11f0-9221-eb052759ad8c 2025-10-07 15:37:12.161816 | 2025-10-07 15:37:12.161874 | LOOP [emit-job-header : Print node information] 2025-10-07 15:37:12.269206 | localhost | ok: 2025-10-07 15:37:12.269403 | localhost | # Node Information 2025-10-07 15:37:12.269431 | localhost | Inventory Hostname: controller 2025-10-07 15:37:12.269453 | localhost | Hostname: np0005474506 2025-10-07 15:37:12.269472 | localhost | Username: zuul 2025-10-07 15:37:12.269492 | localhost | Distro: CentOS 9 2025-10-07 15:37:12.269509 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-07 15:37:12.269526 | localhost | Region: RegionOne 2025-10-07 15:37:12.269542 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-07 15:37:12.269558 | localhost | Product Name: OpenStack Nova 2025-10-07 15:37:12.269574 | localhost | Interface IP: 38.102.83.199 2025-10-07 15:37:12.298710 | 2025-10-07 15:37:12.298829 | PLAY [all] 2025-10-07 15:37:12.305423 | 2025-10-07 15:37:12.305488 | TASK [Gather network facts] 2025-10-07 15:37:12.795762 | controller | ok 2025-10-07 15:37:12.818099 | 2025-10-07 15:37:12.818304 | TASK [include_role : start-zuul-console] 2025-10-07 15:37:12.838853 | controller | ok 2025-10-07 15:37:12.852302 | 2025-10-07 15:37:12.852380 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-07 15:37:13.228784 | controller | ok 2025-10-07 15:37:13.237966 | 2025-10-07 15:37:13.238029 | TASK [include_role : add-build-sshkey] 2025-10-07 15:37:13.270247 | controller | ok 2025-10-07 15:37:13.296789 | 2025-10-07 15:37:13.296884 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-07 15:37:13.636219 | controller -> localhost | ok 2025-10-07 15:37:13.663370 | 2025-10-07 15:37:13.665420 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-07 15:37:13.707650 | controller | ok 2025-10-07 15:37:13.731152 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-07 15:37:13.752064 | 2025-10-07 15:37:13.752217 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-07 15:37:14.649326 | controller -> localhost | Generating public/private rsa key pair. 2025-10-07 15:37:14.649510 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/3ac75f3e8bd240158cd4e584f445b035_id_rsa. 2025-10-07 15:37:14.649541 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/3ac75f3e8bd240158cd4e584f445b035_id_rsa.pub. 2025-10-07 15:37:14.649563 | controller -> localhost | The key fingerprint is: 2025-10-07 15:37:14.649582 | controller -> localhost | SHA256:efDUHYlMhEVZYH9wjJa7JEc8yRj6RsigJGRmnHAOqsQ zuul-build-sshkey 2025-10-07 15:37:14.649601 | controller -> localhost | The key's randomart image is: 2025-10-07 15:37:14.649619 | controller -> localhost | +---[RSA 3072]----+ 2025-10-07 15:37:14.649636 | controller -> localhost | | o+B.. . BOX+*.| 2025-10-07 15:37:14.649654 | controller -> localhost | |.. Boo . o.==o@+.| 2025-10-07 15:37:14.649710 | controller -> localhost | |.E . . . = oooo.| 2025-10-07 15:37:14.649731 | controller -> localhost | |o = o. +. | 2025-10-07 15:37:14.649748 | controller -> localhost | |. S o o+ . | 2025-10-07 15:37:14.649766 | controller -> localhost | | . . . | 2025-10-07 15:37:14.649783 | controller -> localhost | | | 2025-10-07 15:37:14.649802 | controller -> localhost | | | 2025-10-07 15:37:14.649820 | controller -> localhost | | | 2025-10-07 15:37:14.649837 | controller -> localhost | +----[SHA256]-----+ 2025-10-07 15:37:14.649878 | controller -> localhost | ok: Runtime: 0:00:00.458478 2025-10-07 15:37:14.656255 | 2025-10-07 15:37:14.656435 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-07 15:37:14.685335 | controller | ok 2025-10-07 15:37:14.695862 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-07 15:37:14.708595 | 2025-10-07 15:37:14.708708 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-07 15:37:14.732718 | controller | skipping: Conditional result was False 2025-10-07 15:37:14.740341 | 2025-10-07 15:37:14.740416 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-07 15:37:15.278625 | controller | changed 2025-10-07 15:37:15.285869 | 2025-10-07 15:37:15.285936 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-07 15:37:15.623542 | controller | ok 2025-10-07 15:37:15.631224 | 2025-10-07 15:37:15.631314 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-07 15:37:16.550964 | controller | changed 2025-10-07 15:37:16.555885 | 2025-10-07 15:37:16.555946 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-07 15:37:17.395420 | controller | changed 2025-10-07 15:37:17.400490 | 2025-10-07 15:37:17.400548 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-07 15:37:17.425200 | controller | skipping: Conditional result was False 2025-10-07 15:37:17.431366 | 2025-10-07 15:37:17.431430 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-07 15:37:17.794574 | controller -> localhost | changed 2025-10-07 15:37:17.804816 | 2025-10-07 15:37:17.804884 | TASK [add-build-sshkey : Add back temp key] 2025-10-07 15:37:18.093038 | controller -> localhost | Identity added: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/3ac75f3e8bd240158cd4e584f445b035_id_rsa (zuul-build-sshkey) 2025-10-07 15:37:18.093239 | controller -> localhost | ok: Runtime: 0:00:00.008514 2025-10-07 15:37:18.099101 | 2025-10-07 15:37:18.099161 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-07 15:37:18.486823 | controller | ok 2025-10-07 15:37:18.497488 | 2025-10-07 15:37:18.497617 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-07 15:37:18.535864 | controller | skipping: Conditional result was False 2025-10-07 15:37:18.549296 | 2025-10-07 15:37:18.549382 | TASK [include_role : validate-host] 2025-10-07 15:37:18.568980 | controller | ok 2025-10-07 15:37:18.611379 | 2025-10-07 15:37:18.611509 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-07 15:37:18.660272 | controller | ok 2025-10-07 15:37:18.665571 | 2025-10-07 15:37:18.665633 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-07 15:37:18.973186 | controller -> localhost | ok 2025-10-07 15:37:18.980968 | 2025-10-07 15:37:18.981034 | TASK [validate-host : Collect information about the host] 2025-10-07 15:37:19.806011 | controller | ok 2025-10-07 15:37:19.814360 | 2025-10-07 15:37:19.814419 | TASK [validate-host : Sanitize hostname] 2025-10-07 15:37:19.879402 | controller | ok 2025-10-07 15:37:19.890727 | 2025-10-07 15:37:19.890866 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-07 15:37:20.360903 | controller -> localhost | changed 2025-10-07 15:37:20.367349 | 2025-10-07 15:37:20.367413 | TASK [validate-host : Collect information about zuul worker] 2025-10-07 15:37:20.762859 | controller | ok 2025-10-07 15:37:20.768217 | 2025-10-07 15:37:20.768280 | TASK [validate-host : Write out all zuul information for each host] 2025-10-07 15:37:21.221027 | controller -> localhost | changed 2025-10-07 15:37:21.231125 | 2025-10-07 15:37:21.231186 | TASK [include_role : prepare-workspace-openshift] 2025-10-07 15:37:21.244995 | controller | skipping: Conditional result was False 2025-10-07 15:37:21.249819 | 2025-10-07 15:37:21.249878 | TASK [include_role : remove-zuul-sshkey] 2025-10-07 15:37:21.263418 | controller | skipping: Conditional result was False 2025-10-07 15:37:21.269116 | 2025-10-07 15:37:21.269177 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 15:37:21.518555 | controller | ok: "logs" 2025-10-07 15:37:21.519081 | controller | ok: All items complete 2025-10-07 15:37:21.519143 | 2025-10-07 15:37:21.763156 | controller | ok: "artifacts" 2025-10-07 15:37:21.985592 | controller | ok: "docs" 2025-10-07 15:37:22.002397 | 2025-10-07 15:37:22.002576 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 15:37:22.286341 | controller | changed: "logs" 2025-10-07 15:37:22.514511 | controller | changed: "artifacts" 2025-10-07 15:37:22.833756 | controller | changed: "docs" 2025-10-07 15:37:22.881560 | 2025-10-07 15:37:22.881650 | PLAY RECAP 2025-10-07 15:37:22.881743 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-07 15:37:22.881782 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 15:37:22.881808 | 2025-10-07 15:37:22.985810 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-07 15:37:22.986596 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 15:37:23.608591 | 2025-10-07 15:37:23.608713 | PLAY [localhost] 2025-10-07 15:37:23.625029 | 2025-10-07 15:37:23.625224 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-07 15:37:24.059192 | localhost | ok 2025-10-07 15:37:24.064895 | 2025-10-07 15:37:24.065030 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-07 15:37:24.779053 | localhost | changed 2025-10-07 15:37:24.803960 | 2025-10-07 15:37:24.804099 | PLAY [all] 2025-10-07 15:37:24.819737 | 2025-10-07 15:37:24.819798 | TASK [include_role : prepare-workspace] 2025-10-07 15:37:24.840178 | controller | ok 2025-10-07 15:37:24.854620 | 2025-10-07 15:37:24.854855 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-07 15:37:25.248647 | controller | ok 2025-10-07 15:37:25.263282 | 2025-10-07 15:37:25.263442 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-07 15:37:26.938423 | controller | Output suppressed because no_log was given 2025-10-07 15:37:26.952503 | 2025-10-07 15:37:26.952593 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-07 15:37:27.244117 | controller | changed: "logs" 2025-10-07 15:37:27.475822 | controller | changed: "artifacts" 2025-10-07 15:37:27.744606 | controller | changed: "docs" 2025-10-07 15:37:27.754655 | 2025-10-07 15:37:27.754864 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-07 15:37:28.025235 | controller | changed: "logs" 2025-10-07 15:37:28.025468 | controller | changed: All items complete 2025-10-07 15:37:28.025496 | 2025-10-07 15:37:28.247867 | controller | changed: "artifacts" 2025-10-07 15:37:28.463876 | controller | changed: "docs" 2025-10-07 15:37:28.491154 | 2025-10-07 15:37:28.491305 | TASK [Check if worker can sudo] 2025-10-07 15:37:29.032008 | controller | ok: Runtime: 0:00:00.047306 2025-10-07 15:37:29.038528 | 2025-10-07 15:37:29.038704 | TASK [configure-mirrors : Gather needed facts] 2025-10-07 15:37:29.083222 | controller | skipping: Conditional result was False 2025-10-07 15:37:29.089530 | 2025-10-07 15:37:29.089604 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-07 15:37:29.162144 | controller | ok 2025-10-07 15:37:29.170424 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-07 15:37:29.176094 | 2025-10-07 15:37:29.176154 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-07 15:37:29.475598 | controller | ok 2025-10-07 15:37:29.506986 | 2025-10-07 15:37:29.507095 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-07 15:37:29.560354 | controller | ok: "/var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-07 15:37:29.567500 | 2025-10-07 15:37:29.567562 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-07 15:37:30.379410 | controller | changed 2025-10-07 15:37:30.388087 | 2025-10-07 15:37:30.388174 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-07 15:37:30.456727 | controller | ok: "/var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-07 15:37:30.456929 | controller | ok: All items complete 2025-10-07 15:37:30.456954 | 2025-10-07 15:37:30.512433 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-07 15:37:30.519253 | 2025-10-07 15:37:30.519319 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-07 15:37:31.467697 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-07 15:37:32.266350 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-07 15:37:32.282721 | 2025-10-07 15:37:32.282837 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-07 15:37:32.740529 | controller | changed: section and option added 2025-10-07 15:37:32.767033 | 2025-10-07 15:37:32.767120 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-07 15:37:34.072834 | controller | 29 files removed 2025-10-07 15:37:34.073251 | controller | ok: Item: dnf clean all Runtime: 0:00:00.920584 2025-10-07 15:37:34.073337 | controller | changed: All items complete 2025-10-07 15:37:34.073383 | 2025-10-07 15:37:46.264079 | 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:37:46.264242 | controller | DNF version: 4.14.0 2025-10-07 15:37:46.264297 | controller | cachedir: /var/cache/dnf 2025-10-07 15:37:46.264340 | controller | Making cache files for all metadata files. 2025-10-07 15:37:46.264381 | controller | baseos: has expired and will be refreshed. 2025-10-07 15:37:46.264419 | controller | appstream: has expired and will be refreshed. 2025-10-07 15:37:46.264457 | controller | crb: has expired and will be refreshed. 2025-10-07 15:37:46.264513 | controller | extras-common: has expired and will be refreshed. 2025-10-07 15:37:46.264552 | controller | repo: downloading from remote: baseos 2025-10-07 15:37:46.264588 | controller | CentOS Stream 9 - BaseOS 18 MB/s | 8.8 MB 00:00 2025-10-07 15:37:46.264625 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-07 15:37:46.264661 | controller | repo: downloading from remote: appstream 2025-10-07 15:37:46.264766 | controller | CentOS Stream 9 - AppStream 29 MB/s | 25 MB 00:00 2025-10-07 15:37:46.264805 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-07 15:37:46.264841 | controller | repo: downloading from remote: crb 2025-10-07 15:37:46.264876 | controller | CentOS Stream 9 - CRB 76 MB/s | 7.1 MB 00:00 2025-10-07 15:37:46.264913 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-07 15:37:46.264948 | controller | repo: downloading from remote: extras-common 2025-10-07 15:37:46.264984 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-07 15:37:46.265020 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-07 15:37:46.265056 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-07 15:37:46.265093 | controller | Completion plugin: Generating completion cache... 2025-10-07 15:37:46.265129 | controller | Metadata cache created. 2025-10-07 15:37:46.265184 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.893745 2025-10-07 15:37:46.291940 | 2025-10-07 15:37:46.292100 | PLAY RECAP 2025-10-07 15:37:46.292186 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-07 15:37:46.292241 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-07 15:37:46.292279 | 2025-10-07 15:37:46.437119 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-07 15:37:46.437975 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 15:37:47.047434 | 2025-10-07 15:37:47.047537 | PLAY [all] 2025-10-07 15:37:47.068033 | 2025-10-07 15:37:47.068110 | TASK [Install binary dependencies] 2025-10-07 15:37:47.127534 | controller | ok 2025-10-07 15:37:47.145925 | 2025-10-07 15:37:47.146001 | TASK [bindep : Include find tasks] 2025-10-07 15:37:47.174547 | controller | ok 2025-10-07 15:37:47.181752 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-07 15:37:47.187706 | 2025-10-07 15:37:47.187767 | TASK [bindep : Look for bindep.txt] 2025-10-07 15:37:47.610020 | controller | ok 2025-10-07 15:37:47.616503 | 2025-10-07 15:37:47.616572 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:37:47.646038 | controller | ok 2025-10-07 15:37:47.651074 | 2025-10-07 15:37:47.651152 | TASK [bindep : Look for other-requirements.txt] 2025-10-07 15:37:47.665217 | controller | skipping: Conditional result was False 2025-10-07 15:37:47.671229 | 2025-10-07 15:37:47.671294 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:37:47.695277 | controller | skipping: Conditional result was False 2025-10-07 15:37:47.700896 | 2025-10-07 15:37:47.700960 | TASK [bindep : Look for bindep fallback file] 2025-10-07 15:37:47.735436 | controller | skipping: Conditional result was False 2025-10-07 15:37:47.741310 | 2025-10-07 15:37:47.741374 | TASK [bindep : Define bindep_file fact] 2025-10-07 15:37:47.765148 | controller | skipping: Conditional result was False 2025-10-07 15:37:47.771528 | 2025-10-07 15:37:47.771594 | TASK [bindep : Include bindep tasks] 2025-10-07 15:37:47.802120 | controller | ok 2025-10-07 15:37:47.808560 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-07 15:37:47.816376 | 2025-10-07 15:37:47.816551 | TASK [bindep : Look for bindep command] 2025-10-07 15:37:47.840371 | controller | skipping: Conditional result was False 2025-10-07 15:37:47.846357 | 2025-10-07 15:37:47.846418 | TASK [bindep : Check for system bindep] 2025-10-07 15:37:48.375850 | controller | ok: Runtime: 0:00:00.005954 2025-10-07 15:37:48.386068 | 2025-10-07 15:37:48.386200 | TASK [bindep : Define bindep_command fact] 2025-10-07 15:37:48.464028 | controller | skipping: Conditional result was False 2025-10-07 15:37:48.474039 | 2025-10-07 15:37:48.474184 | TASK [bindep : Include install tasks] 2025-10-07 15:37:48.522988 | controller | ok 2025-10-07 15:37:48.530960 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-07 15:37:48.548124 | 2025-10-07 15:37:48.548334 | TASK [bindep : Create temp dir for bindep] 2025-10-07 15:37:48.933857 | controller | changed 2025-10-07 15:37:48.964955 | 2025-10-07 15:37:48.965204 | TASK [Ensure we have pip dependencies] 2025-10-07 15:37:49.001922 | controller | ok 2025-10-07 15:37:49.050023 | 2025-10-07 15:37:49.050176 | TASK [ensure-pip : Check if pip is installed] 2025-10-07 11:37:49.357618 | controller | /usr/bin/pip3 2025-10-07 11:37:49.383164 | controller | /usr/bin/python3: No module named wheel 2025-10-07 15:37:49.601087 | controller | ok: Runtime: 0:00:00.038174 2025-10-07 15:37:49.607738 | 2025-10-07 15:37:49.607815 | LOOP [ensure-pip : Install pip from packages] 2025-10-07 15:37:49.656521 | controller | ok: "/var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-07 15:37:49.673879 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-07 15:37:49.684390 | 2025-10-07 15:37:49.684471 | TASK [ensure-pip : Install Python 3 pip] 2025-10-07 15:37:52.474434 | controller | changed 2025-10-07 15:37:52.489986 | 2025-10-07 15:37:52.490116 | TASK [ensure-pip : Check for EPEL repository] 2025-10-07 15:37:52.537182 | controller | skipping: Conditional result was False 2025-10-07 15:37:52.546492 | 2025-10-07 15:37:52.546584 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-07 15:37:52.593047 | controller | skipping: Conditional result was False 2025-10-07 15:37:52.601803 | 2025-10-07 15:37:52.601892 | TASK [ensure-pip : Install Python 2 pip] 2025-10-07 15:37:52.667208 | controller | skipping: Conditional result was False 2025-10-07 15:37:52.681001 | 2025-10-07 15:37:52.681189 | TASK [ensure-pip : Ensure setuptools] 2025-10-07 15:37:52.717029 | controller | skipping: Conditional result was False 2025-10-07 15:37:52.725978 | 2025-10-07 15:37:52.726069 | TASK [ensure-pip : Check for ensurepip module] 2025-10-07 15:37:53.283002 | controller | skipping: Conditional result was False 2025-10-07 15:37:53.296869 | 2025-10-07 15:37:53.297037 | TASK [ensure-pip : Ensure python3-venv] 2025-10-07 15:37:53.324565 | controller | skipping: Conditional result was False 2025-10-07 15:37:53.337287 | 2025-10-07 15:37:53.337421 | TASK [ensure-pip : Install pip from source] 2025-10-07 15:37:53.364583 | controller | skipping: Conditional result was False 2025-10-07 15:37:53.378690 | 2025-10-07 15:37:53.378831 | TASK [ensure-pip : Probe for venv python full path] 2025-10-07 11:37:53.696433 | controller | /usr/bin/python3 2025-10-07 15:37:53.924325 | controller | ok: Runtime: 0:00:00.008704 2025-10-07 15:37:53.933808 | 2025-10-07 15:37:53.934038 | TASK [ensure-pip : Set host default] 2025-10-07 15:37:53.985748 | controller | ok 2025-10-07 15:37:53.991365 | 2025-10-07 15:37:53.991456 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-07 15:37:54.046121 | controller | ok 2025-10-07 15:37:54.056759 | 2025-10-07 15:37:54.056823 | TASK [bindep : Install bindep into temporary venv] 2025-10-07 15:37:58.591038 | controller | changed 2025-10-07 15:37:58.618814 | 2025-10-07 15:37:58.618972 | TASK [bindep : Define bindep_command] 2025-10-07 15:37:58.663981 | controller | ok 2025-10-07 15:37:58.671386 | 2025-10-07 15:37:58.671474 | LOOP [bindep : Include package tasks] 2025-10-07 15:37:58.731111 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-07 15:37:58.731339 | controller | ok: All items complete 2025-10-07 15:37:58.731367 | 2025-10-07 15:37:58.747309 | controller | included: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-07 15:37:58.760193 | 2025-10-07 15:37:58.760285 | TASK [bindep : Define bindep_run fact] 2025-10-07 15:37:58.789294 | controller | ok 2025-10-07 15:37:58.794490 | 2025-10-07 15:37:58.794552 | TASK [bindep : Get list of packages to install from bindep] 2025-10-07 11:38:00.102784 | controller | podman 2025-10-07 11:38:00.134184 | controller | python3-jmespath 2025-10-07 11:38:00.134252 | controller | python3-libvirt 2025-10-07 11:38:00.134263 | controller | python3-lxml 2025-10-07 11:38:00.134357 | controller | python3-netaddr 2025-10-07 15:38:00.329574 | controller | ok: Runtime: 0:00:01.071902 2025-10-07 15:38:00.342671 | 2025-10-07 15:38:00.342833 | TASK [bindep : Install distro packages from bindep] 2025-10-07 15:39:06.186943 | controller | changed 2025-10-07 15:39:06.199799 | 2025-10-07 15:39:06.199932 | TASK [bindep : Check that packages are installed] 2025-10-07 15:39:07.746394 | controller | ok: Runtime: 0:00:01.086100 2025-10-07 15:39:07.759737 | 2025-10-07 15:39:07.759874 | TASK [bindep : Fail if we cannot install all packages] 2025-10-07 15:39:07.797399 | controller | skipping: Conditional result was False 2025-10-07 15:39:07.822926 | 2025-10-07 15:39:07.823329 | TASK [Run test-setup role] 2025-10-07 15:39:07.847634 | controller | ok 2025-10-07 15:39:07.882495 | 2025-10-07 15:39:07.882746 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-07 15:39:08.129527 | controller | ok 2025-10-07 15:39:08.136341 | 2025-10-07 15:39:08.136426 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-07 15:39:08.675761 | controller | skipping: Conditional result was False 2025-10-07 15:39:08.720262 | 2025-10-07 15:39:08.720365 | TASK [bindep : Remove bindep temp dir] 2025-10-07 15:39:09.121953 | controller | ok 2025-10-07 15:39:09.162551 | 2025-10-07 15:39:09.162656 | PLAY RECAP 2025-10-07 15:39:09.162720 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-07 15:39:09.162742 | 2025-10-07 15:39:09.270592 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-07 15:39:09.271527 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 15:39:09.845038 | 2025-10-07 15:39:09.845153 | PLAY [all] 2025-10-07 15:39:09.864608 | 2025-10-07 15:39:09.864696 | TASK [Abort when test_command variable is undefined] 2025-10-07 15:39:09.899065 | controller | skipping: Conditional result was False 2025-10-07 15:39:09.905191 | 2025-10-07 15:39:09.905265 | TASK [Convert test_command to list] 2025-10-07 15:39:09.959539 | controller | skipping: Conditional result was False 2025-10-07 15:39:09.965949 | 2025-10-07 15:39:09.966015 | TASK [Use test_command list] 2025-10-07 15:39:10.030776 | controller | ok 2025-10-07 15:39:10.042504 | 2025-10-07 15:39:10.042639 | LOOP [Run test_command] 2025-10-07 15:39:10.473950 | controller | no check to run 2025-10-07 15:39:10.474284 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008624 2025-10-07 15:39:10.527111 | 2025-10-07 15:39:10.527237 | PLAY RECAP 2025-10-07 15:39:10.527292 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 15:39:10.527319 | 2025-10-07 15:39:10.640202 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-07 15:39:10.641083 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 15:39:11.261205 | 2025-10-07 15:39:11.261319 | PLAY [all] 2025-10-07 15:39:11.281305 | 2025-10-07 15:39:11.281381 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-07 15:39:11.674986 | controller | changed: non-zero return code 2025-10-07 15:39:11.687367 | 2025-10-07 15:39:11.687521 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-07 15:39:11.714826 | controller | skipping: Conditional result was False 2025-10-07 15:39:11.726960 | 2025-10-07 15:39:11.727104 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-07 15:39:11.769781 | 2025-10-07 15:39:11.780136 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-07 15:39:11.824444 | 2025-10-07 15:39:11.824710 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-07 15:39:11.849821 | controller | skipping: Conditional result was False 2025-10-07 15:39:11.857339 | 2025-10-07 15:39:11.857411 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-07 15:39:11.900375 | 2025-10-07 15:39:11.900560 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-07 15:39:11.936945 | controller | skipping: Conditional result was False 2025-10-07 15:39:11.942899 | 2025-10-07 15:39:11.942966 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-07 15:39:11.966436 | controller | skipping: Conditional result was False 2025-10-07 15:39:11.972684 | 2025-10-07 15:39:11.972752 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-07 15:39:12.001656 | controller | skipping: Conditional result was False 2025-10-07 15:39:12.027589 | 2025-10-07 15:39:12.027690 | PLAY RECAP 2025-10-07 15:39:12.027738 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-07 15:39:12.027758 | 2025-10-07 15:39:12.127611 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-07 15:39:12.128760 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 15:39:12.683847 | 2025-10-07 15:39:12.683968 | PLAY [all] 2025-10-07 15:39:12.702636 | 2025-10-07 15:39:12.702739 | TASK [include_role : fetch-output] 2025-10-07 15:39:12.752799 | controller | ok 2025-10-07 15:39:12.770756 | 2025-10-07 15:39:12.770834 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-07 15:39:12.825218 | controller | skipping: Conditional result was False 2025-10-07 15:39:12.832869 | 2025-10-07 15:39:12.832965 | TASK [fetch-output : Set log path for single node] 2025-10-07 15:39:12.864610 | controller | ok 2025-10-07 15:39:12.871347 | 2025-10-07 15:39:12.871435 | LOOP [fetch-output : Ensure local output dirs] 2025-10-07 15:39:13.299620 | controller -> localhost | ok: "/var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/logs" 2025-10-07 15:39:13.571096 | controller -> localhost | changed: "/var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/artifacts" 2025-10-07 15:39:13.827779 | controller -> localhost | changed: "/var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/docs" 2025-10-07 15:39:13.841512 | 2025-10-07 15:39:13.841739 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-07 15:39:14.576054 | controller | changed: .d..t...... ./ 2025-10-07 15:39:14.576606 | controller | changed: All items complete 2025-10-07 15:39:14.576707 | 2025-10-07 15:39:15.077900 | controller | changed: .d..t...... ./ 2025-10-07 15:39:15.639547 | controller | changed: .d..t...... ./ 2025-10-07 15:39:15.659920 | 2025-10-07 15:39:15.660126 | TASK [include_role : fetch-output-openshift] 2025-10-07 15:39:15.699564 | controller | skipping: Conditional result was False 2025-10-07 15:39:15.706062 | 2025-10-07 15:39:15.706128 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-07 15:39:16.202991 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014816 2025-10-07 15:39:16.463332 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.018483 2025-10-07 15:39:16.507347 | 2025-10-07 15:39:16.507525 | PLAY [all] 2025-10-07 15:39:16.529332 | 2025-10-07 15:39:16.529416 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-07 15:39:16.987950 | controller | changed 2025-10-07 15:39:17.019559 | 2025-10-07 15:39:17.019638 | PLAY RECAP 2025-10-07 15:39:17.019702 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-07 15:39:17.019725 | 2025-10-07 15:39:17.165779 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-07 15:39:17.166627 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-07 15:39:17.815411 | 2025-10-07 15:39:17.815555 | PLAY [localhost] 2025-10-07 15:39:17.834466 | 2025-10-07 15:39:17.834548 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-07 15:39:18.248895 | localhost | changed 2025-10-07 15:39:18.257613 | 2025-10-07 15:39:18.257764 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-07 15:39:18.286761 | localhost | ok 2025-10-07 15:39:18.295005 | 2025-10-07 15:39:18.295077 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-07 15:39:18.782523 | localhost | changed 2025-10-07 15:39:18.795348 | 2025-10-07 15:39:18.795492 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-07 15:39:19.694546 | localhost | changed 2025-10-07 15:39:19.704095 | 2025-10-07 15:39:19.704174 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-07 15:39:20.138275 | localhost | Identity added: /var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/tmp/ansible.9_cni87d (/var/lib/zuul/builds/3ac75f3e8bd240158cd4e584f445b035/work/tmp/ansible.9_cni87d) 2025-10-07 15:39:20.138493 | localhost | ok: Runtime: 0:00:00.014925 2025-10-07 15:39:20.146388 | 2025-10-07 15:39:20.146459 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-07 15:39:20.465327 | localhost | ok: Runtime: 0:00:00.010319 2025-10-07 15:39:20.477330 | 2025-10-07 15:39:20.477483 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-07 15:39:20.556823 | localhost | changed 2025-10-07 15:39:20.567221 | 2025-10-07 15:39:20.567356 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-07 15:39:21.060444 | localhost | changed 2025-10-07 15:39:21.097987 | 2025-10-07 15:39:21.098153 | PLAY [localhost] 2025-10-07 15:39:21.116028 | 2025-10-07 15:39:21.116121 | TASK [Generate bulk log download script] 2025-10-07 15:39:21.140132 | localhost | ok 2025-10-07 15:39:21.157471 | 2025-10-07 15:39:21.157561 | TASK [local-log-download : Check API endpoint is defined] 2025-10-07 15:39:21.211005 | localhost | ok: All assertions passed 2025-10-07 15:39:21.222080 | 2025-10-07 15:39:21.222238 | TASK [local-log-download : Create download script] 2025-10-07 15:39:21.704498 | localhost -> localhost | changed 2025-10-07 15:39:21.714950 | 2025-10-07 15:39:21.715020 | TASK [Register quick-download link] 2025-10-07 15:39:21.748989 | localhost | ok 2025-10-07 15:39:21.808192 | 2025-10-07 15:39:21.808355 | PLAY [logserver.rdoproject.org] 2025-10-07 15:39:21.818061 | 2025-10-07 15:39:21.818126 | TASK [Set zuul-log-path fact] 2025-10-07 15:39:21.846456 | logserver.rdoproject.org | ok 2025-10-07 15:39:21.856363 | 2025-10-07 15:39:21.856431 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-07 15:39:21.895425 | logserver.rdoproject.org | ok 2025-10-07 15:39:21.900885 | 2025-10-07 15:39:21.900951 | TASK [upload-logs : Create log directories] 2025-10-07 15:39:22.603656 | logserver.rdoproject.org | changed 2025-10-07 15:39:22.612251 | 2025-10-07 15:39:22.612487 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-07 15:39:22.939650 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006770 2025-10-07 15:39:22.950179 | 2025-10-07 15:39:22.950316 | TASK [upload-logs : Upload logs to log server] 2025-10-07 15:39:23.615834 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-07 15:39:23.620480 | 2025-10-07 15:39:23.620571 | LOOP [upload-logs : Compress console log and json output] 2025-10-07 15:39:23.678562 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:23.690440 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:23.708792 | 2025-10-07 15:39:23.708988 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-07 15:39:23.761872 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:23.762242 | 2025-10-07 15:39:23.765073 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-07 15:39:23.774254 | 2025-10-07 15:39:23.774472 | LOOP [upload-logs : Upload console log and json output]