2025-10-13 11:55:57.260103 | Job console starting... 2025-10-13 11:55:57.272312 | Updating repositories 2025-10-13 11:55:57.296331 | Preparing job workspace 2025-10-13 11:56:00.901286 | Running Ansible setup... 2025-10-13 11:56:05.021903 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 11:56:05.628308 | 2025-10-13 11:56:05.628428 | PLAY [localhost] 2025-10-13 11:56:05.637353 | 2025-10-13 11:56:05.637428 | TASK [Gathering Facts] 2025-10-13 11:56:06.560805 | localhost | ok 2025-10-13 11:56:06.575447 | 2025-10-13 11:56:06.575552 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 11:56:06.980346 | localhost -> localhost | changed 2025-10-13 11:56:06.986136 | 2025-10-13 11:56:06.986212 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 11:56:08.014097 | localhost -> localhost | changed 2025-10-13 11:56:08.025740 | 2025-10-13 11:56:08.025838 | TASK [Setup log path fact] 2025-10-13 11:56:08.056421 | localhost | ok 2025-10-13 11:56:08.068090 | 2025-10-13 11:56:08.068183 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 11:56:08.096662 | localhost | ok 2025-10-13 11:56:08.105236 | 2025-10-13 11:56:08.105322 | TASK [emit-job-header : Print job information] 2025-10-13 11:56:08.133855 | # Job Information 2025-10-13 11:56:08.134011 | Ansible Version: 2.15.12 2025-10-13 11:56:08.134048 | Job: cifmw-molecule-cifmw_nfs 2025-10-13 11:56:08.134069 | Pipeline: github-check 2025-10-13 11:56:08.134089 | Executor: ze03.softwarefactory-project.io 2025-10-13 11:56:08.134113 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402 2025-10-13 11:56:08.134140 | Log URL (when completed): https://logserver.rdoproject.org/3ac/rdoproject.org/3ac35110126b4fdb9e2765ff6f7301c8/ 2025-10-13 11:56:08.134167 | Event ID: 3d0bd0d0-a82b-11f0-9a9b-cd26fae28367 2025-10-13 11:56:08.138992 | 2025-10-13 11:56:08.139067 | LOOP [emit-job-header : Print node information] 2025-10-13 11:56:08.247437 | localhost | ok: 2025-10-13 11:56:08.247680 | localhost | # Node Information 2025-10-13 11:56:08.247710 | localhost | Inventory Hostname: controller 2025-10-13 11:56:08.247736 | localhost | Hostname: np0005484136 2025-10-13 11:56:08.247777 | localhost | Username: zuul 2025-10-13 11:56:08.247800 | localhost | Distro: CentOS 9 2025-10-13 11:56:08.247818 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 11:56:08.247836 | localhost | Region: RegionOne 2025-10-13 11:56:08.247852 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 11:56:08.247869 | localhost | Product Name: OpenStack Nova 2025-10-13 11:56:08.247885 | localhost | Interface IP: 38.102.83.248 2025-10-13 11:56:08.271061 | 2025-10-13 11:56:08.271165 | PLAY [all] 2025-10-13 11:56:08.285425 | 2025-10-13 11:56:08.285539 | TASK [Gather network facts] 2025-10-13 11:56:08.794787 | controller | ok 2025-10-13 11:56:08.822161 | 2025-10-13 11:56:08.822300 | TASK [include_role : start-zuul-console] 2025-10-13 11:56:08.849002 | controller | ok 2025-10-13 11:56:08.877445 | 2025-10-13 11:56:08.877577 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 11:56:09.363357 | controller | ok 2025-10-13 11:56:09.380714 | 2025-10-13 11:56:09.380814 | TASK [include_role : add-build-sshkey] 2025-10-13 11:56:09.438559 | controller | ok 2025-10-13 11:56:09.459609 | 2025-10-13 11:56:09.459691 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 11:56:09.990827 | controller -> localhost | ok 2025-10-13 11:56:09.997573 | 2025-10-13 11:56:09.997640 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 11:56:10.026443 | controller | ok 2025-10-13 11:56:10.039619 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 11:56:10.045325 | 2025-10-13 11:56:10.045400 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 11:56:10.862965 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 11:56:10.863290 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/3ac35110126b4fdb9e2765ff6f7301c8_id_rsa. 2025-10-13 11:56:10.863349 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/3ac35110126b4fdb9e2765ff6f7301c8_id_rsa.pub. 2025-10-13 11:56:10.863381 | controller -> localhost | The key fingerprint is: 2025-10-13 11:56:10.863408 | controller -> localhost | SHA256:K5463l/wYc7rsfUsMKok8BqC39izg4B4CzGfVEEM+zI zuul-build-sshkey 2025-10-13 11:56:10.863433 | controller -> localhost | The key's randomart image is: 2025-10-13 11:56:10.863457 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 11:56:10.863481 | controller -> localhost | | .+o. | 2025-10-13 11:56:10.863505 | controller -> localhost | | .o | 2025-10-13 11:56:10.863529 | controller -> localhost | | .. | 2025-10-13 11:56:10.863554 | controller -> localhost | |o .. | 2025-10-13 11:56:10.863578 | controller -> localhost | |o=E.. S o | 2025-10-13 11:56:10.863603 | controller -> localhost | |* += Bo. | 2025-10-13 11:56:10.863629 | controller -> localhost | |o+.oo o ..*o. | 2025-10-13 11:56:10.863657 | controller -> localhost | | oo*+= o.. =.o | 2025-10-13 11:56:10.863680 | controller -> localhost | | +.**=o..+ .o | 2025-10-13 11:56:10.863701 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 11:56:10.863766 | controller -> localhost | ok: Runtime: 0:00:00.316092 2025-10-13 11:56:10.869644 | 2025-10-13 11:56:10.869708 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 11:56:10.921021 | controller | ok 2025-10-13 11:56:10.934075 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 11:56:10.944638 | 2025-10-13 11:56:10.944759 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 11:56:10.976794 | controller | skipping: Conditional result was False 2025-10-13 11:56:10.982813 | 2025-10-13 11:56:10.982895 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 11:56:11.566845 | controller | changed 2025-10-13 11:56:11.574971 | 2025-10-13 11:56:11.575099 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 11:56:11.832161 | controller | ok 2025-10-13 11:56:11.847470 | 2025-10-13 11:56:11.847600 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 11:56:12.779120 | controller | changed 2025-10-13 11:56:12.786718 | 2025-10-13 11:56:12.786860 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 11:56:13.693675 | controller | changed 2025-10-13 11:56:13.701584 | 2025-10-13 11:56:13.701685 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 11:56:13.717497 | controller | skipping: Conditional result was False 2025-10-13 11:56:13.726265 | 2025-10-13 11:56:13.726363 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 11:56:14.118066 | controller -> localhost | changed 2025-10-13 11:56:14.133857 | 2025-10-13 11:56:14.133979 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 11:56:14.404168 | controller -> localhost | Identity added: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/3ac35110126b4fdb9e2765ff6f7301c8_id_rsa (zuul-build-sshkey) 2025-10-13 11:56:14.404340 | controller -> localhost | ok: Runtime: 0:00:00.008926 2025-10-13 11:56:14.410617 | 2025-10-13 11:56:14.410681 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 11:56:14.902257 | controller | ok 2025-10-13 11:56:14.914173 | 2025-10-13 11:56:14.914294 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 11:56:14.988476 | controller | skipping: Conditional result was False 2025-10-13 11:56:15.017325 | 2025-10-13 11:56:15.017479 | TASK [include_role : validate-host] 2025-10-13 11:56:15.090536 | controller | ok 2025-10-13 11:56:15.129650 | 2025-10-13 11:56:15.129826 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 11:56:15.171673 | controller | ok 2025-10-13 11:56:15.179676 | 2025-10-13 11:56:15.179822 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 11:56:15.470489 | controller -> localhost | ok 2025-10-13 11:56:15.497822 | 2025-10-13 11:56:15.497938 | TASK [validate-host : Collect information about the host] 2025-10-13 11:56:16.319581 | controller | ok 2025-10-13 11:56:16.327812 | 2025-10-13 11:56:16.327873 | TASK [validate-host : Sanitize hostname] 2025-10-13 11:56:16.386634 | controller | ok 2025-10-13 11:56:16.391612 | 2025-10-13 11:56:16.391673 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 11:56:16.855140 | controller -> localhost | changed 2025-10-13 11:56:16.863535 | 2025-10-13 11:56:16.863635 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 11:56:17.347594 | controller | ok 2025-10-13 11:56:17.353061 | 2025-10-13 11:56:17.353137 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 11:56:17.803342 | controller -> localhost | changed 2025-10-13 11:56:17.814329 | 2025-10-13 11:56:17.814401 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 11:56:17.828347 | controller | skipping: Conditional result was False 2025-10-13 11:56:17.834559 | 2025-10-13 11:56:17.834637 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 11:56:17.859175 | controller | skipping: Conditional result was False 2025-10-13 11:56:17.865816 | 2025-10-13 11:56:17.865936 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 11:56:18.153313 | controller | ok: "logs" 2025-10-13 11:56:18.153561 | controller | ok: All items complete 2025-10-13 11:56:18.153591 | 2025-10-13 11:56:18.422870 | controller | ok: "artifacts" 2025-10-13 11:56:18.687088 | controller | ok: "docs" 2025-10-13 11:56:18.699194 | 2025-10-13 11:56:18.699315 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 11:56:18.976632 | controller | changed: "logs" 2025-10-13 11:56:19.240868 | controller | changed: "artifacts" 2025-10-13 11:56:19.484349 | controller | changed: "docs" 2025-10-13 11:56:19.553414 | 2025-10-13 11:56:19.553515 | PLAY RECAP 2025-10-13 11:56:19.553557 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 11:56:19.553582 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 11:56:19.553600 | 2025-10-13 11:56:19.700562 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 11:56:19.701402 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 11:56:20.353286 | 2025-10-13 11:56:20.353398 | PLAY [localhost] 2025-10-13 11:56:20.369200 | 2025-10-13 11:56:20.369273 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 11:56:20.844079 | localhost | ok 2025-10-13 11:56:20.849169 | 2025-10-13 11:56:20.849242 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 11:56:21.538152 | localhost | changed 2025-10-13 11:56:21.566991 | 2025-10-13 11:56:21.567102 | PLAY [all] 2025-10-13 11:56:21.600237 | 2025-10-13 11:56:21.600361 | TASK [include_role : prepare-workspace] 2025-10-13 11:56:21.619950 | controller | ok 2025-10-13 11:56:21.635819 | 2025-10-13 11:56:21.635946 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 11:56:22.045480 | controller | ok 2025-10-13 11:56:22.055374 | 2025-10-13 11:56:22.055478 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 11:56:23.752113 | controller | Output suppressed because no_log was given 2025-10-13 11:56:23.782375 | 2025-10-13 11:56:23.782474 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 11:56:24.068276 | controller | changed: "logs" 2025-10-13 11:56:24.300999 | controller | changed: "artifacts" 2025-10-13 11:56:24.553740 | controller | changed: "docs" 2025-10-13 11:56:24.573356 | 2025-10-13 11:56:24.573505 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 11:56:24.911563 | controller | changed: "logs" 2025-10-13 11:56:24.911840 | controller | changed: All items complete 2025-10-13 11:56:24.911867 | 2025-10-13 11:56:25.204467 | controller | changed: "artifacts" 2025-10-13 11:56:25.462194 | controller | changed: "docs" 2025-10-13 11:56:25.513536 | 2025-10-13 11:56:25.513687 | TASK [Check if worker can sudo] 2025-10-13 11:56:26.552067 | controller | ok: Runtime: 0:00:00.061187 2025-10-13 11:56:26.558126 | 2025-10-13 11:56:26.558244 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 11:56:26.602659 | controller | skipping: Conditional result was False 2025-10-13 11:56:26.609040 | 2025-10-13 11:56:26.609126 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 11:56:26.672138 | controller | ok 2025-10-13 11:56:26.679789 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 11:56:26.717509 | 2025-10-13 11:56:26.717623 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 11:56:27.007428 | controller | ok 2025-10-13 11:56:27.013542 | 2025-10-13 11:56:27.013617 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 11:56:27.072283 | controller | ok: "/var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 11:56:27.087996 | 2025-10-13 11:56:27.088125 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 11:56:28.116076 | controller | changed 2025-10-13 11:56:28.121412 | 2025-10-13 11:56:28.121473 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 11:56:28.192418 | controller | ok: "/var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 11:56:28.192574 | controller | ok: All items complete 2025-10-13 11:56:28.192600 | 2025-10-13 11:56:28.234500 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 11:56:28.240906 | 2025-10-13 11:56:28.240968 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 11:56:29.321185 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 11:56:30.286030 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 11:56:30.303534 | 2025-10-13 11:56:30.303652 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 11:56:30.863666 | controller | changed: section and option added 2025-10-13 11:56:30.885843 | 2025-10-13 11:56:30.885933 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 11:56:31.707544 | controller | 29 files removed 2025-10-13 11:56:31.707771 | controller | ok: Item: dnf clean all Runtime: 0:00:00.475547 2025-10-13 11:56:31.707815 | controller | changed: All items complete 2025-10-13 11:56:31.707837 | 2025-10-13 11:56:42.259796 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, notify-packagekit, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-10-13 11:56:42.259941 | controller | DNF version: 4.14.0 2025-10-13 11:56:42.259988 | controller | cachedir: /var/cache/dnf 2025-10-13 11:56:42.260028 | controller | Making cache files for all metadata files. 2025-10-13 11:56:42.260067 | controller | baseos: has expired and will be refreshed. 2025-10-13 11:56:42.260100 | controller | appstream: has expired and will be refreshed. 2025-10-13 11:56:42.260131 | controller | crb: has expired and will be refreshed. 2025-10-13 11:56:42.261175 | controller | extras-common: has expired and will be refreshed. 2025-10-13 11:56:42.261294 | controller | repo: downloading from remote: baseos 2025-10-13 11:56:42.261318 | controller | CentOS Stream 9 - BaseOS 64 MB/s | 8.8 MB 00:00 2025-10-13 11:56:42.261337 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 11:56:42.261355 | controller | repo: downloading from remote: appstream 2025-10-13 11:56:42.261372 | controller | CentOS Stream 9 - AppStream 92 MB/s | 25 MB 00:00 2025-10-13 11:56:42.261390 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 11:56:42.261409 | controller | repo: downloading from remote: crb 2025-10-13 11:56:42.261426 | controller | CentOS Stream 9 - CRB 88 MB/s | 7.2 MB 00:00 2025-10-13 11:56:42.261443 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 11:56:42.261460 | controller | repo: downloading from remote: extras-common 2025-10-13 11:56:42.261476 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-10-13 11:56:42.261492 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 11:56:42.261508 | controller | Last metadata expiration check: 0:00:01 ago on Mon 13 Oct 2025 07:56:40 AM EDT. 2025-10-13 11:56:42.261525 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 11:56:42.261541 | controller | Completion plugin: Generating completion cache... 2025-10-13 11:56:42.261558 | controller | Metadata cache created. 2025-10-13 11:56:42.261593 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.266549 2025-10-13 11:56:42.281308 | 2025-10-13 11:56:42.281401 | PLAY RECAP 2025-10-13 11:56:42.281441 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 11:56:42.281466 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 11:56:42.281484 | 2025-10-13 11:56:42.390283 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 11:56:42.391241 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 11:56:43.013563 | 2025-10-13 11:56:43.013675 | PLAY [all] 2025-10-13 11:56:43.035200 | 2025-10-13 11:56:43.035285 | TASK [Install binary dependencies] 2025-10-13 11:56:43.074960 | controller | ok 2025-10-13 11:56:43.100691 | 2025-10-13 11:56:43.100820 | TASK [bindep : Include find tasks] 2025-10-13 11:56:43.129959 | controller | ok 2025-10-13 11:56:43.141369 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 11:56:43.147429 | 2025-10-13 11:56:43.147495 | TASK [bindep : Look for bindep.txt] 2025-10-13 11:56:43.553507 | controller | ok 2025-10-13 11:56:43.561849 | 2025-10-13 11:56:43.561986 | TASK [bindep : Define bindep_file fact] 2025-10-13 11:56:43.591470 | controller | ok 2025-10-13 11:56:43.596665 | 2025-10-13 11:56:43.596749 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 11:56:43.612640 | controller | skipping: Conditional result was False 2025-10-13 11:56:43.620829 | 2025-10-13 11:56:43.620946 | TASK [bindep : Define bindep_file fact] 2025-10-13 11:56:43.645315 | controller | skipping: Conditional result was False 2025-10-13 11:56:43.651126 | 2025-10-13 11:56:43.651204 | TASK [bindep : Look for bindep fallback file] 2025-10-13 11:56:43.675765 | controller | skipping: Conditional result was False 2025-10-13 11:56:43.682394 | 2025-10-13 11:56:43.682500 | TASK [bindep : Define bindep_file fact] 2025-10-13 11:56:43.707661 | controller | skipping: Conditional result was False 2025-10-13 11:56:43.713801 | 2025-10-13 11:56:43.714054 | TASK [bindep : Include bindep tasks] 2025-10-13 11:56:43.744096 | controller | ok 2025-10-13 11:56:43.751613 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 11:56:43.760160 | 2025-10-13 11:56:43.760248 | TASK [bindep : Look for bindep command] 2025-10-13 11:56:43.784019 | controller | skipping: Conditional result was False 2025-10-13 11:56:43.790481 | 2025-10-13 11:56:43.790575 | TASK [bindep : Check for system bindep] 2025-10-13 11:56:44.322186 | controller | ok: Runtime: 0:00:00.004695 2025-10-13 11:56:44.327794 | 2025-10-13 11:56:44.327868 | TASK [bindep : Define bindep_command fact] 2025-10-13 11:56:44.353354 | controller | skipping: Conditional result was False 2025-10-13 11:56:44.359643 | 2025-10-13 11:56:44.359759 | TASK [bindep : Include install tasks] 2025-10-13 11:56:44.394061 | controller | ok 2025-10-13 11:56:44.401263 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 11:56:44.412778 | 2025-10-13 11:56:44.412862 | TASK [bindep : Create temp dir for bindep] 2025-10-13 11:56:44.779939 | controller | changed 2025-10-13 11:56:44.785162 | 2025-10-13 11:56:44.785226 | TASK [Ensure we have pip dependencies] 2025-10-13 11:56:44.804418 | controller | ok 2025-10-13 11:56:44.829307 | 2025-10-13 11:56:44.829426 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 07:56:45.155907 | controller | /usr/bin/pip3 2025-10-13 07:56:45.196793 | controller | /usr/bin/python3: No module named wheel 2025-10-13 11:56:45.370610 | controller | ok: Runtime: 0:00:00.055315 2025-10-13 11:56:45.379530 | 2025-10-13 11:56:45.379665 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 11:56:45.410316 | controller | ok: "/var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 11:56:45.431205 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 11:56:45.444111 | 2025-10-13 11:56:45.444235 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 11:56:47.785476 | controller | changed 2025-10-13 11:56:47.791351 | 2025-10-13 11:56:47.791427 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 11:56:47.825741 | controller | skipping: Conditional result was False 2025-10-13 11:56:47.837979 | 2025-10-13 11:56:47.838105 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 11:56:47.872915 | controller | skipping: Conditional result was False 2025-10-13 11:56:47.880819 | 2025-10-13 11:56:47.880929 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 11:56:47.926824 | controller | skipping: Conditional result was False 2025-10-13 11:56:47.934027 | 2025-10-13 11:56:47.934103 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 11:56:47.948175 | controller | skipping: Conditional result was False 2025-10-13 11:56:47.954605 | 2025-10-13 11:56:47.954677 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 11:56:47.992065 | controller | skipping: Conditional result was False 2025-10-13 11:56:47.998112 | 2025-10-13 11:56:47.998231 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 11:56:48.012109 | controller | skipping: Conditional result was False 2025-10-13 11:56:48.019320 | 2025-10-13 11:56:48.019408 | TASK [ensure-pip : Install pip from source] 2025-10-13 11:56:48.043937 | controller | skipping: Conditional result was False 2025-10-13 11:56:48.049964 | 2025-10-13 11:56:48.050054 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 07:56:48.331206 | controller | /usr/bin/python3 2025-10-13 11:56:48.587294 | controller | ok: Runtime: 0:00:00.007555 2025-10-13 11:56:48.597653 | 2025-10-13 11:56:48.597777 | TASK [ensure-pip : Set host default] 2025-10-13 11:56:48.678543 | controller | ok 2025-10-13 11:56:48.683788 | 2025-10-13 11:56:48.683870 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 11:56:48.745008 | controller | ok 2025-10-13 11:56:48.755477 | 2025-10-13 11:56:48.755548 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 11:56:52.938516 | controller | changed 2025-10-13 11:56:52.943967 | 2025-10-13 11:56:52.944028 | TASK [bindep : Define bindep_command] 2025-10-13 11:56:52.974016 | controller | ok 2025-10-13 11:56:52.979150 | 2025-10-13 11:56:52.979212 | LOOP [bindep : Include package tasks] 2025-10-13 11:56:53.089473 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 11:56:53.089636 | controller | ok: All items complete 2025-10-13 11:56:53.089661 | 2025-10-13 11:56:53.102672 | controller | included: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 11:56:53.115076 | 2025-10-13 11:56:53.115190 | TASK [bindep : Define bindep_run fact] 2025-10-13 11:56:53.144691 | controller | ok 2025-10-13 11:56:53.149794 | 2025-10-13 11:56:53.149873 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 07:56:54.514414 | controller | podman 2025-10-13 07:56:54.557364 | controller | python3-jmespath 2025-10-13 07:56:54.557586 | controller | python3-libvirt 2025-10-13 07:56:54.557600 | controller | python3-lxml 2025-10-13 07:56:54.557611 | controller | python3-netaddr 2025-10-13 11:56:54.683019 | controller | ok: Runtime: 0:00:01.138099 2025-10-13 11:56:54.689171 | 2025-10-13 11:56:54.689252 | TASK [bindep : Install distro packages from bindep] 2025-10-13 11:57:55.815467 | controller | changed 2025-10-13 11:57:55.820883 | 2025-10-13 11:57:55.820946 | TASK [bindep : Check that packages are installed] 2025-10-13 11:57:57.359001 | controller | ok: Runtime: 0:00:01.009721 2025-10-13 11:57:57.375656 | 2025-10-13 11:57:57.375821 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 11:57:57.413916 | controller | skipping: Conditional result was False 2025-10-13 11:57:57.440319 | 2025-10-13 11:57:57.440426 | TASK [Run test-setup role] 2025-10-13 11:57:57.461090 | controller | ok 2025-10-13 11:57:57.483810 | 2025-10-13 11:57:57.483898 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 11:57:57.737343 | controller | ok 2025-10-13 11:57:57.743178 | 2025-10-13 11:57:57.743238 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 11:57:58.284896 | controller | skipping: Conditional result was False 2025-10-13 11:57:58.304414 | 2025-10-13 11:57:58.304486 | TASK [bindep : Remove bindep temp dir] 2025-10-13 11:57:58.669977 | controller | ok 2025-10-13 11:57:58.692022 | 2025-10-13 11:57:58.692091 | PLAY RECAP 2025-10-13 11:57:58.692144 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 11:57:58.692171 | 2025-10-13 11:57:58.813610 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 11:57:58.814464 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 11:57:59.398281 | 2025-10-13 11:57:59.398394 | PLAY [all] 2025-10-13 11:57:59.417376 | 2025-10-13 11:57:59.417453 | TASK [Abort when test_command variable is undefined] 2025-10-13 11:57:59.450406 | controller | skipping: Conditional result was False 2025-10-13 11:57:59.455766 | 2025-10-13 11:57:59.455838 | TASK [Convert test_command to list] 2025-10-13 11:57:59.499092 | controller | skipping: Conditional result was False 2025-10-13 11:57:59.505185 | 2025-10-13 11:57:59.505248 | TASK [Use test_command list] 2025-10-13 11:57:59.559297 | controller | ok 2025-10-13 11:57:59.570381 | 2025-10-13 11:57:59.570504 | LOOP [Run test_command] 2025-10-13 11:57:59.993283 | controller | no check to run 2025-10-13 11:57:59.993622 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004703 2025-10-13 11:58:00.015074 | 2025-10-13 11:58:00.015184 | PLAY RECAP 2025-10-13 11:58:00.015227 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 11:58:00.015256 | 2025-10-13 11:58:00.126441 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 11:58:00.127294 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 11:58:00.647567 | 2025-10-13 11:58:00.647670 | PLAY [all] 2025-10-13 11:58:00.668015 | 2025-10-13 11:58:00.668091 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 11:58:01.060403 | controller | changed: non-zero return code 2025-10-13 11:58:01.071955 | 2025-10-13 11:58:01.072117 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 11:58:01.089573 | controller | skipping: Conditional result was False 2025-10-13 11:58:01.102653 | 2025-10-13 11:58:01.102831 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 11:58:01.137543 | 2025-10-13 11:58:01.137744 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 11:58:01.170863 | 2025-10-13 11:58:01.171064 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 11:58:01.196001 | controller | skipping: Conditional result was False 2025-10-13 11:58:01.205816 | 2025-10-13 11:58:01.205924 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 11:58:01.231595 | 2025-10-13 11:58:01.231838 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 11:58:01.247219 | controller | skipping: Conditional result was False 2025-10-13 11:58:01.256835 | 2025-10-13 11:58:01.256947 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 11:58:01.275403 | controller | skipping: Conditional result was False 2025-10-13 11:58:01.281355 | 2025-10-13 11:58:01.281422 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 11:58:01.305332 | controller | skipping: Conditional result was False 2025-10-13 11:58:01.346903 | 2025-10-13 11:58:01.346956 | PLAY RECAP 2025-10-13 11:58:01.346995 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 11:58:01.347014 | 2025-10-13 11:58:01.482755 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 11:58:01.483516 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 11:58:02.123794 | 2025-10-13 11:58:02.123899 | PLAY [all] 2025-10-13 11:58:02.146626 | 2025-10-13 11:58:02.146700 | TASK [include_role : fetch-output] 2025-10-13 11:58:02.175346 | controller | ok 2025-10-13 11:58:02.200968 | 2025-10-13 11:58:02.201059 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 11:58:02.255040 | controller | skipping: Conditional result was False 2025-10-13 11:58:02.260467 | 2025-10-13 11:58:02.260531 | TASK [fetch-output : Set log path for single node] 2025-10-13 11:58:02.288482 | controller | ok 2025-10-13 11:58:02.294599 | 2025-10-13 11:58:02.294662 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 11:58:02.693465 | controller -> localhost | ok: "/var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/logs" 2025-10-13 11:58:02.900449 | controller -> localhost | changed: "/var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/artifacts" 2025-10-13 11:58:03.086778 | controller -> localhost | changed: "/var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/docs" 2025-10-13 11:58:03.098317 | 2025-10-13 11:58:03.101941 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 11:58:03.758987 | controller | changed: .d..t...... ./ 2025-10-13 11:58:03.768853 | controller | changed: All items complete 2025-10-13 11:58:03.768903 | 2025-10-13 11:58:04.205309 | controller | changed: .d..t...... ./ 2025-10-13 11:58:04.705472 | controller | changed: .d..t...... ./ 2025-10-13 11:58:04.732179 | 2025-10-13 11:58:04.732249 | TASK [include_role : fetch-output-openshift] 2025-10-13 11:58:04.755375 | controller | skipping: Conditional result was False 2025-10-13 11:58:04.765942 | 2025-10-13 11:58:04.766006 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 11:58:05.238632 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007870 2025-10-13 11:58:05.466614 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007754 2025-10-13 11:58:05.512008 | 2025-10-13 11:58:05.512117 | PLAY [all] 2025-10-13 11:58:05.540387 | 2025-10-13 11:58:05.540514 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 11:58:06.019922 | controller | changed 2025-10-13 11:58:06.048172 | 2025-10-13 11:58:06.048238 | PLAY RECAP 2025-10-13 11:58:06.048277 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 11:58:06.048297 | 2025-10-13 11:58:06.144295 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 11:58:06.145181 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 11:58:06.710958 | 2025-10-13 11:58:06.711085 | PLAY [localhost] 2025-10-13 11:58:06.728961 | 2025-10-13 11:58:06.729046 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 11:58:07.081415 | localhost | changed 2025-10-13 11:58:07.087653 | 2025-10-13 11:58:07.087786 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 11:58:07.108791 | localhost | ok 2025-10-13 11:58:07.119451 | 2025-10-13 11:58:07.119542 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 11:58:07.468570 | localhost | changed 2025-10-13 11:58:07.479127 | 2025-10-13 11:58:07.479273 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 11:58:08.166005 | localhost | changed 2025-10-13 11:58:08.171076 | 2025-10-13 11:58:08.171137 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 11:58:08.669388 | localhost | Identity added: /var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/tmp/ansible.gdkb67_d (/var/lib/zuul/builds/3ac35110126b4fdb9e2765ff6f7301c8/work/tmp/ansible.gdkb67_d) 2025-10-13 11:58:08.669605 | localhost | ok: Runtime: 0:00:00.012604 2025-10-13 11:58:08.675968 | 2025-10-13 11:58:08.676053 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 11:58:09.009765 | localhost | ok: Runtime: 0:00:00.006463 2025-10-13 11:58:09.016477 | 2025-10-13 11:58:09.016569 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 11:58:09.075316 | localhost | changed 2025-10-13 11:58:09.079627 | 2025-10-13 11:58:09.079693 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 11:58:09.523229 | localhost | changed 2025-10-13 11:58:09.561311 | 2025-10-13 11:58:09.561431 | PLAY [localhost] 2025-10-13 11:58:09.574011 | 2025-10-13 11:58:09.574083 | TASK [Generate bulk log download script] 2025-10-13 11:58:09.591944 | localhost | ok 2025-10-13 11:58:09.603880 | 2025-10-13 11:58:09.604009 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 11:58:09.632691 | localhost | ok: All assertions passed 2025-10-13 11:58:09.637405 | 2025-10-13 11:58:09.637466 | TASK [local-log-download : Create download script] 2025-10-13 11:58:09.998632 | localhost -> localhost | changed 2025-10-13 11:58:10.009256 | 2025-10-13 11:58:10.009345 | TASK [Register quick-download link] 2025-10-13 11:58:10.028050 | localhost | ok 2025-10-13 11:58:10.077037 | 2025-10-13 11:58:10.077169 | PLAY [logserver.rdoproject.org] 2025-10-13 11:58:10.087278 | 2025-10-13 11:58:10.087356 | TASK [Set zuul-log-path fact] 2025-10-13 11:58:10.104623 | logserver.rdoproject.org | ok 2025-10-13 11:58:10.116046 | 2025-10-13 11:58:10.116134 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 11:58:10.143247 | logserver.rdoproject.org | ok 2025-10-13 11:58:10.151670 | 2025-10-13 11:58:10.151755 | TASK [upload-logs : Create log directories] 2025-10-13 11:58:10.781226 | logserver.rdoproject.org | changed 2025-10-13 11:58:10.785620 | 2025-10-13 11:58:10.785704 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 11:58:11.047110 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008811 2025-10-13 11:58:11.052002 | 2025-10-13 11:58:11.052083 | TASK [upload-logs : Upload logs to log server] 2025-10-13 11:58:11.668196 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 11:58:11.674604 | 2025-10-13 11:58:11.674770 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 11:58:11.750196 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 11:58:11.751255 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 11:58:11.761105 | 2025-10-13 11:58:11.761222 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 11:58:11.801026 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 11:58:11.801265 | 2025-10-13 11:58:11.801787 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 11:58:11.808032 | 2025-10-13 11:58:11.808150 | LOOP [upload-logs : Upload console log and json output]