2025-11-27 17:27:04.282988 | Job console starting... 2025-11-27 17:27:04.292875 | Updating repositories 2025-11-27 17:27:04.324359 | Preparing job workspace 2025-11-27 17:27:08.133437 | Running Ansible setup... 2025-11-27 17:27:11.874605 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-27 17:27:12.512889 | 2025-11-27 17:27:12.513062 | PLAY [localhost] 2025-11-27 17:27:12.528451 | 2025-11-27 17:27:12.528519 | TASK [Gathering Facts] 2025-11-27 17:27:13.525600 | localhost | ok 2025-11-27 17:27:13.544067 | 2025-11-27 17:27:13.544154 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-27 17:27:14.066524 | localhost -> localhost | changed 2025-11-27 17:27:14.072195 | 2025-11-27 17:27:14.072280 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-27 17:27:14.986521 | localhost -> localhost | changed 2025-11-27 17:27:15.004567 | 2025-11-27 17:27:15.004709 | TASK [Setup log path fact] 2025-11-27 17:27:15.029586 | localhost | ok 2025-11-27 17:27:15.053690 | 2025-11-27 17:27:15.053774 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-27 17:27:15.093774 | localhost | ok 2025-11-27 17:27:15.104353 | 2025-11-27 17:27:15.104453 | TASK [emit-job-header : Print job information] 2025-11-27 17:27:15.159684 | # Job Information 2025-11-27 17:27:15.159928 | Ansible Version: 2.15.12 2025-11-27 17:27:15.159985 | Job: cifmw-molecule-pcp_metrics 2025-11-27 17:27:15.160062 | Pipeline: github-check 2025-11-27 17:27:15.160106 | Executor: ze01.softwarefactory-project.io 2025-11-27 17:27:15.160145 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3522 2025-11-27 17:27:15.160185 | Log URL (when completed): https://logserver.rdoproject.org/fb2/rdoproject.org/fb2108455d2943c0b765e34032351675/ 2025-11-27 17:27:15.160224 | Event ID: 12e3a2c0-cbb6-11f0-8ac2-64f7bfbb7658 2025-11-27 17:27:15.168324 | 2025-11-27 17:27:15.168460 | LOOP [emit-job-header : Print node information] 2025-11-27 17:27:15.275626 | localhost | ok: 2025-11-27 17:27:15.275857 | localhost | # Node Information 2025-11-27 17:27:15.275886 | localhost | Inventory Hostname: controller 2025-11-27 17:27:15.275912 | localhost | Hostname: np0005538133 2025-11-27 17:27:15.275931 | localhost | Username: zuul 2025-11-27 17:27:15.275950 | localhost | Distro: CentOS 9 2025-11-27 17:27:15.275967 | localhost | Provider: vexxhost-nodepool-tripleo 2025-11-27 17:27:15.275984 | localhost | Region: RegionOne 2025-11-27 17:27:15.275999 | localhost | Label: cloud-centos-9-stream-tripleo 2025-11-27 17:27:15.276037 | localhost | Product Name: OpenStack Nova 2025-11-27 17:27:15.276063 | localhost | Interface IP: 38.102.83.245 2025-11-27 17:27:15.317960 | 2025-11-27 17:27:15.318216 | PLAY [all] 2025-11-27 17:27:15.332227 | 2025-11-27 17:27:15.332366 | TASK [Gather network facts] 2025-11-27 17:27:15.803392 | controller | ok 2025-11-27 17:27:15.844107 | 2025-11-27 17:27:15.844269 | TASK [include_role : start-zuul-console] 2025-11-27 17:27:15.875971 | controller | ok 2025-11-27 17:27:15.900577 | 2025-11-27 17:27:15.900689 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-27 17:27:16.370821 | controller | ok 2025-11-27 17:27:16.387178 | 2025-11-27 17:27:16.387295 | TASK [include_role : add-build-sshkey] 2025-11-27 17:27:16.419220 | controller | ok 2025-11-27 17:27:16.439527 | 2025-11-27 17:27:16.439658 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-27 17:27:16.719051 | controller -> localhost | ok 2025-11-27 17:27:16.725541 | 2025-11-27 17:27:16.725610 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-27 17:27:16.745006 | controller | ok 2025-11-27 17:27:16.759553 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-27 17:27:16.766592 | 2025-11-27 17:27:16.766807 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-27 17:27:17.432660 | controller -> localhost | Generating public/private rsa key pair. 2025-11-27 17:27:17.433053 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/fb2108455d2943c0b765e34032351675_id_rsa. 2025-11-27 17:27:17.433128 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/fb2108455d2943c0b765e34032351675_id_rsa.pub. 2025-11-27 17:27:17.433178 | controller -> localhost | The key fingerprint is: 2025-11-27 17:27:17.433246 | controller -> localhost | SHA256:rKKiwIN87sZScjFtCdfL6U7v9A13mnB2rw2Abxi5CBw zuul-build-sshkey 2025-11-27 17:27:17.433294 | controller -> localhost | The key's randomart image is: 2025-11-27 17:27:17.433335 | controller -> localhost | +---[RSA 3072]----+ 2025-11-27 17:27:17.433374 | controller -> localhost | | . | 2025-11-27 17:27:17.433414 | controller -> localhost | | . . . | 2025-11-27 17:27:17.433452 | controller -> localhost | | + E o | 2025-11-27 17:27:17.433491 | controller -> localhost | | o = * o | 2025-11-27 17:27:17.433530 | controller -> localhost | | + + S + . | 2025-11-27 17:27:17.433568 | controller -> localhost | |+. o = . = . | 2025-11-27 17:27:17.433606 | controller -> localhost | |o+=.. + o.ooo+.o | 2025-11-27 17:27:17.433644 | controller -> localhost | |o.++ . .....B =o.| 2025-11-27 17:27:17.433685 | controller -> localhost | |o.=o .. . +..o| 2025-11-27 17:27:17.433722 | controller -> localhost | +----[SHA256]-----+ 2025-11-27 17:27:17.433803 | controller -> localhost | ok: Runtime: 0:00:00.223548 2025-11-27 17:27:17.442836 | 2025-11-27 17:27:17.442962 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-27 17:27:17.489147 | controller | ok 2025-11-27 17:27:17.506911 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-27 17:27:17.524732 | 2025-11-27 17:27:17.524876 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-27 17:27:17.549637 | controller | skipping: Conditional result was False 2025-11-27 17:27:17.560355 | 2025-11-27 17:27:17.560492 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-27 17:27:18.086310 | controller | changed 2025-11-27 17:27:18.106589 | 2025-11-27 17:27:18.106761 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-27 17:27:18.393980 | controller | ok 2025-11-27 17:27:18.405754 | 2025-11-27 17:27:18.405894 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-27 17:27:19.323342 | controller | changed 2025-11-27 17:27:19.340053 | 2025-11-27 17:27:19.340289 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-27 17:27:20.225339 | controller | changed 2025-11-27 17:27:20.240509 | 2025-11-27 17:27:20.240666 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-27 17:27:20.279452 | controller | skipping: Conditional result was False 2025-11-27 17:27:20.291995 | 2025-11-27 17:27:20.292195 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-27 17:27:20.756801 | controller -> localhost | changed 2025-11-27 17:27:20.788388 | 2025-11-27 17:27:20.788544 | TASK [add-build-sshkey : Add back temp key] 2025-11-27 17:27:21.143852 | controller -> localhost | Identity added: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/fb2108455d2943c0b765e34032351675_id_rsa (zuul-build-sshkey) 2025-11-27 17:27:21.144096 | controller -> localhost | ok: Runtime: 0:00:00.014946 2025-11-27 17:27:21.150199 | 2025-11-27 17:27:21.150263 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-27 17:27:21.560215 | controller | ok 2025-11-27 17:27:21.565493 | 2025-11-27 17:27:21.565571 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-27 17:27:21.590232 | controller | skipping: Conditional result was False 2025-11-27 17:27:21.601179 | 2025-11-27 17:27:21.601255 | TASK [include_role : validate-host] 2025-11-27 17:27:21.620043 | controller | ok 2025-11-27 17:27:21.639401 | 2025-11-27 17:27:21.639477 | TASK [validate-host : Define zuul_info_dir fact] 2025-11-27 17:27:21.668312 | controller | ok 2025-11-27 17:27:21.673218 | 2025-11-27 17:27:21.673279 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-11-27 17:27:21.891486 | controller -> localhost | ok 2025-11-27 17:27:21.899731 | 2025-11-27 17:27:21.899810 | TASK [validate-host : Collect information about the host] 2025-11-27 17:27:22.810147 | controller | ok 2025-11-27 17:27:22.829415 | 2025-11-27 17:27:22.829567 | TASK [validate-host : Sanitize hostname] 2025-11-27 17:27:22.908973 | controller | ok 2025-11-27 17:27:22.920338 | 2025-11-27 17:27:22.920472 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-11-27 17:27:23.464259 | controller -> localhost | changed 2025-11-27 17:27:23.472545 | 2025-11-27 17:27:23.472636 | TASK [validate-host : Collect information about zuul worker] 2025-11-27 17:27:23.997229 | controller | ok 2025-11-27 17:27:24.004268 | 2025-11-27 17:27:24.004363 | TASK [validate-host : Write out all zuul information for each host] 2025-11-27 17:27:24.560434 | controller -> localhost | changed 2025-11-27 17:27:24.570063 | 2025-11-27 17:27:24.570130 | TASK [include_role : prepare-workspace-openshift] 2025-11-27 17:27:24.585162 | controller | skipping: Conditional result was False 2025-11-27 17:27:24.590745 | 2025-11-27 17:27:24.590805 | TASK [include_role : remove-zuul-sshkey] 2025-11-27 17:27:24.604374 | controller | skipping: Conditional result was False 2025-11-27 17:27:24.617461 | 2025-11-27 17:27:24.617649 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-27 17:27:25.289005 | controller | ok: "logs" 2025-11-27 17:27:25.289267 | controller | ok: All items complete 2025-11-27 17:27:25.289293 | 2025-11-27 17:27:25.564924 | controller | ok: "artifacts" 2025-11-27 17:27:25.827187 | controller | ok: "docs" 2025-11-27 17:27:25.841862 | 2025-11-27 17:27:25.842072 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-27 17:27:26.159215 | controller | changed: "logs" 2025-11-27 17:27:26.374621 | controller | changed: "artifacts" 2025-11-27 17:27:26.577290 | controller | changed: "docs" 2025-11-27 17:27:26.627336 | 2025-11-27 17:27:26.627463 | PLAY RECAP 2025-11-27 17:27:26.627523 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-11-27 17:27:26.627562 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-27 17:27:26.627588 | 2025-11-27 17:27:26.788751 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-27 17:27:26.789659 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-27 17:27:27.441543 | 2025-11-27 17:27:27.441655 | PLAY [localhost] 2025-11-27 17:27:27.457650 | 2025-11-27 17:27:27.457724 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-11-27 17:27:27.820428 | localhost | ok 2025-11-27 17:27:27.828021 | 2025-11-27 17:27:27.828124 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-11-27 17:27:28.492278 | localhost | changed 2025-11-27 17:27:28.532625 | 2025-11-27 17:27:28.532760 | PLAY [all] 2025-11-27 17:27:28.555142 | 2025-11-27 17:27:28.555229 | TASK [include_role : prepare-workspace] 2025-11-27 17:27:28.577753 | controller | ok 2025-11-27 17:27:28.597914 | 2025-11-27 17:27:28.598007 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-27 17:27:29.000795 | controller | ok 2025-11-27 17:27:29.013897 | 2025-11-27 17:27:29.014069 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-27 17:27:30.741101 | controller | Output suppressed because no_log was given 2025-11-27 17:27:30.750710 | 2025-11-27 17:27:30.750775 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-27 17:27:31.020943 | controller | changed: "logs" 2025-11-27 17:27:31.269827 | controller | changed: "artifacts" 2025-11-27 17:27:31.516923 | controller | changed: "docs" 2025-11-27 17:27:31.543815 | 2025-11-27 17:27:31.544068 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-27 17:27:31.863216 | controller | changed: "logs" 2025-11-27 17:27:31.863618 | controller | changed: All items complete 2025-11-27 17:27:31.863676 | 2025-11-27 17:27:32.121613 | controller | changed: "artifacts" 2025-11-27 17:27:32.338287 | controller | changed: "docs" 2025-11-27 17:27:32.376967 | 2025-11-27 17:27:32.377202 | TASK [Check if worker can sudo] 2025-11-27 17:27:32.949748 | controller | ok: Runtime: 0:00:00.060060 2025-11-27 17:27:32.955001 | 2025-11-27 17:27:32.955096 | TASK [configure-mirrors : Gather needed facts] 2025-11-27 17:27:32.999582 | controller | skipping: Conditional result was False 2025-11-27 17:27:33.006401 | 2025-11-27 17:27:33.006465 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-11-27 17:27:33.055862 | controller | ok 2025-11-27 17:27:33.063496 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-11-27 17:27:33.069189 | 2025-11-27 17:27:33.069248 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-11-27 17:27:33.418141 | controller | ok 2025-11-27 17:27:33.425502 | 2025-11-27 17:27:33.425582 | LOOP [configure-mirrors : Include OS-specific variables] 2025-11-27 17:27:33.503171 | controller | ok: "/var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-11-27 17:27:33.521901 | 2025-11-27 17:27:33.522076 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-11-27 17:27:34.508088 | controller | changed 2025-11-27 17:27:34.513277 | 2025-11-27 17:27:34.513337 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-11-27 17:27:34.577493 | controller | ok: "/var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-11-27 17:27:34.577718 | controller | ok: All items complete 2025-11-27 17:27:34.577746 | 2025-11-27 17:27:34.660956 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-11-27 17:27:34.669235 | 2025-11-27 17:27:34.669342 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-11-27 17:27:35.736377 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-11-27 17:27:36.649167 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-11-27 17:27:36.660111 | 2025-11-27 17:27:36.660188 | TASK [configure-mirrors : Disable deltrarpm] 2025-11-27 17:27:37.106821 | controller | changed: section and option added 2025-11-27 17:27:37.135117 | 2025-11-27 17:27:37.135231 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-11-27 17:27:37.946407 | controller | 29 files removed 2025-11-27 17:27:37.946680 | controller | ok: Item: dnf clean all Runtime: 0:00:00.465782 2025-11-27 17:27:37.946725 | controller | changed: All items complete 2025-11-27 17:27:37.946747 | 2025-11-27 17:27:48.376685 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-11-27 17:27:48.377098 | controller | DNF version: 4.14.0 2025-11-27 17:27:48.377172 | controller | cachedir: /var/cache/dnf 2025-11-27 17:27:48.377219 | controller | Making cache files for all metadata files. 2025-11-27 17:27:48.377259 | controller | baseos: has expired and will be refreshed. 2025-11-27 17:27:48.377296 | controller | appstream: has expired and will be refreshed. 2025-11-27 17:27:48.377331 | controller | crb: has expired and will be refreshed. 2025-11-27 17:27:48.377382 | controller | extras-common: has expired and will be refreshed. 2025-11-27 17:27:48.377419 | controller | repo: downloading from remote: baseos 2025-11-27 17:27:48.377455 | controller | CentOS Stream 9 - BaseOS 67 MB/s | 8.8 MB 00:00 2025-11-27 17:27:48.377491 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST. 2025-11-27 17:27:48.377526 | controller | repo: downloading from remote: appstream 2025-11-27 17:27:48.377561 | controller | CentOS Stream 9 - AppStream 90 MB/s | 25 MB 00:00 2025-11-27 17:27:48.377597 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST. 2025-11-27 17:27:48.377631 | controller | repo: downloading from remote: crb 2025-11-27 17:27:48.377666 | controller | CentOS Stream 9 - CRB 43 MB/s | 7.3 MB 00:00 2025-11-27 17:27:48.377701 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST. 2025-11-27 17:27:48.377736 | controller | repo: downloading from remote: extras-common 2025-11-27 17:27:48.377771 | controller | CentOS Stream 9 - Extras packages 1.6 MB/s | 20 kB 00:00 2025-11-27 17:27:48.377805 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-11-27 17:27:48.377839 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-11-27 17:27:48.377874 | controller | Completion plugin: Generating completion cache... 2025-11-27 17:27:48.377908 | controller | Metadata cache created. 2025-11-27 17:27:48.377961 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.193838 2025-11-27 17:27:48.412690 | 2025-11-27 17:27:48.413437 | PLAY RECAP 2025-11-27 17:27:48.413581 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-11-27 17:27:48.413641 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-27 17:27:48.413680 | 2025-11-27 17:27:48.517570 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-27 17:27:48.519429 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-27 17:27:49.136902 | 2025-11-27 17:27:49.137087 | PLAY [all] 2025-11-27 17:27:49.157898 | 2025-11-27 17:27:49.157983 | TASK [Install binary dependencies] 2025-11-27 17:27:49.232125 | controller | ok 2025-11-27 17:27:49.251338 | 2025-11-27 17:27:49.251433 | TASK [bindep : Include find tasks] 2025-11-27 17:27:49.292188 | controller | ok 2025-11-27 17:27:49.302650 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-27 17:27:49.311436 | 2025-11-27 17:27:49.311542 | TASK [bindep : Look for bindep.txt] 2025-11-27 17:27:49.746398 | controller | ok 2025-11-27 17:27:49.760525 | 2025-11-27 17:27:49.760673 | TASK [bindep : Define bindep_file fact] 2025-11-27 17:27:49.809683 | controller | ok 2025-11-27 17:27:49.824603 | 2025-11-27 17:27:49.824779 | TASK [bindep : Look for other-requirements.txt] 2025-11-27 17:27:49.853777 | controller | skipping: Conditional result was False 2025-11-27 17:27:49.869352 | 2025-11-27 17:27:49.869518 | TASK [bindep : Define bindep_file fact] 2025-11-27 17:27:49.908967 | controller | skipping: Conditional result was False 2025-11-27 17:27:49.914829 | 2025-11-27 17:27:49.914895 | TASK [bindep : Look for bindep fallback file] 2025-11-27 17:27:49.951037 | controller | skipping: Conditional result was False 2025-11-27 17:27:49.958219 | 2025-11-27 17:27:49.958286 | TASK [bindep : Define bindep_file fact] 2025-11-27 17:27:49.992669 | controller | skipping: Conditional result was False 2025-11-27 17:27:49.998116 | 2025-11-27 17:27:49.998177 | TASK [bindep : Include bindep tasks] 2025-11-27 17:27:50.038246 | controller | ok 2025-11-27 17:27:50.044603 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-11-27 17:27:50.052236 | 2025-11-27 17:27:50.052293 | TASK [bindep : Look for bindep command] 2025-11-27 17:27:50.076470 | controller | skipping: Conditional result was False 2025-11-27 17:27:50.085009 | 2025-11-27 17:27:50.085113 | TASK [bindep : Check for system bindep] 2025-11-27 17:27:50.625501 | controller | ok: Runtime: 0:00:00.007580 2025-11-27 17:27:50.637378 | 2025-11-27 17:27:50.637513 | TASK [bindep : Define bindep_command fact] 2025-11-27 17:27:50.674810 | controller | skipping: Conditional result was False 2025-11-27 17:27:50.690534 | 2025-11-27 17:27:50.690691 | TASK [bindep : Include install tasks] 2025-11-27 17:27:50.735936 | controller | ok 2025-11-27 17:27:50.756626 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-11-27 17:27:50.780345 | 2025-11-27 17:27:50.780491 | TASK [bindep : Create temp dir for bindep] 2025-11-27 17:27:51.173936 | controller | changed 2025-11-27 17:27:51.185699 | 2025-11-27 17:27:51.185825 | TASK [Ensure we have pip dependencies] 2025-11-27 17:27:51.215979 | controller | ok 2025-11-27 17:27:51.262449 | 2025-11-27 17:27:51.262597 | TASK [ensure-pip : Check if pip is installed] 2025-11-27 12:27:51.561186 | controller | /usr/bin/pip3 2025-11-27 12:27:51.582062 | controller | /usr/bin/python3: No module named wheel 2025-11-27 17:27:51.798378 | controller | ok: Runtime: 0:00:00.029600 2025-11-27 17:27:51.810864 | 2025-11-27 17:27:51.811111 | LOOP [ensure-pip : Install pip from packages] 2025-11-27 17:27:51.858150 | controller | ok: "/var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-11-27 17:27:51.877584 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-11-27 17:27:51.900363 | 2025-11-27 17:27:51.900453 | TASK [ensure-pip : Install Python 3 pip] 2025-11-27 17:27:54.090065 | controller | changed 2025-11-27 17:27:54.102145 | 2025-11-27 17:27:54.102280 | TASK [ensure-pip : Check for EPEL repository] 2025-11-27 17:27:54.140220 | controller | skipping: Conditional result was False 2025-11-27 17:27:54.154302 | 2025-11-27 17:27:54.154465 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-11-27 17:27:54.204848 | controller | skipping: Conditional result was False 2025-11-27 17:27:54.218616 | 2025-11-27 17:27:54.218753 | TASK [ensure-pip : Install Python 2 pip] 2025-11-27 17:27:54.255781 | controller | skipping: Conditional result was False 2025-11-27 17:27:54.270192 | 2025-11-27 17:27:54.270333 | TASK [ensure-pip : Ensure setuptools] 2025-11-27 17:27:54.297171 | controller | skipping: Conditional result was False 2025-11-27 17:27:54.311267 | 2025-11-27 17:27:54.311444 | TASK [ensure-pip : Check for ensurepip module] 2025-11-27 17:27:54.857907 | controller | skipping: Conditional result was False 2025-11-27 17:27:54.871948 | 2025-11-27 17:27:54.872152 | TASK [ensure-pip : Ensure python3-venv] 2025-11-27 17:27:54.899807 | controller | skipping: Conditional result was False 2025-11-27 17:27:54.915500 | 2025-11-27 17:27:54.915730 | TASK [ensure-pip : Install pip from source] 2025-11-27 17:27:54.942466 | controller | skipping: Conditional result was False 2025-11-27 17:27:54.956811 | 2025-11-27 17:27:54.956958 | TASK [ensure-pip : Probe for venv python full path] 2025-11-27 12:27:55.234174 | controller | /usr/bin/python3 2025-11-27 17:27:55.501855 | controller | ok: Runtime: 0:00:00.005901 2025-11-27 17:27:55.514261 | 2025-11-27 17:27:55.514455 | TASK [ensure-pip : Set host default] 2025-11-27 17:27:55.569302 | controller | ok 2025-11-27 17:27:55.576518 | 2025-11-27 17:27:55.576602 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-11-27 17:27:55.631186 | controller | ok 2025-11-27 17:27:55.657497 | 2025-11-27 17:27:55.657695 | TASK [bindep : Install bindep into temporary venv] 2025-11-27 17:28:00.383531 | controller | changed 2025-11-27 17:28:00.389011 | 2025-11-27 17:28:00.389086 | TASK [bindep : Define bindep_command] 2025-11-27 17:28:00.427856 | controller | ok 2025-11-27 17:28:00.432889 | 2025-11-27 17:28:00.432951 | LOOP [bindep : Include package tasks] 2025-11-27 17:28:00.498488 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-11-27 17:28:00.498926 | controller | ok: All items complete 2025-11-27 17:28:00.498973 | 2025-11-27 17:28:00.517046 | controller | included: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-11-27 17:28:00.527435 | 2025-11-27 17:28:00.527533 | TASK [bindep : Define bindep_run fact] 2025-11-27 17:28:00.555969 | controller | ok 2025-11-27 17:28:00.560943 | 2025-11-27 17:28:00.561004 | TASK [bindep : Get list of packages to install from bindep] 2025-11-27 12:28:01.911730 | controller | podman 2025-11-27 12:28:01.941911 | controller | python3-jmespath 2025-11-27 12:28:01.941984 | controller | python3-libvirt 2025-11-27 12:28:01.941992 | controller | python3-lxml 2025-11-27 12:28:01.942001 | controller | python3-netaddr 2025-11-27 17:28:02.105555 | controller | ok: Runtime: 0:00:01.138459 2025-11-27 17:28:02.117789 | 2025-11-27 17:28:02.117924 | TASK [bindep : Install distro packages from bindep] 2025-11-27 17:29:04.872964 | controller | changed 2025-11-27 17:29:04.885217 | 2025-11-27 17:29:04.885353 | TASK [bindep : Check that packages are installed] 2025-11-27 17:29:06.468459 | controller | ok: Runtime: 0:00:01.163355 2025-11-27 17:29:06.481987 | 2025-11-27 17:29:06.482207 | TASK [bindep : Fail if we cannot install all packages] 2025-11-27 17:29:06.517894 | controller | skipping: Conditional result was False 2025-11-27 17:29:06.533468 | 2025-11-27 17:29:06.533557 | TASK [Run test-setup role] 2025-11-27 17:29:06.561462 | controller | ok 2025-11-27 17:29:06.586901 | 2025-11-27 17:29:06.587000 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-27 17:29:06.859531 | controller | ok 2025-11-27 17:29:06.872970 | 2025-11-27 17:29:06.873170 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-27 17:29:07.420194 | controller | skipping: Conditional result was False 2025-11-27 17:29:07.463189 | 2025-11-27 17:29:07.463386 | TASK [bindep : Remove bindep temp dir] 2025-11-27 17:29:07.859760 | controller | ok 2025-11-27 17:29:07.882073 | 2025-11-27 17:29:07.882242 | PLAY RECAP 2025-11-27 17:29:07.882369 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-11-27 17:29:07.882426 | 2025-11-27 17:29:07.999582 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-27 17:29:08.001540 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-27 17:29:08.586639 | 2025-11-27 17:29:08.586835 | PLAY [all] 2025-11-27 17:29:08.606275 | 2025-11-27 17:29:08.606364 | TASK [Abort when test_command variable is undefined] 2025-11-27 17:29:08.631305 | controller | skipping: Conditional result was False 2025-11-27 17:29:08.636807 | 2025-11-27 17:29:08.636878 | TASK [Convert test_command to list] 2025-11-27 17:29:08.670866 | controller | skipping: Conditional result was False 2025-11-27 17:29:08.680127 | 2025-11-27 17:29:08.680254 | TASK [Use test_command list] 2025-11-27 17:29:08.753185 | controller | ok 2025-11-27 17:29:08.763134 | 2025-11-27 17:29:08.763261 | LOOP [Run test_command] 2025-11-27 17:29:09.162682 | controller | no check to run 2025-11-27 17:29:09.163044 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004408 2025-11-27 17:29:09.223963 | 2025-11-27 17:29:09.224107 | PLAY RECAP 2025-11-27 17:29:09.224161 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-27 17:29:09.224189 | 2025-11-27 17:29:09.327263 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-27 17:29:09.328216 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-27 17:29:09.933137 | 2025-11-27 17:29:09.933275 | PLAY [all] 2025-11-27 17:29:09.954538 | 2025-11-27 17:29:09.954639 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-27 17:29:10.391340 | controller | changed: non-zero return code 2025-11-27 17:29:10.397187 | 2025-11-27 17:29:10.397284 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-27 17:29:10.428286 | controller | skipping: Conditional result was False 2025-11-27 17:29:10.435419 | 2025-11-27 17:29:10.435495 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-27 17:29:10.465793 | 2025-11-27 17:29:10.465922 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-27 17:29:10.496004 | 2025-11-27 17:29:10.496165 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-27 17:29:10.520332 | controller | skipping: Conditional result was False 2025-11-27 17:29:10.526484 | 2025-11-27 17:29:10.526554 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-27 17:29:10.558815 | 2025-11-27 17:29:10.559011 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-27 17:29:10.583941 | controller | skipping: Conditional result was False 2025-11-27 17:29:10.589665 | 2025-11-27 17:29:10.589731 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-27 17:29:10.604531 | controller | skipping: Conditional result was False 2025-11-27 17:29:10.610630 | 2025-11-27 17:29:10.610698 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-27 17:29:10.634694 | controller | skipping: Conditional result was False 2025-11-27 17:29:10.671591 | 2025-11-27 17:29:10.671759 | PLAY RECAP 2025-11-27 17:29:10.671823 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-27 17:29:10.671857 | 2025-11-27 17:29:10.769834 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-27 17:29:10.771572 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-27 17:29:11.387632 | 2025-11-27 17:29:11.387761 | PLAY [all] 2025-11-27 17:29:11.407835 | 2025-11-27 17:29:11.407929 | TASK [include_role : fetch-output] 2025-11-27 17:29:11.448109 | controller | ok 2025-11-27 17:29:11.465232 | 2025-11-27 17:29:11.465332 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-27 17:29:11.540228 | controller | skipping: Conditional result was False 2025-11-27 17:29:11.548097 | 2025-11-27 17:29:11.548190 | TASK [fetch-output : Set log path for single node] 2025-11-27 17:29:11.590570 | controller | ok 2025-11-27 17:29:11.597710 | 2025-11-27 17:29:11.597803 | LOOP [fetch-output : Ensure local output dirs] 2025-11-27 17:29:11.983752 | controller -> localhost | ok: "/var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/logs" 2025-11-27 17:29:12.223187 | controller -> localhost | changed: "/var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/artifacts" 2025-11-27 17:29:12.438349 | controller -> localhost | changed: "/var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/docs" 2025-11-27 17:29:12.456532 | 2025-11-27 17:29:12.456650 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-27 17:29:13.211733 | controller | changed: .d..t...... ./ 2025-11-27 17:29:13.212156 | controller | changed: All items complete 2025-11-27 17:29:13.212252 | 2025-11-27 17:29:13.786977 | controller | changed: .d..t...... ./ 2025-11-27 17:29:14.340496 | controller | changed: .d..t...... ./ 2025-11-27 17:29:14.377168 | 2025-11-27 17:29:14.377364 | TASK [include_role : fetch-output-openshift] 2025-11-27 17:29:14.404500 | controller | skipping: Conditional result was False 2025-11-27 17:29:14.417882 | 2025-11-27 17:29:14.418049 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-27 17:29:14.839733 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.011912 2025-11-27 17:29:15.136558 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.010862 2025-11-27 17:29:15.163323 | 2025-11-27 17:29:15.163448 | PLAY [all] 2025-11-27 17:29:15.183706 | 2025-11-27 17:29:15.183804 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-11-27 17:29:15.668341 | controller | changed 2025-11-27 17:29:15.711506 | 2025-11-27 17:29:15.711642 | PLAY RECAP 2025-11-27 17:29:15.711703 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-27 17:29:15.711731 | 2025-11-27 17:29:15.811388 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-27 17:29:15.813564 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-11-27 17:29:16.465331 | 2025-11-27 17:29:16.465450 | PLAY [localhost] 2025-11-27 17:29:16.484060 | 2025-11-27 17:29:16.484183 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-27 17:29:16.937957 | localhost | changed 2025-11-27 17:29:16.942600 | 2025-11-27 17:29:16.942674 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-27 17:29:16.981978 | localhost | ok 2025-11-27 17:29:16.989944 | 2025-11-27 17:29:16.990038 | TASK [add-fileserver : Create SSH private key tempfile] 2025-11-27 17:29:17.430777 | localhost | changed 2025-11-27 17:29:17.442876 | 2025-11-27 17:29:17.443111 | TASK [add-fileserver : Create SSH private key from secret] 2025-11-27 17:29:18.238200 | localhost | changed 2025-11-27 17:29:18.243569 | 2025-11-27 17:29:18.243637 | TASK [add-fileserver : Add fileserver ssh key] 2025-11-27 17:29:18.693372 | localhost | Identity added: /var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/tmp/ansible.mn2l_ibe (/var/lib/zuul/builds/fb2108455d2943c0b765e34032351675/work/tmp/ansible.mn2l_ibe) 2025-11-27 17:29:18.693591 | localhost | ok: Runtime: 0:00:00.012915 2025-11-27 17:29:18.698083 | 2025-11-27 17:29:18.698152 | TASK [add-fileserver : Remove SSH private key from disk] 2025-11-27 17:29:19.024822 | localhost | ok: Runtime: 0:00:00.008584 2025-11-27 17:29:19.030657 | 2025-11-27 17:29:19.030758 | TASK [add-fileserver : Add fileserver to inventory] 2025-11-27 17:29:19.111871 | localhost | changed 2025-11-27 17:29:19.116537 | 2025-11-27 17:29:19.116609 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-11-27 17:29:19.512207 | localhost | changed 2025-11-27 17:29:19.532498 | 2025-11-27 17:29:19.532564 | PLAY [localhost] 2025-11-27 17:29:19.546635 | 2025-11-27 17:29:19.546725 | TASK [Generate bulk log download script] 2025-11-27 17:29:19.567147 | localhost | ok 2025-11-27 17:29:19.580979 | 2025-11-27 17:29:19.581103 | TASK [local-log-download : Check API endpoint is defined] 2025-11-27 17:29:19.631763 | localhost | ok: All assertions passed 2025-11-27 17:29:19.636466 | 2025-11-27 17:29:19.636527 | TASK [local-log-download : Create download script] 2025-11-27 17:29:20.097745 | localhost -> localhost | changed 2025-11-27 17:29:20.106438 | 2025-11-27 17:29:20.106499 | TASK [Register quick-download link] 2025-11-27 17:29:20.136483 | localhost | ok 2025-11-27 17:29:20.174602 | 2025-11-27 17:29:20.174709 | PLAY [logserver.rdoproject.org] 2025-11-27 17:29:20.184346 | 2025-11-27 17:29:20.184406 | TASK [Set zuul-log-path fact] 2025-11-27 17:29:20.202166 | logserver.rdoproject.org | ok 2025-11-27 17:29:20.211124 | 2025-11-27 17:29:20.211186 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-27 17:29:20.259758 | logserver.rdoproject.org | ok 2025-11-27 17:29:20.267399 | 2025-11-27 17:29:20.267480 | TASK [upload-logs : Create log directories] 2025-11-27 17:29:21.142901 | logserver.rdoproject.org | changed 2025-11-27 17:29:21.149701 | 2025-11-27 17:29:21.149834 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-11-27 17:29:21.484859 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007876 2025-11-27 17:29:21.491129 | 2025-11-27 17:29:21.491264 | TASK [upload-logs : Upload logs to log server] 2025-11-27 17:29:22.214621 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-11-27 17:29:22.217984 | 2025-11-27 17:29:22.218104 | LOOP [upload-logs : Compress console log and json output] 2025-11-27 17:29:22.265978 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-27 17:29:22.285684 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-27 17:29:22.301531 | 2025-11-27 17:29:22.301802 | LOOP [upload-logs : Upload compressed console log and json output] 2025-11-27 17:29:22.362738 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-27 17:29:22.363295 | 2025-11-27 17:29:22.367395 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-27 17:29:22.377866 | 2025-11-27 17:29:22.378089 | LOOP [upload-logs : Upload console log and json output]