2025-12-05 10:27:29.676917 | Job console starting... 2025-12-05 10:27:29.688345 | Updating repositories 2025-12-05 10:27:29.712368 | Preparing job workspace 2025-12-05 10:28:04.082551 | Running Ansible setup... 2025-12-05 10:28:07.949454 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 10:28:08.575292 | 2025-12-05 10:28:08.575425 | PLAY [localhost] 2025-12-05 10:28:08.585039 | 2025-12-05 10:28:08.585156 | TASK [Gathering Facts] 2025-12-05 10:28:09.622450 | localhost | ok 2025-12-05 10:28:09.653725 | 2025-12-05 10:28:09.653899 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 10:28:10.118895 | localhost -> localhost | changed 2025-12-05 10:28:10.125232 | 2025-12-05 10:28:10.125334 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 10:28:11.013913 | localhost -> localhost | changed 2025-12-05 10:28:11.028622 | 2025-12-05 10:28:11.028862 | TASK [Setup log path fact] 2025-12-05 10:28:11.048765 | localhost | ok 2025-12-05 10:28:11.064455 | 2025-12-05 10:28:11.064565 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 10:28:11.094002 | localhost | ok 2025-12-05 10:28:11.105553 | 2025-12-05 10:28:11.105663 | TASK [emit-job-header : Print job information] 2025-12-05 10:28:11.146437 | # Job Information 2025-12-05 10:28:11.146615 | Ansible Version: 2.15.12 2025-12-05 10:28:11.146650 | Job: cifmw-molecule-federation 2025-12-05 10:28:11.146677 | Pipeline: github-check 2025-12-05 10:28:11.146701 | Executor: ze01.softwarefactory-project.io 2025-12-05 10:28:11.146726 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3533 2025-12-05 10:28:11.146752 | Log URL (when completed): https://logserver.rdoproject.org/99c/rdoproject.org/99c15ce6734c4fe883acf17e7f016fef/ 2025-12-05 10:28:11.146778 | Event ID: c701bb20-d1c4-11f0-8a19-d2d4cf562300 2025-12-05 10:28:11.156270 | 2025-12-05 10:28:11.156537 | LOOP [emit-job-header : Print node information] 2025-12-05 10:28:11.262167 | localhost | ok: 2025-12-05 10:28:11.262443 | localhost | # Node Information 2025-12-05 10:28:11.262502 | localhost | Inventory Hostname: controller 2025-12-05 10:28:11.262572 | localhost | Hostname: np0005546823 2025-12-05 10:28:11.262631 | localhost | Username: zuul 2025-12-05 10:28:11.262679 | localhost | Distro: CentOS 9 2025-12-05 10:28:11.262721 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 10:28:11.262760 | localhost | Region: RegionOne 2025-12-05 10:28:11.262799 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 10:28:11.262837 | localhost | Product Name: OpenStack Nova 2025-12-05 10:28:11.262879 | localhost | Interface IP: 38.129.56.194 2025-12-05 10:28:11.321185 | 2025-12-05 10:28:11.321385 | PLAY [all] 2025-12-05 10:28:11.338640 | 2025-12-05 10:28:11.338819 | TASK [Gather network facts] 2025-12-05 10:28:11.880776 | controller | ok 2025-12-05 10:28:11.909254 | 2025-12-05 10:28:11.909380 | TASK [include_role : start-zuul-console] 2025-12-05 10:28:11.933232 | controller | ok 2025-12-05 10:28:11.948775 | 2025-12-05 10:28:11.948872 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 10:28:12.424139 | controller | ok 2025-12-05 10:28:12.446247 | 2025-12-05 10:28:12.446418 | TASK [include_role : add-build-sshkey] 2025-12-05 10:28:12.487585 | controller | ok 2025-12-05 10:28:12.518868 | 2025-12-05 10:28:12.519074 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 10:28:12.771634 | controller -> localhost | ok 2025-12-05 10:28:12.777607 | 2025-12-05 10:28:12.777701 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 10:28:12.808044 | controller | ok 2025-12-05 10:28:12.823326 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 10:28:12.829829 | 2025-12-05 10:28:12.829901 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 10:28:13.469322 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 10:28:13.469529 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/99c15ce6734c4fe883acf17e7f016fef_id_rsa. 2025-12-05 10:28:13.469560 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/99c15ce6734c4fe883acf17e7f016fef_id_rsa.pub. 2025-12-05 10:28:13.469582 | controller -> localhost | The key fingerprint is: 2025-12-05 10:28:13.469602 | controller -> localhost | SHA256:cnHhnZU1gaueKkzJCBepiBsBI+EvsZCmsTH/6qI3txI zuul-build-sshkey 2025-12-05 10:28:13.469621 | controller -> localhost | The key's randomart image is: 2025-12-05 10:28:13.469640 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 10:28:13.469658 | controller -> localhost | |*. . . o=o| 2025-12-05 10:28:13.469685 | controller -> localhost | |+o o . o +. .| 2025-12-05 10:28:13.469713 | controller -> localhost | |B=. . . . o o . | 2025-12-05 10:28:13.469734 | controller -> localhost | |*B+o . o . | 2025-12-05 10:28:13.469752 | controller -> localhost | |o=..o + S . | 2025-12-05 10:28:13.469771 | controller -> localhost | |. E. . * . | 2025-12-05 10:28:13.469789 | controller -> localhost | | .. o . . | 2025-12-05 10:28:13.469807 | controller -> localhost | |. +.. o o | 2025-12-05 10:28:13.469824 | controller -> localhost | |o+o+.. ... | 2025-12-05 10:28:13.469841 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 10:28:13.469905 | controller -> localhost | ok: Runtime: 0:00:00.159922 2025-12-05 10:28:13.475821 | 2025-12-05 10:28:13.475890 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 10:28:13.514966 | controller | ok 2025-12-05 10:28:13.526517 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 10:28:13.537679 | 2025-12-05 10:28:13.537757 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 10:28:13.561758 | controller | skipping: Conditional result was False 2025-12-05 10:28:13.568380 | 2025-12-05 10:28:13.568451 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 10:28:14.037963 | controller | changed 2025-12-05 10:28:14.044661 | 2025-12-05 10:28:14.044749 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 10:28:14.311237 | controller | ok 2025-12-05 10:28:14.318409 | 2025-12-05 10:28:14.318492 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 10:28:15.289292 | controller | changed 2025-12-05 10:28:15.296614 | 2025-12-05 10:28:15.296712 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 10:28:16.306971 | controller | changed 2025-12-05 10:28:16.319716 | 2025-12-05 10:28:16.319930 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 10:28:16.357957 | controller | skipping: Conditional result was False 2025-12-05 10:28:16.371730 | 2025-12-05 10:28:16.371904 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 10:28:16.817346 | controller -> localhost | changed 2025-12-05 10:28:16.831166 | 2025-12-05 10:28:16.831381 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 10:28:17.120543 | controller -> localhost | Identity added: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/99c15ce6734c4fe883acf17e7f016fef_id_rsa (zuul-build-sshkey) 2025-12-05 10:28:17.120758 | controller -> localhost | ok: Runtime: 0:00:00.015755 2025-12-05 10:28:17.127348 | 2025-12-05 10:28:17.127434 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 10:28:17.537115 | controller | ok 2025-12-05 10:28:17.549879 | 2025-12-05 10:28:17.550130 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 10:28:17.612255 | controller | skipping: Conditional result was False 2025-12-05 10:28:17.623603 | 2025-12-05 10:28:17.623712 | TASK [include_role : validate-host] 2025-12-05 10:28:17.653670 | controller | ok 2025-12-05 10:28:17.676514 | 2025-12-05 10:28:17.676632 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 10:28:17.716472 | controller | ok 2025-12-05 10:28:17.721890 | 2025-12-05 10:28:17.721981 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 10:28:17.979959 | controller -> localhost | ok 2025-12-05 10:28:17.987046 | 2025-12-05 10:28:17.987118 | TASK [validate-host : Collect information about the host] 2025-12-05 10:28:18.783783 | controller | ok 2025-12-05 10:28:18.804473 | 2025-12-05 10:28:18.804884 | TASK [validate-host : Sanitize hostname] 2025-12-05 10:28:18.879277 | controller | ok 2025-12-05 10:28:18.887340 | 2025-12-05 10:28:18.887447 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 10:28:19.416437 | controller -> localhost | changed 2025-12-05 10:28:19.424115 | 2025-12-05 10:28:19.424193 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 10:28:19.858374 | controller | ok 2025-12-05 10:28:19.863756 | 2025-12-05 10:28:19.863842 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 10:28:20.346212 | controller -> localhost | changed 2025-12-05 10:28:20.356525 | 2025-12-05 10:28:20.356613 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 10:28:20.370005 | controller | skipping: Conditional result was False 2025-12-05 10:28:20.375934 | 2025-12-05 10:28:20.376164 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 10:28:20.390344 | controller | skipping: Conditional result was False 2025-12-05 10:28:20.398373 | 2025-12-05 10:28:20.398484 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 10:28:20.684120 | controller | ok: "logs" 2025-12-05 10:28:20.684517 | controller | ok: All items complete 2025-12-05 10:28:20.684574 | 2025-12-05 10:28:20.952584 | controller | ok: "artifacts" 2025-12-05 10:28:21.174386 | controller | ok: "docs" 2025-12-05 10:28:21.189901 | 2025-12-05 10:28:21.190104 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 10:28:21.481682 | controller | changed: "logs" 2025-12-05 10:28:21.717881 | controller | changed: "artifacts" 2025-12-05 10:28:22.003483 | controller | changed: "docs" 2025-12-05 10:28:22.058934 | 2025-12-05 10:28:22.059133 | PLAY RECAP 2025-12-05 10:28:22.059232 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 10:28:22.059292 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 10:28:22.059335 | 2025-12-05 10:28:22.187587 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 10:28:22.189684 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 10:28:22.820839 | 2025-12-05 10:28:22.820947 | PLAY [localhost] 2025-12-05 10:28:22.837576 | 2025-12-05 10:28:22.837661 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 10:28:23.299304 | localhost | ok 2025-12-05 10:28:23.310744 | 2025-12-05 10:28:23.310912 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 10:28:23.967164 | localhost | changed 2025-12-05 10:28:23.995613 | 2025-12-05 10:28:23.995712 | PLAY [all] 2025-12-05 10:28:24.012531 | 2025-12-05 10:28:24.012641 | TASK [include_role : prepare-workspace] 2025-12-05 10:28:24.042660 | controller | ok 2025-12-05 10:28:24.057723 | 2025-12-05 10:28:24.057829 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 10:28:24.510470 | controller | ok 2025-12-05 10:28:24.526482 | 2025-12-05 10:28:24.526719 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 10:28:26.302251 | controller | Output suppressed because no_log was given 2025-12-05 10:28:26.316832 | 2025-12-05 10:28:26.316924 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 10:28:26.609294 | controller | changed: "logs" 2025-12-05 10:28:26.855440 | controller | changed: "artifacts" 2025-12-05 10:28:27.085062 | controller | changed: "docs" 2025-12-05 10:28:27.102848 | 2025-12-05 10:28:27.102980 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 10:28:27.393123 | controller | changed: "logs" 2025-12-05 10:28:27.393895 | controller | changed: All items complete 2025-12-05 10:28:27.394009 | 2025-12-05 10:28:27.652978 | controller | changed: "artifacts" 2025-12-05 10:28:27.917171 | controller | changed: "docs" 2025-12-05 10:28:27.949470 | 2025-12-05 10:28:27.949666 | TASK [Check if worker can sudo] 2025-12-05 10:28:28.499421 | controller | ok: Runtime: 0:00:00.044727 2025-12-05 10:28:28.513407 | 2025-12-05 10:28:28.513707 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 10:28:28.575975 | controller | skipping: Conditional result was False 2025-12-05 10:28:28.593165 | 2025-12-05 10:28:28.593344 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 10:28:28.686486 | controller | ok 2025-12-05 10:28:28.706678 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 10:28:28.719648 | 2025-12-05 10:28:28.719830 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 10:28:29.088037 | controller | ok 2025-12-05 10:28:29.100791 | 2025-12-05 10:28:29.100962 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 10:28:29.172649 | controller | ok: "/var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 10:28:29.184945 | 2025-12-05 10:28:29.185111 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 10:28:30.043552 | controller | changed 2025-12-05 10:28:30.056670 | 2025-12-05 10:28:30.056810 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 10:28:30.151291 | controller | ok: "/var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 10:28:30.151843 | controller | ok: All items complete 2025-12-05 10:28:30.151916 | 2025-12-05 10:28:30.235115 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 10:28:30.242141 | 2025-12-05 10:28:30.242227 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 10:28:31.230915 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 10:28:32.164957 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 10:28:32.189819 | 2025-12-05 10:28:32.189962 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 10:28:32.711530 | controller | changed: section and option added 2025-12-05 10:28:32.752897 | 2025-12-05 10:28:32.753099 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 10:28:33.343707 | controller | 29 files removed 2025-12-05 10:28:33.343969 | controller | ok: Item: dnf clean all Runtime: 0:00:00.255104 2025-12-05 10:28:33.344028 | controller | changed: All items complete 2025-12-05 10:28:33.344087 | 2025-12-05 10:28:44.990405 | 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-12-05 10:28:44.990582 | controller | DNF version: 4.14.0 2025-12-05 10:28:44.990638 | controller | cachedir: /var/cache/dnf 2025-12-05 10:28:44.990684 | controller | Making cache files for all metadata files. 2025-12-05 10:28:44.990728 | controller | baseos: has expired and will be refreshed. 2025-12-05 10:28:44.990769 | controller | appstream: has expired and will be refreshed. 2025-12-05 10:28:44.990809 | controller | crb: has expired and will be refreshed. 2025-12-05 10:28:44.990865 | controller | extras-common: has expired and will be refreshed. 2025-12-05 10:28:44.990906 | controller | repo: downloading from remote: baseos 2025-12-05 10:28:44.990945 | controller | CentOS Stream 9 - BaseOS 54 MB/s | 8.8 MB 00:00 2025-12-05 10:28:44.990983 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 10:28:44.991055 | controller | repo: downloading from remote: appstream 2025-12-05 10:28:44.991108 | controller | CentOS Stream 9 - AppStream 60 MB/s | 25 MB 00:00 2025-12-05 10:28:44.991149 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 10:28:44.991188 | controller | repo: downloading from remote: crb 2025-12-05 10:28:44.991226 | controller | CentOS Stream 9 - CRB 36 MB/s | 7.3 MB 00:00 2025-12-05 10:28:44.991265 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 10:28:44.991304 | controller | repo: downloading from remote: extras-common 2025-12-05 10:28:44.991343 | controller | CentOS Stream 9 - Extras packages 114 kB/s | 20 kB 00:00 2025-12-05 10:28:44.991381 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 10:28:44.991419 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 10:28:44.991456 | controller | Completion plugin: Generating completion cache... 2025-12-05 10:28:44.991494 | controller | Metadata cache created. 2025-12-05 10:28:44.991550 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.328552 2025-12-05 10:28:45.025288 | 2025-12-05 10:28:45.025430 | PLAY RECAP 2025-12-05 10:28:45.025516 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 10:28:45.025574 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 10:28:45.025616 | 2025-12-05 10:28:45.146046 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 10:28:45.147654 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 10:28:45.763697 | 2025-12-05 10:28:45.763800 | PLAY [all] 2025-12-05 10:28:45.785149 | 2025-12-05 10:28:45.785255 | TASK [Install binary dependencies] 2025-12-05 10:28:45.844828 | controller | ok 2025-12-05 10:28:45.863781 | 2025-12-05 10:28:45.863883 | TASK [bindep : Include find tasks] 2025-12-05 10:28:45.906380 | controller | ok 2025-12-05 10:28:45.918108 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 10:28:45.926946 | 2025-12-05 10:28:45.927053 | TASK [bindep : Look for bindep.txt] 2025-12-05 10:28:46.330395 | controller | ok 2025-12-05 10:28:46.346859 | 2025-12-05 10:28:46.347084 | TASK [bindep : Define bindep_file fact] 2025-12-05 10:28:46.387330 | controller | ok 2025-12-05 10:28:46.399961 | 2025-12-05 10:28:46.400198 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 10:28:46.427512 | controller | skipping: Conditional result was False 2025-12-05 10:28:46.436288 | 2025-12-05 10:28:46.436411 | TASK [bindep : Define bindep_file fact] 2025-12-05 10:28:46.482530 | controller | skipping: Conditional result was False 2025-12-05 10:28:46.491938 | 2025-12-05 10:28:46.492125 | TASK [bindep : Look for bindep fallback file] 2025-12-05 10:28:46.528268 | controller | skipping: Conditional result was False 2025-12-05 10:28:46.536453 | 2025-12-05 10:28:46.536589 | TASK [bindep : Define bindep_file fact] 2025-12-05 10:28:46.561799 | controller | skipping: Conditional result was False 2025-12-05 10:28:46.567822 | 2025-12-05 10:28:46.568160 | TASK [bindep : Include bindep tasks] 2025-12-05 10:28:46.598678 | controller | ok 2025-12-05 10:28:46.605842 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 10:28:46.615036 | 2025-12-05 10:28:46.615148 | TASK [bindep : Look for bindep command] 2025-12-05 10:28:46.639921 | controller | skipping: Conditional result was False 2025-12-05 10:28:46.647450 | 2025-12-05 10:28:46.647562 | TASK [bindep : Check for system bindep] 2025-12-05 10:28:47.185790 | controller | ok: Runtime: 0:00:00.007354 2025-12-05 10:28:47.199285 | 2025-12-05 10:28:47.199471 | TASK [bindep : Define bindep_command fact] 2025-12-05 10:28:47.227771 | controller | skipping: Conditional result was False 2025-12-05 10:28:47.242625 | 2025-12-05 10:28:47.242816 | TASK [bindep : Include install tasks] 2025-12-05 10:28:47.291844 | controller | ok 2025-12-05 10:28:47.309608 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 10:28:47.322864 | 2025-12-05 10:28:47.322996 | TASK [bindep : Create temp dir for bindep] 2025-12-05 10:28:47.708480 | controller | changed 2025-12-05 10:28:47.725100 | 2025-12-05 10:28:47.725256 | TASK [Ensure we have pip dependencies] 2025-12-05 10:28:47.755889 | controller | ok 2025-12-05 10:28:47.791742 | 2025-12-05 10:28:47.792177 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 05:28:48.061305 | controller | /usr/bin/pip3 2025-12-05 05:28:48.081930 | controller | /usr/bin/python3: No module named wheel 2025-12-05 10:28:48.320059 | controller | ok: Runtime: 0:00:00.032087 2025-12-05 10:28:48.333783 | 2025-12-05 10:28:48.333965 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 10:28:48.389369 | controller | ok: "/var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 10:28:48.408920 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 10:28:48.432693 | 2025-12-05 10:28:48.432827 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 10:28:50.491964 | controller | changed 2025-12-05 10:28:50.504712 | 2025-12-05 10:28:50.504869 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 10:28:50.565362 | controller | skipping: Conditional result was False 2025-12-05 10:28:50.578728 | 2025-12-05 10:28:50.578884 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 10:28:50.636461 | controller | skipping: Conditional result was False 2025-12-05 10:28:50.645733 | 2025-12-05 10:28:50.645833 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 10:28:50.691486 | controller | skipping: Conditional result was False 2025-12-05 10:28:50.703397 | 2025-12-05 10:28:50.703479 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 10:28:50.727836 | controller | skipping: Conditional result was False 2025-12-05 10:28:50.742886 | 2025-12-05 10:28:50.743084 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 10:28:51.287270 | controller | skipping: Conditional result was False 2025-12-05 10:28:51.301510 | 2025-12-05 10:28:51.301690 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 10:28:51.328498 | controller | skipping: Conditional result was False 2025-12-05 10:28:51.341692 | 2025-12-05 10:28:51.341849 | TASK [ensure-pip : Install pip from source] 2025-12-05 10:28:51.369694 | controller | skipping: Conditional result was False 2025-12-05 10:28:51.384243 | 2025-12-05 10:28:51.384422 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 05:28:51.742846 | controller | /usr/bin/python3 2025-12-05 10:28:51.938195 | controller | ok: Runtime: 0:00:00.004878 2025-12-05 10:28:51.954710 | 2025-12-05 10:28:51.954909 | TASK [ensure-pip : Set host default] 2025-12-05 10:28:52.019604 | controller | ok 2025-12-05 10:28:52.031716 | 2025-12-05 10:28:52.031864 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 10:28:52.088613 | controller | ok 2025-12-05 10:28:52.102348 | 2025-12-05 10:28:52.102480 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 10:28:59.253592 | controller | changed 2025-12-05 10:28:59.261384 | 2025-12-05 10:28:59.261465 | TASK [bindep : Define bindep_command] 2025-12-05 10:28:59.294578 | controller | ok 2025-12-05 10:28:59.301723 | 2025-12-05 10:28:59.301807 | LOOP [bindep : Include package tasks] 2025-12-05 10:28:59.366182 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 10:28:59.366412 | controller | ok: All items complete 2025-12-05 10:28:59.366450 | 2025-12-05 10:28:59.379467 | controller | included: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 10:28:59.395429 | 2025-12-05 10:28:59.395598 | TASK [bindep : Define bindep_run fact] 2025-12-05 10:28:59.431744 | controller | ok 2025-12-05 10:28:59.439728 | 2025-12-05 10:28:59.439834 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 05:29:00.902234 | controller | podman 2025-12-05 05:29:00.934884 | controller | python3-jmespath 2025-12-05 05:29:00.935111 | controller | python3-libvirt 2025-12-05 05:29:00.935138 | controller | python3-lxml 2025-12-05 05:29:00.935156 | controller | python3-netaddr 2025-12-05 10:29:00.984688 | controller | ok: Runtime: 0:00:01.157187 2025-12-05 10:29:00.998132 | 2025-12-05 10:29:00.998297 | TASK [bindep : Install distro packages from bindep] 2025-12-05 10:30:07.891348 | controller | changed 2025-12-05 10:30:07.899917 | 2025-12-05 10:30:07.900080 | TASK [bindep : Check that packages are installed] 2025-12-05 10:30:09.442784 | controller | ok: Runtime: 0:00:01.153530 2025-12-05 10:30:09.457242 | 2025-12-05 10:30:09.457405 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 10:30:09.484895 | controller | skipping: Conditional result was False 2025-12-05 10:30:09.510776 | 2025-12-05 10:30:09.510950 | TASK [Run test-setup role] 2025-12-05 10:30:09.556857 | controller | ok 2025-12-05 10:30:09.572857 | 2025-12-05 10:30:09.572950 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 10:30:09.858886 | controller | ok 2025-12-05 10:30:09.866611 | 2025-12-05 10:30:09.866738 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 10:30:10.402954 | controller | skipping: Conditional result was False 2025-12-05 10:30:10.429231 | 2025-12-05 10:30:10.429365 | TASK [bindep : Remove bindep temp dir] 2025-12-05 10:30:10.807121 | controller | ok 2025-12-05 10:30:10.831174 | 2025-12-05 10:30:10.831343 | PLAY RECAP 2025-12-05 10:30:10.831430 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 10:30:10.831475 | 2025-12-05 10:30:10.952199 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 10:30:10.953058 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 10:30:11.516742 | 2025-12-05 10:30:11.516858 | PLAY [all] 2025-12-05 10:30:11.536969 | 2025-12-05 10:30:11.537083 | TASK [Abort when test_command variable is undefined] 2025-12-05 10:30:11.561683 | controller | skipping: Conditional result was False 2025-12-05 10:30:11.567936 | 2025-12-05 10:30:11.568035 | TASK [Convert test_command to list] 2025-12-05 10:30:11.622547 | controller | skipping: Conditional result was False 2025-12-05 10:30:11.629186 | 2025-12-05 10:30:11.629256 | TASK [Use test_command list] 2025-12-05 10:30:11.678273 | controller | ok 2025-12-05 10:30:11.683525 | 2025-12-05 10:30:11.683582 | LOOP [Run test_command] 2025-12-05 10:30:12.123820 | controller | no check to run 2025-12-05 10:30:12.124008 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008029 2025-12-05 10:30:12.168538 | 2025-12-05 10:30:12.168669 | PLAY RECAP 2025-12-05 10:30:12.168729 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 10:30:12.168760 | 2025-12-05 10:30:12.272537 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 10:30:12.274175 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 10:30:12.875224 | 2025-12-05 10:30:12.875362 | PLAY [all] 2025-12-05 10:30:12.897718 | 2025-12-05 10:30:12.897851 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 10:30:13.325282 | controller | changed: non-zero return code 2025-12-05 10:30:13.338578 | 2025-12-05 10:30:13.338747 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 10:30:13.357828 | controller | skipping: Conditional result was False 2025-12-05 10:30:13.376628 | 2025-12-05 10:30:13.376754 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 10:30:13.419508 | 2025-12-05 10:30:13.419690 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 10:30:13.453556 | 2025-12-05 10:30:13.453760 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 10:30:13.480523 | controller | skipping: Conditional result was False 2025-12-05 10:30:13.490427 | 2025-12-05 10:30:13.490526 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 10:30:13.522701 | 2025-12-05 10:30:13.522869 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 10:30:13.537274 | controller | skipping: Conditional result was False 2025-12-05 10:30:13.543180 | 2025-12-05 10:30:13.543252 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 10:30:13.556684 | controller | skipping: Conditional result was False 2025-12-05 10:30:13.562837 | 2025-12-05 10:30:13.562915 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 10:30:13.576395 | controller | skipping: Conditional result was False 2025-12-05 10:30:13.602575 | 2025-12-05 10:30:13.602672 | PLAY RECAP 2025-12-05 10:30:13.602724 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 10:30:13.602747 | 2025-12-05 10:30:13.695983 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 10:30:13.696835 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 10:30:14.268477 | 2025-12-05 10:30:14.268628 | PLAY [all] 2025-12-05 10:30:14.290655 | 2025-12-05 10:30:14.290785 | TASK [include_role : fetch-output] 2025-12-05 10:30:14.321219 | controller | ok 2025-12-05 10:30:14.339770 | 2025-12-05 10:30:14.339884 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 10:30:14.404825 | controller | skipping: Conditional result was False 2025-12-05 10:30:14.410868 | 2025-12-05 10:30:14.410943 | TASK [fetch-output : Set log path for single node] 2025-12-05 10:30:14.446462 | controller | ok 2025-12-05 10:30:14.455427 | 2025-12-05 10:30:14.455552 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 10:30:14.847680 | controller -> localhost | ok: "/var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/logs" 2025-12-05 10:30:15.076961 | controller -> localhost | changed: "/var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/artifacts" 2025-12-05 10:30:15.325708 | controller -> localhost | changed: "/var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/docs" 2025-12-05 10:30:15.347486 | 2025-12-05 10:30:15.347650 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 10:30:16.036740 | controller | changed: .d..t...... ./ 2025-12-05 10:30:16.038911 | controller | changed: All items complete 2025-12-05 10:30:16.038999 | 2025-12-05 10:30:16.572873 | controller | changed: .d..t...... ./ 2025-12-05 10:30:17.060100 | controller | changed: .d..t...... ./ 2025-12-05 10:30:17.090202 | 2025-12-05 10:30:17.090326 | TASK [include_role : fetch-output-openshift] 2025-12-05 10:30:17.105875 | controller | skipping: Conditional result was False 2025-12-05 10:30:17.115368 | 2025-12-05 10:30:17.115529 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 10:30:17.551903 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007191 2025-12-05 10:30:17.774392 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007432 2025-12-05 10:30:17.806930 | 2025-12-05 10:30:17.807054 | PLAY [all] 2025-12-05 10:30:17.834613 | 2025-12-05 10:30:17.834726 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 10:30:18.366163 | controller | changed 2025-12-05 10:30:18.408578 | 2025-12-05 10:30:18.408706 | PLAY RECAP 2025-12-05 10:30:18.408769 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 10:30:18.408808 | 2025-12-05 10:30:18.539138 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 10:30:18.541091 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 10:30:19.191237 | 2025-12-05 10:30:19.191351 | PLAY [localhost] 2025-12-05 10:30:19.217963 | 2025-12-05 10:30:19.218071 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 10:30:19.618881 | localhost | changed 2025-12-05 10:30:19.628461 | 2025-12-05 10:30:19.628625 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 10:30:19.656709 | localhost | ok 2025-12-05 10:30:19.665443 | 2025-12-05 10:30:19.665514 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 10:30:20.015508 | localhost | changed 2025-12-05 10:30:20.025483 | 2025-12-05 10:30:20.025599 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 10:30:20.640901 | localhost | changed 2025-12-05 10:30:20.649355 | 2025-12-05 10:30:20.649468 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 10:30:21.030720 | localhost | Identity added: /var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/tmp/ansible.hk5nlhuk (/var/lib/zuul/builds/99c15ce6734c4fe883acf17e7f016fef/work/tmp/ansible.hk5nlhuk) 2025-12-05 10:30:21.030961 | localhost | ok: Runtime: 0:00:00.008872 2025-12-05 10:30:21.037616 | 2025-12-05 10:30:21.037703 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 10:30:21.297293 | localhost | ok: Runtime: 0:00:00.005602 2025-12-05 10:30:21.302318 | 2025-12-05 10:30:21.302384 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 10:30:21.351538 | localhost | changed 2025-12-05 10:30:21.356607 | 2025-12-05 10:30:21.356672 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 10:30:21.752533 | localhost | changed 2025-12-05 10:30:21.774344 | 2025-12-05 10:30:21.774447 | PLAY [localhost] 2025-12-05 10:30:21.786340 | 2025-12-05 10:30:21.786423 | TASK [Generate bulk log download script] 2025-12-05 10:30:21.805550 | localhost | ok 2025-12-05 10:30:21.817725 | 2025-12-05 10:30:21.817834 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 10:30:21.846261 | localhost | ok: All assertions passed 2025-12-05 10:30:21.850790 | 2025-12-05 10:30:21.850850 | TASK [local-log-download : Create download script] 2025-12-05 10:30:22.264903 | localhost -> localhost | changed 2025-12-05 10:30:22.283902 | 2025-12-05 10:30:22.284058 | TASK [Register quick-download link] 2025-12-05 10:30:22.305604 | localhost | ok 2025-12-05 10:30:22.360153 | 2025-12-05 10:30:22.360258 | PLAY [logserver.rdoproject.org] 2025-12-05 10:30:22.369946 | 2025-12-05 10:30:22.370074 | TASK [Set zuul-log-path fact] 2025-12-05 10:30:22.387412 | logserver.rdoproject.org | ok 2025-12-05 10:30:22.396854 | 2025-12-05 10:30:22.396946 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 10:30:22.434115 | logserver.rdoproject.org | ok 2025-12-05 10:30:22.439695 | 2025-12-05 10:30:22.439767 | TASK [upload-logs : Create log directories] 2025-12-05 10:30:23.070505 | logserver.rdoproject.org | changed 2025-12-05 10:30:23.075722 | 2025-12-05 10:30:23.075824 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 10:30:23.383608 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005289 2025-12-05 10:30:23.388480 | 2025-12-05 10:30:23.388546 | TASK [upload-logs : Upload logs to log server] 2025-12-05 10:30:24.095426 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 10:30:24.101902 | 2025-12-05 10:30:24.102099 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 10:30:24.147462 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:30:24.156219 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:30:24.165168 | 2025-12-05 10:30:24.165264 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 10:30:24.207537 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:30:24.207851 | 2025-12-05 10:30:24.211718 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 10:30:24.217601 | 2025-12-05 10:30:24.217703 | LOOP [upload-logs : Upload console log and json output]