2025-12-05 23:36:42.835691 | Job console starting... 2025-12-05 23:36:42.849123 | Updating repositories 2025-12-05 23:36:42.874758 | Preparing job workspace 2025-12-05 23:36:47.157334 | Running Ansible setup... 2025-12-05 23:36:51.106571 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 23:36:51.796159 | 2025-12-05 23:36:51.796267 | PLAY [localhost] 2025-12-05 23:36:51.813575 | 2025-12-05 23:36:51.813651 | TASK [Gathering Facts] 2025-12-05 23:36:52.945389 | localhost | ok 2025-12-05 23:36:52.960997 | 2025-12-05 23:36:52.961143 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 23:36:53.516904 | localhost -> localhost | changed 2025-12-05 23:36:53.526452 | 2025-12-05 23:36:53.526577 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 23:36:55.040286 | localhost -> localhost | changed 2025-12-05 23:36:55.049002 | 2025-12-05 23:36:55.049065 | TASK [Setup log path fact] 2025-12-05 23:36:55.068665 | localhost | ok 2025-12-05 23:36:55.084230 | 2025-12-05 23:36:55.084307 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 23:36:55.121876 | localhost | ok 2025-12-05 23:36:55.132617 | 2025-12-05 23:36:55.132701 | TASK [emit-job-header : Print job information] 2025-12-05 23:36:55.190797 | # Job Information 2025-12-05 23:36:55.190940 | Ansible Version: 2.15.12 2025-12-05 23:36:55.190968 | Job: cifmw-molecule-cifmw_nfs 2025-12-05 23:36:55.190989 | Pipeline: github-check 2025-12-05 23:36:55.191008 | Executor: ze03.softwarefactory-project.io 2025-12-05 23:36:55.191027 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539 2025-12-05 23:36:55.191046 | Log URL (when completed): https://logserver.rdoproject.org/dd4/rdoproject.org/dd47883310c4497db5adfd0b2c25fd39/ 2025-12-05 23:36:55.191066 | Event ID: 0eecf260-d233-11f0-9ab7-da45df476e85 2025-12-05 23:36:55.194795 | 2025-12-05 23:36:55.194860 | LOOP [emit-job-header : Print node information] 2025-12-05 23:36:55.356166 | localhost | ok: 2025-12-05 23:36:55.356310 | localhost | # Node Information 2025-12-05 23:36:55.356337 | localhost | Inventory Hostname: controller 2025-12-05 23:36:55.356361 | localhost | Hostname: np0005548172 2025-12-05 23:36:55.356381 | localhost | Username: zuul 2025-12-05 23:36:55.356401 | localhost | Distro: CentOS 9 2025-12-05 23:36:55.356419 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 23:36:55.356437 | localhost | Region: RegionOne 2025-12-05 23:36:55.356454 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 23:36:55.356471 | localhost | Product Name: OpenStack Nova 2025-12-05 23:36:55.356487 | localhost | Interface IP: 38.102.83.251 2025-12-05 23:36:55.413062 | 2025-12-05 23:36:55.413165 | PLAY [all] 2025-12-05 23:36:55.430905 | 2025-12-05 23:36:55.431009 | TASK [Gather network facts] 2025-12-05 23:36:55.972402 | controller | ok 2025-12-05 23:36:55.991318 | 2025-12-05 23:36:55.991389 | TASK [include_role : start-zuul-console] 2025-12-05 23:36:56.009418 | controller | ok 2025-12-05 23:36:56.024488 | 2025-12-05 23:36:56.024567 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 23:36:56.471465 | controller | ok 2025-12-05 23:36:56.483901 | 2025-12-05 23:36:56.483969 | TASK [include_role : add-build-sshkey] 2025-12-05 23:36:56.529098 | controller | ok 2025-12-05 23:36:56.580024 | 2025-12-05 23:36:56.580124 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 23:36:56.939064 | controller -> localhost | ok 2025-12-05 23:36:56.944413 | 2025-12-05 23:36:56.944474 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 23:36:56.983858 | controller | ok 2025-12-05 23:36:56.997114 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 23:36:57.002847 | 2025-12-05 23:36:57.002909 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 23:36:57.880310 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 23:36:57.880515 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/dd47883310c4497db5adfd0b2c25fd39_id_rsa. 2025-12-05 23:36:57.880546 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/dd47883310c4497db5adfd0b2c25fd39_id_rsa.pub. 2025-12-05 23:36:57.880568 | controller -> localhost | The key fingerprint is: 2025-12-05 23:36:57.880589 | controller -> localhost | SHA256:pMMXPgEDepjJTSeC8kMtVOBA2p8weqM4QZ92TCQsiYY zuul-build-sshkey 2025-12-05 23:36:57.880610 | controller -> localhost | The key's randomart image is: 2025-12-05 23:36:57.880629 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 23:36:57.880646 | controller -> localhost | |=+*==o+ | 2025-12-05 23:36:57.880666 | controller -> localhost | |EOoX+o o | 2025-12-05 23:36:57.880683 | controller -> localhost | |++%.o. + | 2025-12-05 23:36:57.880701 | controller -> localhost | |..+=+o + o | 2025-12-05 23:36:57.880719 | controller -> localhost | |o o=oo+ S | 2025-12-05 23:36:57.880759 | controller -> localhost | |.+... o . | 2025-12-05 23:36:57.880778 | controller -> localhost | |+ | 2025-12-05 23:36:57.880798 | controller -> localhost | | . | 2025-12-05 23:36:57.880817 | controller -> localhost | | | 2025-12-05 23:36:57.880834 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 23:36:57.880879 | controller -> localhost | ok: Runtime: 0:00:00.316012 2025-12-05 23:36:57.898108 | 2025-12-05 23:36:57.898230 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 23:36:57.948385 | controller | ok 2025-12-05 23:36:58.025673 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 23:36:58.036415 | 2025-12-05 23:36:58.036483 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 23:36:58.099117 | controller | skipping: Conditional result was False 2025-12-05 23:36:58.104840 | 2025-12-05 23:36:58.104910 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 23:36:58.785002 | controller | changed 2025-12-05 23:36:58.790053 | 2025-12-05 23:36:58.790172 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 23:36:59.087324 | controller | ok 2025-12-05 23:36:59.093094 | 2025-12-05 23:36:59.093159 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 23:36:59.906865 | controller | changed 2025-12-05 23:36:59.912265 | 2025-12-05 23:36:59.912329 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 23:37:00.765625 | controller | changed 2025-12-05 23:37:00.770934 | 2025-12-05 23:37:00.771017 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 23:37:00.786378 | controller | skipping: Conditional result was False 2025-12-05 23:37:00.793063 | 2025-12-05 23:37:00.793149 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 23:37:01.252620 | controller -> localhost | changed 2025-12-05 23:37:01.263997 | 2025-12-05 23:37:01.264076 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 23:37:01.659694 | controller -> localhost | Identity added: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/dd47883310c4497db5adfd0b2c25fd39_id_rsa (zuul-build-sshkey) 2025-12-05 23:37:01.660071 | controller -> localhost | ok: Runtime: 0:00:00.016599 2025-12-05 23:37:01.666206 | 2025-12-05 23:37:01.666269 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 23:37:02.124913 | controller | ok 2025-12-05 23:37:02.130857 | 2025-12-05 23:37:02.130921 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 23:37:02.162687 | controller | skipping: Conditional result was False 2025-12-05 23:37:02.174179 | 2025-12-05 23:37:02.174273 | TASK [include_role : validate-host] 2025-12-05 23:37:02.196181 | controller | ok 2025-12-05 23:37:02.223175 | 2025-12-05 23:37:02.223266 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 23:37:02.282651 | controller | ok 2025-12-05 23:37:02.344652 | 2025-12-05 23:37:02.347678 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 23:37:02.761528 | controller -> localhost | ok 2025-12-05 23:37:02.767496 | 2025-12-05 23:37:02.767571 | TASK [validate-host : Collect information about the host] 2025-12-05 23:37:03.541004 | controller | ok 2025-12-05 23:37:03.554538 | 2025-12-05 23:37:03.554661 | TASK [validate-host : Sanitize hostname] 2025-12-05 23:37:03.668155 | controller | ok 2025-12-05 23:37:03.676152 | 2025-12-05 23:37:03.676248 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 23:37:04.339801 | controller -> localhost | changed 2025-12-05 23:37:04.345416 | 2025-12-05 23:37:04.345482 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 23:37:04.745545 | controller | ok 2025-12-05 23:37:04.754646 | 2025-12-05 23:37:04.754765 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 23:37:05.229296 | controller -> localhost | changed 2025-12-05 23:37:05.240569 | 2025-12-05 23:37:05.240690 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 23:37:05.253791 | controller | skipping: Conditional result was False 2025-12-05 23:37:05.259073 | 2025-12-05 23:37:05.259136 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 23:37:05.272544 | controller | skipping: Conditional result was False 2025-12-05 23:37:05.278115 | 2025-12-05 23:37:05.278178 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 23:37:05.524034 | controller | ok: "logs" 2025-12-05 23:37:05.524408 | controller | ok: All items complete 2025-12-05 23:37:05.524466 | 2025-12-05 23:37:05.788248 | controller | ok: "artifacts" 2025-12-05 23:37:06.019427 | controller | ok: "docs" 2025-12-05 23:37:06.025132 | 2025-12-05 23:37:06.025196 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 23:37:06.306443 | controller | changed: "logs" 2025-12-05 23:37:06.512638 | controller | changed: "artifacts" 2025-12-05 23:37:06.739872 | controller | changed: "docs" 2025-12-05 23:37:06.767644 | 2025-12-05 23:37:06.767797 | PLAY RECAP 2025-12-05 23:37:06.767844 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 23:37:06.767870 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 23:37:06.767887 | 2025-12-05 23:37:06.879928 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 23:37:06.880674 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 23:37:07.499448 | 2025-12-05 23:37:07.499567 | PLAY [localhost] 2025-12-05 23:37:07.523128 | 2025-12-05 23:37:07.523219 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 23:37:07.926450 | localhost | ok 2025-12-05 23:37:07.931652 | 2025-12-05 23:37:07.931759 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 23:37:08.564535 | localhost | changed 2025-12-05 23:37:08.584539 | 2025-12-05 23:37:08.584599 | PLAY [all] 2025-12-05 23:37:08.600185 | 2025-12-05 23:37:08.600247 | TASK [include_role : prepare-workspace] 2025-12-05 23:37:08.629135 | controller | ok 2025-12-05 23:37:08.643210 | 2025-12-05 23:37:08.643291 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 23:37:09.066686 | controller | ok 2025-12-05 23:37:09.081165 | 2025-12-05 23:37:09.081259 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 23:37:11.089649 | controller | Output suppressed because no_log was given 2025-12-05 23:37:11.107687 | 2025-12-05 23:37:11.107835 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 23:37:11.372317 | controller | changed: "logs" 2025-12-05 23:37:11.578192 | controller | changed: "artifacts" 2025-12-05 23:37:11.776979 | controller | changed: "docs" 2025-12-05 23:37:11.783890 | 2025-12-05 23:37:11.783978 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 23:37:12.044503 | controller | changed: "logs" 2025-12-05 23:37:12.044920 | controller | changed: All items complete 2025-12-05 23:37:12.044978 | 2025-12-05 23:37:12.258791 | controller | changed: "artifacts" 2025-12-05 23:37:12.457480 | controller | changed: "docs" 2025-12-05 23:37:12.491913 | 2025-12-05 23:37:12.492129 | TASK [Check if worker can sudo] 2025-12-05 23:37:13.049935 | controller | ok: Runtime: 0:00:00.029669 2025-12-05 23:37:13.060929 | 2025-12-05 23:37:13.061038 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 23:37:13.140481 | controller | skipping: Conditional result was False 2025-12-05 23:37:13.147238 | 2025-12-05 23:37:13.147383 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 23:37:13.210773 | controller | ok 2025-12-05 23:37:13.224622 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 23:37:13.241209 | 2025-12-05 23:37:13.241348 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 23:37:13.577706 | controller | ok 2025-12-05 23:37:13.585496 | 2025-12-05 23:37:13.585688 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 23:37:13.684123 | controller | ok: "/var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 23:37:13.696108 | 2025-12-05 23:37:13.696257 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 23:37:14.579214 | controller | changed 2025-12-05 23:37:14.591301 | 2025-12-05 23:37:14.591438 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 23:37:14.675393 | controller | ok: "/var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 23:37:14.675663 | controller | ok: All items complete 2025-12-05 23:37:14.675700 | 2025-12-05 23:37:14.741299 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 23:37:14.747812 | 2025-12-05 23:37:14.747876 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 23:37:15.653642 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 23:37:16.475699 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 23:37:16.489944 | 2025-12-05 23:37:16.490042 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 23:37:16.913053 | controller | changed: section and option added 2025-12-05 23:37:16.962146 | 2025-12-05 23:37:16.962328 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 23:37:17.647945 | controller | 29 files removed 2025-12-05 23:37:17.648350 | controller | ok: Item: dnf clean all Runtime: 0:00:00.338176 2025-12-05 23:37:17.648432 | controller | changed: All items complete 2025-12-05 23:37:17.648477 | 2025-12-05 23:37:29.097431 | 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 23:37:29.097616 | controller | DNF version: 4.14.0 2025-12-05 23:37:29.097674 | controller | cachedir: /var/cache/dnf 2025-12-05 23:37:29.097718 | controller | Making cache files for all metadata files. 2025-12-05 23:37:29.097809 | controller | baseos: has expired and will be refreshed. 2025-12-05 23:37:29.097850 | controller | appstream: has expired and will be refreshed. 2025-12-05 23:37:29.097887 | controller | crb: has expired and will be refreshed. 2025-12-05 23:37:29.097939 | controller | extras-common: has expired and will be refreshed. 2025-12-05 23:37:29.097976 | controller | repo: downloading from remote: baseos 2025-12-05 23:37:29.098011 | controller | CentOS Stream 9 - BaseOS 50 MB/s | 8.8 MB 00:00 2025-12-05 23:37:29.098047 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 23:37:29.098082 | controller | repo: downloading from remote: appstream 2025-12-05 23:37:29.098116 | controller | CentOS Stream 9 - AppStream 83 MB/s | 25 MB 00:00 2025-12-05 23:37:29.098150 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 23:37:29.098183 | controller | repo: downloading from remote: crb 2025-12-05 23:37:29.098218 | controller | CentOS Stream 9 - CRB 60 MB/s | 7.3 MB 00:00 2025-12-05 23:37:29.098254 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 23:37:29.098289 | controller | repo: downloading from remote: extras-common 2025-12-05 23:37:29.098325 | controller | CentOS Stream 9 - Extras packages 59 kB/s | 20 kB 00:00 2025-12-05 23:37:29.098360 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 23:37:29.098395 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 23:37:29.098430 | controller | Completion plugin: Generating completion cache... 2025-12-05 23:37:29.098466 | controller | Metadata cache created. 2025-12-05 23:37:29.098519 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.167313 2025-12-05 23:37:29.120656 | 2025-12-05 23:37:29.120782 | PLAY RECAP 2025-12-05 23:37:29.120836 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 23:37:29.120872 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 23:37:29.120897 | 2025-12-05 23:37:29.221435 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 23:37:29.222335 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 23:37:29.774944 | 2025-12-05 23:37:29.775035 | PLAY [all] 2025-12-05 23:37:29.795956 | 2025-12-05 23:37:29.796030 | TASK [Install binary dependencies] 2025-12-05 23:37:29.877960 | controller | ok 2025-12-05 23:37:29.897178 | 2025-12-05 23:37:29.897256 | TASK [bindep : Include find tasks] 2025-12-05 23:37:29.927537 | controller | ok 2025-12-05 23:37:29.939435 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 23:37:29.946767 | 2025-12-05 23:37:29.946832 | TASK [bindep : Look for bindep.txt] 2025-12-05 23:37:30.352221 | controller | ok 2025-12-05 23:37:30.359467 | 2025-12-05 23:37:30.359539 | TASK [bindep : Define bindep_file fact] 2025-12-05 23:37:30.390140 | controller | ok 2025-12-05 23:37:30.395272 | 2025-12-05 23:37:30.395335 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 23:37:30.419107 | controller | skipping: Conditional result was False 2025-12-05 23:37:30.424998 | 2025-12-05 23:37:30.425068 | TASK [bindep : Define bindep_file fact] 2025-12-05 23:37:30.459469 | controller | skipping: Conditional result was False 2025-12-05 23:37:30.465439 | 2025-12-05 23:37:30.465505 | TASK [bindep : Look for bindep fallback file] 2025-12-05 23:37:30.500353 | controller | skipping: Conditional result was False 2025-12-05 23:37:30.506366 | 2025-12-05 23:37:30.506438 | TASK [bindep : Define bindep_file fact] 2025-12-05 23:37:30.531202 | controller | skipping: Conditional result was False 2025-12-05 23:37:30.537396 | 2025-12-05 23:37:30.537462 | TASK [bindep : Include bindep tasks] 2025-12-05 23:37:30.573999 | controller | ok 2025-12-05 23:37:30.591872 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 23:37:30.600660 | 2025-12-05 23:37:30.600743 | TASK [bindep : Look for bindep command] 2025-12-05 23:37:30.625505 | controller | skipping: Conditional result was False 2025-12-05 23:37:30.632455 | 2025-12-05 23:37:30.632520 | TASK [bindep : Check for system bindep] 2025-12-05 23:37:31.163673 | controller | ok: Runtime: 0:00:00.005099 2025-12-05 23:37:31.172969 | 2025-12-05 23:37:31.173103 | TASK [bindep : Define bindep_command fact] 2025-12-05 23:37:31.196803 | controller | skipping: Conditional result was False 2025-12-05 23:37:31.209035 | 2025-12-05 23:37:31.209172 | TASK [bindep : Include install tasks] 2025-12-05 23:37:31.238369 | controller | ok 2025-12-05 23:37:31.246243 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 23:37:31.255177 | 2025-12-05 23:37:31.255264 | TASK [bindep : Create temp dir for bindep] 2025-12-05 23:37:31.628965 | controller | changed 2025-12-05 23:37:31.635108 | 2025-12-05 23:37:31.635240 | TASK [Ensure we have pip dependencies] 2025-12-05 23:37:31.654133 | controller | ok 2025-12-05 23:37:31.680041 | 2025-12-05 23:37:31.680159 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 18:37:31.920169 | controller | /usr/bin/pip3 2025-12-05 18:37:31.940007 | controller | /usr/bin/python3: No module named wheel 2025-12-05 23:37:32.208620 | controller | ok: Runtime: 0:00:00.031142 2025-12-05 23:37:32.216561 | 2025-12-05 23:37:32.216650 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 23:37:32.256633 | controller | ok: "/var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 23:37:32.279085 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 23:37:32.298655 | 2025-12-05 23:37:32.298771 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 23:37:36.136114 | controller | changed 2025-12-05 23:37:36.151188 | 2025-12-05 23:37:36.151384 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 23:37:36.214157 | controller | skipping: Conditional result was False 2025-12-05 23:37:36.229020 | 2025-12-05 23:37:36.229188 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 23:37:36.326034 | controller | skipping: Conditional result was False 2025-12-05 23:37:36.334177 | 2025-12-05 23:37:36.334284 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 23:37:36.384262 | controller | skipping: Conditional result was False 2025-12-05 23:37:36.395757 | 2025-12-05 23:37:36.395899 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 23:37:36.438004 | controller | skipping: Conditional result was False 2025-12-05 23:37:36.444336 | 2025-12-05 23:37:36.444437 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 23:37:36.991356 | controller | skipping: Conditional result was False 2025-12-05 23:37:36.997335 | 2025-12-05 23:37:36.997433 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 23:37:37.023271 | controller | skipping: Conditional result was False 2025-12-05 23:37:37.030474 | 2025-12-05 23:37:37.030629 | TASK [ensure-pip : Install pip from source] 2025-12-05 23:37:37.056519 | controller | skipping: Conditional result was False 2025-12-05 23:37:37.062262 | 2025-12-05 23:37:37.062325 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 18:37:37.341447 | controller | /usr/bin/python3 2025-12-05 23:37:37.617376 | controller | ok: Runtime: 0:00:00.005374 2025-12-05 23:37:37.623899 | 2025-12-05 23:37:37.625818 | TASK [ensure-pip : Set host default] 2025-12-05 23:37:37.680673 | controller | ok 2025-12-05 23:37:37.688574 | 2025-12-05 23:37:37.688671 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 23:37:37.754182 | controller | ok 2025-12-05 23:37:37.771711 | 2025-12-05 23:37:37.771839 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 23:37:43.381952 | controller | changed 2025-12-05 23:37:43.396086 | 2025-12-05 23:37:43.396273 | TASK [bindep : Define bindep_command] 2025-12-05 23:37:43.433019 | controller | ok 2025-12-05 23:37:43.444529 | 2025-12-05 23:37:43.444625 | LOOP [bindep : Include package tasks] 2025-12-05 23:37:43.515597 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 23:37:43.515829 | controller | ok: All items complete 2025-12-05 23:37:43.515857 | 2025-12-05 23:37:43.526066 | controller | included: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 23:37:43.542300 | 2025-12-05 23:37:43.542375 | TASK [bindep : Define bindep_run fact] 2025-12-05 23:37:43.577469 | controller | ok 2025-12-05 23:37:43.582471 | 2025-12-05 23:37:43.582535 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 18:37:45.082890 | controller | podman 2025-12-05 18:37:45.148701 | controller | python3-jmespath 2025-12-05 18:37:45.148873 | controller | python3-libvirt 2025-12-05 18:37:45.148885 | controller | python3-lxml 2025-12-05 18:37:45.148895 | controller | python3-netaddr 2025-12-05 23:37:45.616559 | controller | ok: Runtime: 0:00:01.304476 2025-12-05 23:37:45.622720 | 2025-12-05 23:37:45.622813 | TASK [bindep : Install distro packages from bindep] 2025-12-05 23:38:57.071533 | controller | changed 2025-12-05 23:38:57.088647 | 2025-12-05 23:38:57.088858 | TASK [bindep : Check that packages are installed] 2025-12-05 23:38:58.644456 | controller | ok: Runtime: 0:00:01.251772 2025-12-05 23:38:58.650191 | 2025-12-05 23:38:58.650254 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 23:38:58.673926 | controller | skipping: Conditional result was False 2025-12-05 23:38:58.684527 | 2025-12-05 23:38:58.684603 | TASK [Run test-setup role] 2025-12-05 23:38:58.702793 | controller | ok 2025-12-05 23:38:58.740076 | 2025-12-05 23:38:58.740177 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 23:38:59.005657 | controller | ok 2025-12-05 23:38:59.015400 | 2025-12-05 23:38:59.015537 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 23:38:59.571176 | controller | skipping: Conditional result was False 2025-12-05 23:38:59.590409 | 2025-12-05 23:38:59.590481 | TASK [bindep : Remove bindep temp dir] 2025-12-05 23:38:59.992183 | controller | ok 2025-12-05 23:39:00.003798 | 2025-12-05 23:39:00.003932 | PLAY RECAP 2025-12-05 23:39:00.003981 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 23:39:00.004040 | 2025-12-05 23:39:00.150960 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 23:39:00.151879 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 23:39:00.710798 | 2025-12-05 23:39:00.710902 | PLAY [all] 2025-12-05 23:39:00.731453 | 2025-12-05 23:39:00.731547 | TASK [Abort when test_command variable is undefined] 2025-12-05 23:39:00.766142 | controller | skipping: Conditional result was False 2025-12-05 23:39:00.771686 | 2025-12-05 23:39:00.771762 | TASK [Convert test_command to list] 2025-12-05 23:39:00.825694 | controller | skipping: Conditional result was False 2025-12-05 23:39:00.832305 | 2025-12-05 23:39:00.832371 | TASK [Use test_command list] 2025-12-05 23:39:00.881179 | controller | ok 2025-12-05 23:39:00.886547 | 2025-12-05 23:39:00.886608 | LOOP [Run test_command] 2025-12-05 23:39:01.299800 | controller | no check to run 2025-12-05 23:39:01.299984 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005942 2025-12-05 23:39:01.334287 | 2025-12-05 23:39:01.334380 | PLAY RECAP 2025-12-05 23:39:01.334434 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 23:39:01.334464 | 2025-12-05 23:39:01.426435 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 23:39:01.427259 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 23:39:01.985064 | 2025-12-05 23:39:01.985168 | PLAY [all] 2025-12-05 23:39:02.005011 | 2025-12-05 23:39:02.005089 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 23:39:02.367089 | controller | changed: non-zero return code 2025-12-05 23:39:02.373169 | 2025-12-05 23:39:02.373246 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 23:39:02.403030 | controller | skipping: Conditional result was False 2025-12-05 23:39:02.409165 | 2025-12-05 23:39:02.409236 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 23:39:02.439966 | 2025-12-05 23:39:02.440098 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 23:39:02.469735 | 2025-12-05 23:39:02.469884 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 23:39:02.504027 | controller | skipping: Conditional result was False 2025-12-05 23:39:02.509891 | 2025-12-05 23:39:02.509958 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 23:39:02.539613 | 2025-12-05 23:39:02.539735 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 23:39:02.565484 | controller | skipping: Conditional result was False 2025-12-05 23:39:02.570582 | 2025-12-05 23:39:02.570646 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 23:39:02.594201 | controller | skipping: Conditional result was False 2025-12-05 23:39:02.599504 | 2025-12-05 23:39:02.599567 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 23:39:02.613582 | controller | skipping: Conditional result was False 2025-12-05 23:39:02.640015 | 2025-12-05 23:39:02.640070 | PLAY RECAP 2025-12-05 23:39:02.640111 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 23:39:02.640131 | 2025-12-05 23:39:02.726870 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 23:39:02.727698 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 23:39:03.311419 | 2025-12-05 23:39:03.311526 | PLAY [all] 2025-12-05 23:39:03.331008 | 2025-12-05 23:39:03.331082 | TASK [include_role : fetch-output] 2025-12-05 23:39:03.370564 | controller | ok 2025-12-05 23:39:03.387444 | 2025-12-05 23:39:03.387522 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 23:39:03.431907 | controller | skipping: Conditional result was False 2025-12-05 23:39:03.437634 | 2025-12-05 23:39:03.437702 | TASK [fetch-output : Set log path for single node] 2025-12-05 23:39:03.475894 | controller | ok 2025-12-05 23:39:03.480980 | 2025-12-05 23:39:03.481047 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 23:39:03.849003 | controller -> localhost | ok: "/var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/logs" 2025-12-05 23:39:04.096608 | controller -> localhost | changed: "/var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/artifacts" 2025-12-05 23:39:04.322447 | controller -> localhost | changed: "/var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/docs" 2025-12-05 23:39:04.340104 | 2025-12-05 23:39:04.340278 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 23:39:05.006180 | controller | changed: .d..t...... ./ 2025-12-05 23:39:05.006387 | controller | changed: All items complete 2025-12-05 23:39:05.006415 | 2025-12-05 23:39:05.426344 | controller | changed: .d..t...... ./ 2025-12-05 23:39:05.884582 | controller | changed: .d..t...... ./ 2025-12-05 23:39:05.904055 | 2025-12-05 23:39:05.904217 | TASK [include_role : fetch-output-openshift] 2025-12-05 23:39:05.918556 | controller | skipping: Conditional result was False 2025-12-05 23:39:05.924352 | 2025-12-05 23:39:05.924434 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 23:39:06.303790 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008080 2025-12-05 23:39:06.515874 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007776 2025-12-05 23:39:06.547235 | 2025-12-05 23:39:06.547395 | PLAY [all] 2025-12-05 23:39:06.563960 | 2025-12-05 23:39:06.564026 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 23:39:07.063713 | controller | changed 2025-12-05 23:39:07.108207 | 2025-12-05 23:39:07.108315 | PLAY RECAP 2025-12-05 23:39:07.108366 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 23:39:07.108394 | 2025-12-05 23:39:07.231095 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 23:39:07.232271 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 23:39:07.838939 | 2025-12-05 23:39:07.839106 | PLAY [localhost] 2025-12-05 23:39:07.858772 | 2025-12-05 23:39:07.858928 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 23:39:08.186284 | localhost | changed 2025-12-05 23:39:08.191116 | 2025-12-05 23:39:08.191188 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 23:39:08.220591 | localhost | ok 2025-12-05 23:39:08.229061 | 2025-12-05 23:39:08.229163 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 23:39:08.557550 | localhost | changed 2025-12-05 23:39:08.564088 | 2025-12-05 23:39:08.564177 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 23:39:09.215049 | localhost | changed 2025-12-05 23:39:09.221170 | 2025-12-05 23:39:09.221325 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 23:39:09.648845 | localhost | Identity added: /var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/tmp/ansible._nuj_ssp (/var/lib/zuul/builds/dd47883310c4497db5adfd0b2c25fd39/work/tmp/ansible._nuj_ssp) 2025-12-05 23:39:09.649367 | localhost | ok: Runtime: 0:00:00.013241 2025-12-05 23:39:09.659542 | 2025-12-05 23:39:09.659683 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 23:39:09.914775 | localhost | ok: Runtime: 0:00:00.005635 2025-12-05 23:39:09.919668 | 2025-12-05 23:39:09.919756 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 23:39:09.984074 | localhost | changed 2025-12-05 23:39:09.994765 | 2025-12-05 23:39:09.994908 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 23:39:10.454908 | localhost | changed 2025-12-05 23:39:10.475223 | 2025-12-05 23:39:10.475289 | PLAY [localhost] 2025-12-05 23:39:10.486880 | 2025-12-05 23:39:10.486940 | TASK [Generate bulk log download script] 2025-12-05 23:39:10.509781 | localhost | ok 2025-12-05 23:39:10.521350 | 2025-12-05 23:39:10.521423 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 23:39:10.569819 | localhost | ok: All assertions passed 2025-12-05 23:39:10.574458 | 2025-12-05 23:39:10.574529 | TASK [local-log-download : Create download script] 2025-12-05 23:39:11.102511 | localhost -> localhost | changed 2025-12-05 23:39:11.111964 | 2025-12-05 23:39:11.112036 | TASK [Register quick-download link] 2025-12-05 23:39:11.140796 | localhost | ok 2025-12-05 23:39:11.191068 | 2025-12-05 23:39:11.191192 | PLAY [logserver.rdoproject.org] 2025-12-05 23:39:11.200704 | 2025-12-05 23:39:11.200778 | TASK [Set zuul-log-path fact] 2025-12-05 23:39:11.218552 | logserver.rdoproject.org | ok 2025-12-05 23:39:11.228216 | 2025-12-05 23:39:11.228296 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 23:39:11.265293 | logserver.rdoproject.org | ok 2025-12-05 23:39:11.270624 | 2025-12-05 23:39:11.270686 | TASK [upload-logs : Create log directories] 2025-12-05 23:39:12.012125 | logserver.rdoproject.org | changed 2025-12-05 23:39:12.020406 | 2025-12-05 23:39:12.020543 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 23:39:12.354037 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008632 2025-12-05 23:39:12.360966 | 2025-12-05 23:39:12.361047 | TASK [upload-logs : Upload logs to log server] 2025-12-05 23:39:13.015166 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 23:39:13.018203 | 2025-12-05 23:39:13.018265 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 23:39:13.086402 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 23:39:13.095870 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 23:39:13.107335 | 2025-12-05 23:39:13.107412 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 23:39:13.149101 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 23:39:13.149410 | 2025-12-05 23:39:13.152844 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 23:39:13.166779 | 2025-12-05 23:39:13.166857 | LOOP [upload-logs : Upload console log and json output]