2025-10-03 09:59:51.123521 | Job console starting... 2025-10-03 09:59:51.136127 | Updating repositories 2025-10-03 09:59:51.163240 | Preparing job workspace 2025-10-03 09:59:56.079332 | Running Ansible setup... 2025-10-03 10:00:00.213306 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 10:00:02.584360 | 2025-10-03 10:00:02.584509 | PLAY [localhost] 2025-10-03 10:00:02.611651 | 2025-10-03 10:00:02.611778 | TASK [Gathering Facts] 2025-10-03 10:00:03.756710 | localhost | ok 2025-10-03 10:00:03.771454 | 2025-10-03 10:00:03.771573 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-03 10:00:04.161596 | localhost -> localhost | changed 2025-10-03 10:00:04.168150 | 2025-10-03 10:00:04.168571 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-03 10:00:05.141503 | localhost -> localhost | changed 2025-10-03 10:00:05.157518 | 2025-10-03 10:00:05.157728 | TASK [Setup log path fact] 2025-10-03 10:00:05.176161 | localhost | ok 2025-10-03 10:00:05.188646 | 2025-10-03 10:00:05.188766 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 10:00:05.226597 | localhost | ok 2025-10-03 10:00:05.234703 | 2025-10-03 10:00:05.234786 | TASK [emit-job-header : Print job information] 2025-10-03 10:00:05.263466 | # Job Information 2025-10-03 10:00:05.263707 | Ansible Version: 2.15.12 2025-10-03 10:00:05.263742 | Job: cifmw-molecule-cleanup_openstack 2025-10-03 10:00:05.263763 | Pipeline: github-check 2025-10-03 10:00:05.263782 | Executor: ze01.softwarefactory-project.io 2025-10-03 10:00:05.263799 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-03 10:00:05.263818 | Log URL (when completed): https://logserver.rdoproject.org/5bb/rdoproject.org/5bb8a26f7a2a4198be8831a24f79a023/ 2025-10-03 10:00:05.263836 | Event ID: 79314020-a03f-11f0-87f2-6df8ed647fba 2025-10-03 10:00:05.267837 | 2025-10-03 10:00:05.267910 | LOOP [emit-job-header : Print node information] 2025-10-03 10:00:05.379109 | localhost | ok: 2025-10-03 10:00:05.379271 | localhost | # Node Information 2025-10-03 10:00:05.379299 | localhost | Inventory Hostname: controller 2025-10-03 10:00:05.379321 | localhost | Hostname: np0005468514 2025-10-03 10:00:05.379340 | localhost | Username: zuul 2025-10-03 10:00:05.379360 | localhost | Distro: CentOS 9 2025-10-03 10:00:05.379378 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-03 10:00:05.379396 | localhost | Region: RegionOne 2025-10-03 10:00:05.379415 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-03 10:00:05.379433 | localhost | Product Name: OpenStack Nova 2025-10-03 10:00:05.379451 | localhost | Interface IP: 38.129.56.161 2025-10-03 10:00:05.405564 | 2025-10-03 10:00:05.405653 | PLAY [all] 2025-10-03 10:00:05.415605 | 2025-10-03 10:00:05.415726 | TASK [Gather network facts] 2025-10-03 10:00:05.930578 | controller | ok 2025-10-03 10:00:05.951088 | 2025-10-03 10:00:05.951207 | TASK [include_role : start-zuul-console] 2025-10-03 10:00:05.993211 | controller | ok 2025-10-03 10:00:06.006560 | 2025-10-03 10:00:06.006669 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-03 10:00:06.417767 | controller | ok 2025-10-03 10:00:06.428041 | 2025-10-03 10:00:06.428130 | TASK [include_role : add-build-sshkey] 2025-10-03 10:00:06.478339 | controller | ok 2025-10-03 10:00:06.501116 | 2025-10-03 10:00:06.501203 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-03 10:00:06.814260 | controller -> localhost | ok 2025-10-03 10:00:06.821376 | 2025-10-03 10:00:06.821488 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-03 10:00:06.850038 | controller | ok 2025-10-03 10:00:06.873969 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-03 10:00:06.890091 | 2025-10-03 10:00:06.890205 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-03 10:00:07.746311 | controller -> localhost | Generating public/private rsa key pair. 2025-10-03 10:00:07.746529 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/5bb8a26f7a2a4198be8831a24f79a023_id_rsa. 2025-10-03 10:00:07.746561 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/5bb8a26f7a2a4198be8831a24f79a023_id_rsa.pub. 2025-10-03 10:00:07.746584 | controller -> localhost | The key fingerprint is: 2025-10-03 10:00:07.746604 | controller -> localhost | SHA256:EyflZdVdZqNld4XTYyFw4/HW9h6H0V92+7GMataVno0 zuul-build-sshkey 2025-10-03 10:00:07.746624 | controller -> localhost | The key's randomart image is: 2025-10-03 10:00:07.746643 | controller -> localhost | +---[RSA 3072]----+ 2025-10-03 10:00:07.746661 | controller -> localhost | | ..+*.O%| 2025-10-03 10:00:07.746679 | controller -> localhost | | o oo @*O| 2025-10-03 10:00:07.746698 | controller -> localhost | | o o oo+O| 2025-10-03 10:00:07.746716 | controller -> localhost | | + .=*| 2025-10-03 10:00:07.746733 | controller -> localhost | | S .+=| 2025-10-03 10:00:07.746751 | controller -> localhost | | . o+*| 2025-10-03 10:00:07.746769 | controller -> localhost | | ..o+=| 2025-10-03 10:00:07.746787 | controller -> localhost | | o..Eo.| 2025-10-03 10:00:07.746805 | controller -> localhost | | o. | 2025-10-03 10:00:07.746823 | controller -> localhost | +----[SHA256]-----+ 2025-10-03 10:00:07.746872 | controller -> localhost | ok: Runtime: 0:00:00.298676 2025-10-03 10:00:07.752633 | 2025-10-03 10:00:07.752693 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-03 10:00:07.784167 | controller | ok 2025-10-03 10:00:07.802161 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-03 10:00:07.822825 | 2025-10-03 10:00:07.822939 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-03 10:00:07.847789 | controller | skipping: Conditional result was False 2025-10-03 10:00:07.857806 | 2025-10-03 10:00:07.857958 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-03 10:00:08.559862 | controller | changed 2025-10-03 10:00:08.565919 | 2025-10-03 10:00:08.565987 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-03 10:00:08.852544 | controller | ok 2025-10-03 10:00:08.857337 | 2025-10-03 10:00:08.857396 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-03 10:00:09.701614 | controller | changed 2025-10-03 10:00:09.722732 | 2025-10-03 10:00:09.722848 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-03 10:00:10.720347 | controller | changed 2025-10-03 10:00:10.726939 | 2025-10-03 10:00:10.727062 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-03 10:00:10.792279 | controller | skipping: Conditional result was False 2025-10-03 10:00:10.798878 | 2025-10-03 10:00:10.798988 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-03 10:00:11.634515 | controller -> localhost | changed 2025-10-03 10:00:11.647096 | 2025-10-03 10:00:11.647222 | TASK [add-build-sshkey : Add back temp key] 2025-10-03 10:00:12.373611 | controller -> localhost | Identity added: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/5bb8a26f7a2a4198be8831a24f79a023_id_rsa (zuul-build-sshkey) 2025-10-03 10:00:12.373849 | controller -> localhost | ok: Runtime: 0:00:00.010247 2025-10-03 10:00:12.396840 | 2025-10-03 10:00:12.397215 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-03 10:00:12.953969 | controller | ok 2025-10-03 10:00:12.960390 | 2025-10-03 10:00:12.960470 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-03 10:00:12.986683 | controller | skipping: Conditional result was False 2025-10-03 10:00:13.002602 | 2025-10-03 10:00:13.002713 | TASK [include_role : validate-host] 2025-10-03 10:00:13.031222 | controller | ok 2025-10-03 10:00:13.059431 | 2025-10-03 10:00:13.059560 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-03 10:00:13.155208 | controller | ok 2025-10-03 10:00:13.170060 | 2025-10-03 10:00:13.170173 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-03 10:00:13.417953 | controller -> localhost | ok 2025-10-03 10:00:13.424070 | 2025-10-03 10:00:13.424149 | TASK [validate-host : Collect information about the host] 2025-10-03 10:00:14.198868 | controller | ok 2025-10-03 10:00:14.209232 | 2025-10-03 10:00:14.209347 | TASK [validate-host : Sanitize hostname] 2025-10-03 10:00:14.263222 | controller | ok 2025-10-03 10:00:14.268385 | 2025-10-03 10:00:14.268450 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-03 10:00:14.806343 | controller -> localhost | changed 2025-10-03 10:00:14.812003 | 2025-10-03 10:00:14.812103 | TASK [validate-host : Collect information about zuul worker] 2025-10-03 10:00:15.278944 | controller | ok 2025-10-03 10:00:15.286906 | 2025-10-03 10:00:15.287061 | TASK [validate-host : Write out all zuul information for each host] 2025-10-03 10:00:15.791449 | controller -> localhost | changed 2025-10-03 10:00:15.803204 | 2025-10-03 10:00:15.803318 | TASK [include_role : prepare-workspace-openshift] 2025-10-03 10:00:15.829335 | controller | skipping: Conditional result was False 2025-10-03 10:00:15.834712 | 2025-10-03 10:00:15.834782 | TASK [include_role : remove-zuul-sshkey] 2025-10-03 10:00:15.880055 | controller | skipping: Conditional result was False 2025-10-03 10:00:15.888657 | 2025-10-03 10:00:15.888762 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 10:00:16.173289 | controller | ok: "logs" 2025-10-03 10:00:16.173527 | controller | ok: All items complete 2025-10-03 10:00:16.173555 | 2025-10-03 10:00:16.430702 | controller | ok: "artifacts" 2025-10-03 10:00:16.692342 | controller | ok: "docs" 2025-10-03 10:00:16.700403 | 2025-10-03 10:00:16.700530 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 10:00:17.003740 | controller | changed: "logs" 2025-10-03 10:00:17.263145 | controller | changed: "artifacts" 2025-10-03 10:00:17.527561 | controller | changed: "docs" 2025-10-03 10:00:17.574517 | 2025-10-03 10:00:17.575406 | PLAY RECAP 2025-10-03 10:00:17.575503 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-03 10:00:17.575548 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 10:00:17.575576 | 2025-10-03 10:00:18.786858 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-03 10:00:18.787691 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 10:00:19.514762 | 2025-10-03 10:00:19.514905 | PLAY [localhost] 2025-10-03 10:00:19.533087 | 2025-10-03 10:00:19.533242 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-03 10:00:20.021668 | localhost | ok 2025-10-03 10:00:20.029093 | 2025-10-03 10:00:20.029254 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-03 10:00:20.781856 | localhost | changed 2025-10-03 10:00:20.811490 | 2025-10-03 10:00:20.811620 | PLAY [all] 2025-10-03 10:00:20.832256 | 2025-10-03 10:00:20.832411 | TASK [include_role : prepare-workspace] 2025-10-03 10:00:20.862443 | controller | ok 2025-10-03 10:00:20.884280 | 2025-10-03 10:00:20.884428 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-03 10:00:21.293096 | controller | ok 2025-10-03 10:00:21.299846 | 2025-10-03 10:00:21.299915 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-03 10:00:23.307550 | controller | Output suppressed because no_log was given 2025-10-03 10:00:23.338214 | 2025-10-03 10:00:23.338374 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-03 10:00:23.603189 | controller | changed: "logs" 2025-10-03 10:00:23.828834 | controller | changed: "artifacts" 2025-10-03 10:00:24.075781 | controller | changed: "docs" 2025-10-03 10:00:24.091221 | 2025-10-03 10:00:24.091318 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-03 10:00:24.402900 | controller | changed: "logs" 2025-10-03 10:00:24.403157 | controller | changed: All items complete 2025-10-03 10:00:24.403186 | 2025-10-03 10:00:24.636172 | controller | changed: "artifacts" 2025-10-03 10:00:24.881818 | controller | changed: "docs" 2025-10-03 10:00:24.904132 | 2025-10-03 10:00:24.904246 | TASK [Check if worker can sudo] 2025-10-03 10:00:25.965206 | controller | ok: Runtime: 0:00:00.052299 2025-10-03 10:00:25.975411 | 2025-10-03 10:00:25.975583 | TASK [configure-mirrors : Gather needed facts] 2025-10-03 10:00:26.029882 | controller | skipping: Conditional result was False 2025-10-03 10:00:26.055797 | 2025-10-03 10:00:26.056111 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-03 10:00:26.112954 | controller | ok 2025-10-03 10:00:26.129675 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-03 10:00:26.174395 | 2025-10-03 10:00:26.174504 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-03 10:00:26.450802 | controller | ok 2025-10-03 10:00:26.463546 | 2025-10-03 10:00:26.463668 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-03 10:00:26.575736 | controller | ok: "/var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-03 10:00:26.592866 | 2025-10-03 10:00:26.592984 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-03 10:00:27.519269 | controller | changed 2025-10-03 10:00:27.524643 | 2025-10-03 10:00:27.524704 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-03 10:00:27.591212 | controller | ok: "/var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-03 10:00:27.591657 | controller | ok: All items complete 2025-10-03 10:00:27.591694 | 2025-10-03 10:00:27.663582 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-03 10:00:27.670065 | 2025-10-03 10:00:27.670158 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-03 10:00:28.700078 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-03 10:00:29.554912 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-03 10:00:29.564062 | 2025-10-03 10:00:29.564184 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-03 10:00:30.102051 | controller | changed: section and option added 2025-10-03 10:00:30.136614 | 2025-10-03 10:00:30.136761 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-03 10:00:31.126026 | controller | 29 files removed 2025-10-03 10:00:31.126249 | controller | ok: Item: dnf clean all Runtime: 0:00:00.684672 2025-10-03 10:00:31.126288 | controller | changed: All items complete 2025-10-03 10:00:31.126309 | 2025-10-03 10:00:42.957306 | 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-03 10:00:42.957421 | controller | DNF version: 4.14.0 2025-10-03 10:00:42.957447 | controller | cachedir: /var/cache/dnf 2025-10-03 10:00:42.957466 | controller | Making cache files for all metadata files. 2025-10-03 10:00:42.957487 | controller | baseos: has expired and will be refreshed. 2025-10-03 10:00:42.957511 | controller | appstream: has expired and will be refreshed. 2025-10-03 10:00:42.957531 | controller | crb: has expired and will be refreshed. 2025-10-03 10:00:42.957558 | controller | extras-common: has expired and will be refreshed. 2025-10-03 10:00:42.957575 | controller | repo: downloading from remote: baseos 2025-10-03 10:00:42.957592 | controller | CentOS Stream 9 - BaseOS 61 MB/s | 8.8 MB 00:00 2025-10-03 10:00:42.957608 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-03 10:00:42.957624 | controller | repo: downloading from remote: appstream 2025-10-03 10:00:42.957640 | controller | CentOS Stream 9 - AppStream 58 MB/s | 25 MB 00:00 2025-10-03 10:00:42.957656 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-03 10:00:42.957672 | controller | repo: downloading from remote: crb 2025-10-03 10:00:42.957687 | controller | CentOS Stream 9 - CRB 39 MB/s | 7.1 MB 00:00 2025-10-03 10:00:42.957704 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-03 10:00:42.957720 | controller | repo: downloading from remote: extras-common 2025-10-03 10:00:42.957736 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-10-03 10:00:42.957752 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-03 10:00:42.957770 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-03 10:00:42.957788 | controller | Completion plugin: Generating completion cache... 2025-10-03 10:00:42.957804 | controller | Metadata cache created. 2025-10-03 10:00:42.957832 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.573182 2025-10-03 10:00:42.974035 | 2025-10-03 10:00:42.974132 | PLAY RECAP 2025-10-03 10:00:42.974174 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-03 10:00:42.974211 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-03 10:00:42.974238 | 2025-10-03 10:00:43.109723 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-03 10:00:43.111428 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 10:00:43.789572 | 2025-10-03 10:00:43.789716 | PLAY [all] 2025-10-03 10:00:43.814412 | 2025-10-03 10:00:43.814545 | TASK [Install binary dependencies] 2025-10-03 10:00:43.905717 | controller | ok 2025-10-03 10:00:43.928577 | 2025-10-03 10:00:43.928718 | TASK [bindep : Include find tasks] 2025-10-03 10:00:43.971156 | controller | ok 2025-10-03 10:00:43.983382 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-03 10:00:43.989633 | 2025-10-03 10:00:43.989968 | TASK [bindep : Look for bindep.txt] 2025-10-03 10:00:44.418396 | controller | ok 2025-10-03 10:00:44.427118 | 2025-10-03 10:00:44.427265 | TASK [bindep : Define bindep_file fact] 2025-10-03 10:00:44.458221 | controller | ok 2025-10-03 10:00:44.464718 | 2025-10-03 10:00:44.464827 | TASK [bindep : Look for other-requirements.txt] 2025-10-03 10:00:44.480315 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.486831 | 2025-10-03 10:00:44.486924 | TASK [bindep : Define bindep_file fact] 2025-10-03 10:00:44.512629 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.519184 | 2025-10-03 10:00:44.519272 | TASK [bindep : Look for bindep fallback file] 2025-10-03 10:00:44.543403 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.551309 | 2025-10-03 10:00:44.551448 | TASK [bindep : Define bindep_file fact] 2025-10-03 10:00:44.587467 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.594332 | 2025-10-03 10:00:44.594441 | TASK [bindep : Include bindep tasks] 2025-10-03 10:00:44.637546 | controller | ok 2025-10-03 10:00:44.645747 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-03 10:00:44.654928 | 2025-10-03 10:00:44.655039 | TASK [bindep : Look for bindep command] 2025-10-03 10:00:44.679364 | controller | skipping: Conditional result was False 2025-10-03 10:00:44.686691 | 2025-10-03 10:00:44.686764 | TASK [bindep : Check for system bindep] 2025-10-03 10:00:45.221347 | controller | ok: Runtime: 0:00:00.007217 2025-10-03 10:00:45.227644 | 2025-10-03 10:00:45.227715 | TASK [bindep : Define bindep_command fact] 2025-10-03 10:00:45.252162 | controller | skipping: Conditional result was False 2025-10-03 10:00:45.260289 | 2025-10-03 10:00:45.260388 | TASK [bindep : Include install tasks] 2025-10-03 10:00:45.306411 | controller | ok 2025-10-03 10:00:45.318389 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-03 10:00:45.335432 | 2025-10-03 10:00:45.335537 | TASK [bindep : Create temp dir for bindep] 2025-10-03 10:00:45.764278 | controller | changed 2025-10-03 10:00:45.779313 | 2025-10-03 10:00:45.779499 | TASK [Ensure we have pip dependencies] 2025-10-03 10:00:45.803996 | controller | ok 2025-10-03 10:00:45.849543 | 2025-10-03 10:00:45.849724 | TASK [ensure-pip : Check if pip is installed] 2025-10-03 06:00:46.119410 | controller | /usr/bin/pip3 2025-10-03 06:00:46.145545 | controller | /usr/bin/python3: No module named wheel 2025-10-03 10:00:46.396378 | controller | ok: Runtime: 0:00:00.036529 2025-10-03 10:00:46.408726 | 2025-10-03 10:00:46.408874 | LOOP [ensure-pip : Install pip from packages] 2025-10-03 10:00:46.445123 | controller | ok: "/var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-03 10:00:46.454970 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-03 10:00:46.477210 | 2025-10-03 10:00:46.477430 | TASK [ensure-pip : Install Python 3 pip] 2025-10-03 10:00:49.177659 | controller | changed 2025-10-03 10:00:49.190245 | 2025-10-03 10:00:49.190403 | TASK [ensure-pip : Check for EPEL repository] 2025-10-03 10:00:49.248373 | controller | skipping: Conditional result was False 2025-10-03 10:00:49.262745 | 2025-10-03 10:00:49.262895 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-03 10:00:49.322420 | controller | skipping: Conditional result was False 2025-10-03 10:00:49.328889 | 2025-10-03 10:00:49.328966 | TASK [ensure-pip : Install Python 2 pip] 2025-10-03 10:00:49.364449 | controller | skipping: Conditional result was False 2025-10-03 10:00:49.370913 | 2025-10-03 10:00:49.371000 | TASK [ensure-pip : Ensure setuptools] 2025-10-03 10:00:49.386726 | controller | skipping: Conditional result was False 2025-10-03 10:00:49.393788 | 2025-10-03 10:00:49.393908 | TASK [ensure-pip : Check for ensurepip module] 2025-10-03 10:00:49.935635 | controller | skipping: Conditional result was False 2025-10-03 10:00:49.941760 | 2025-10-03 10:00:49.941851 | TASK [ensure-pip : Ensure python3-venv] 2025-10-03 10:00:49.996706 | controller | skipping: Conditional result was False 2025-10-03 10:00:50.008807 | 2025-10-03 10:00:50.008980 | TASK [ensure-pip : Install pip from source] 2025-10-03 10:00:50.042352 | controller | skipping: Conditional result was False 2025-10-03 10:00:50.050162 | 2025-10-03 10:00:50.050292 | TASK [ensure-pip : Probe for venv python full path] 2025-10-03 06:00:50.414238 | controller | /usr/bin/python3 2025-10-03 10:00:50.618562 | controller | ok: Runtime: 0:00:00.005437 2025-10-03 10:00:50.627138 | 2025-10-03 10:00:50.627243 | TASK [ensure-pip : Set host default] 2025-10-03 10:00:50.690587 | controller | ok 2025-10-03 10:00:50.697621 | 2025-10-03 10:00:50.697797 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-03 10:00:50.764078 | controller | ok 2025-10-03 10:00:50.784404 | 2025-10-03 10:00:50.784529 | TASK [bindep : Install bindep into temporary venv] 2025-10-03 10:00:56.074469 | controller | changed 2025-10-03 10:00:56.081241 | 2025-10-03 10:00:56.081342 | TASK [bindep : Define bindep_command] 2025-10-03 10:00:56.127537 | controller | ok 2025-10-03 10:00:56.136210 | 2025-10-03 10:00:56.136320 | LOOP [bindep : Include package tasks] 2025-10-03 10:00:56.193649 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-03 10:00:56.193810 | controller | ok: All items complete 2025-10-03 10:00:56.193838 | 2025-10-03 10:00:56.204772 | controller | included: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-03 10:00:56.225462 | 2025-10-03 10:00:56.225565 | TASK [bindep : Define bindep_run fact] 2025-10-03 10:00:56.260685 | controller | ok 2025-10-03 10:00:56.268263 | 2025-10-03 10:00:56.268362 | TASK [bindep : Get list of packages to install from bindep] 2025-10-03 06:00:57.596496 | controller | podman 2025-10-03 06:00:57.630138 | controller | python3-jmespath 2025-10-03 06:00:57.630173 | controller | python3-libvirt 2025-10-03 06:00:57.630184 | controller | python3-lxml 2025-10-03 06:00:57.630195 | controller | python3-netaddr 2025-10-03 10:00:57.819722 | controller | ok: Runtime: 0:00:01.097771 2025-10-03 10:00:57.825621 | 2025-10-03 10:00:57.825690 | TASK [bindep : Install distro packages from bindep] 2025-10-03 10:02:04.104901 | controller | changed 2025-10-03 10:02:04.113429 | 2025-10-03 10:02:04.113561 | TASK [bindep : Check that packages are installed] 2025-10-03 10:02:06.162628 | controller | ok: Runtime: 0:00:01.406365 2025-10-03 10:02:06.168567 | 2025-10-03 10:02:06.168642 | TASK [bindep : Fail if we cannot install all packages] 2025-10-03 10:02:06.193058 | controller | skipping: Conditional result was False 2025-10-03 10:02:06.205825 | 2025-10-03 10:02:06.205940 | TASK [Run test-setup role] 2025-10-03 10:02:06.238954 | controller | ok 2025-10-03 10:02:06.281177 | 2025-10-03 10:02:06.281322 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-03 10:02:06.519315 | controller | ok 2025-10-03 10:02:06.527291 | 2025-10-03 10:02:06.527561 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-03 10:02:07.060920 | controller | skipping: Conditional result was False 2025-10-03 10:02:07.086583 | 2025-10-03 10:02:07.086702 | TASK [bindep : Remove bindep temp dir] 2025-10-03 10:02:07.483203 | controller | ok 2025-10-03 10:02:07.496172 | 2025-10-03 10:02:07.496243 | PLAY RECAP 2025-10-03 10:02:07.496286 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-03 10:02:07.496307 | 2025-10-03 10:02:07.610779 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-03 10:02:07.611640 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 10:02:08.222573 | 2025-10-03 10:02:08.222714 | PLAY [all] 2025-10-03 10:02:08.242932 | 2025-10-03 10:02:08.243083 | TASK [Abort when test_command variable is undefined] 2025-10-03 10:02:08.267616 | controller | skipping: Conditional result was False 2025-10-03 10:02:08.273894 | 2025-10-03 10:02:08.273971 | TASK [Convert test_command to list] 2025-10-03 10:02:08.328543 | controller | skipping: Conditional result was False 2025-10-03 10:02:08.334999 | 2025-10-03 10:02:08.335082 | TASK [Use test_command list] 2025-10-03 10:02:08.406298 | controller | ok 2025-10-03 10:02:08.411856 | 2025-10-03 10:02:08.411946 | LOOP [Run test_command] 2025-10-03 10:02:08.811684 | controller | no check to run 2025-10-03 10:02:08.811930 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006416 2025-10-03 10:02:08.846706 | 2025-10-03 10:02:08.846848 | PLAY RECAP 2025-10-03 10:02:08.846909 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 10:02:08.846939 | 2025-10-03 10:02:08.969206 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-03 10:02:08.971049 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 10:02:09.588464 | 2025-10-03 10:02:09.588616 | PLAY [all] 2025-10-03 10:02:09.611068 | 2025-10-03 10:02:09.611194 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-03 10:02:09.961910 | controller | changed: non-zero return code 2025-10-03 10:02:09.974755 | 2025-10-03 10:02:09.974924 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-03 10:02:10.002095 | controller | skipping: Conditional result was False 2025-10-03 10:02:10.011424 | 2025-10-03 10:02:10.011571 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-03 10:02:10.046062 | 2025-10-03 10:02:10.046259 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-03 10:02:10.080459 | 2025-10-03 10:02:10.080697 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-03 10:02:10.096081 | controller | skipping: Conditional result was False 2025-10-03 10:02:10.105941 | 2025-10-03 10:02:10.106103 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-03 10:02:10.131219 | 2025-10-03 10:02:10.131434 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-03 10:02:10.147234 | controller | skipping: Conditional result was False 2025-10-03 10:02:10.158908 | 2025-10-03 10:02:10.159058 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-03 10:02:10.174524 | controller | skipping: Conditional result was False 2025-10-03 10:02:10.181684 | 2025-10-03 10:02:10.181775 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-03 10:02:10.195950 | controller | skipping: Conditional result was False 2025-10-03 10:02:10.224098 | 2025-10-03 10:02:10.224204 | PLAY RECAP 2025-10-03 10:02:10.224244 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-03 10:02:10.224264 | 2025-10-03 10:02:10.343185 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-03 10:02:10.344045 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 10:02:10.947851 | 2025-10-03 10:02:10.947981 | PLAY [all] 2025-10-03 10:02:10.967335 | 2025-10-03 10:02:10.967448 | TASK [include_role : fetch-output] 2025-10-03 10:02:11.006596 | controller | ok 2025-10-03 10:02:11.024797 | 2025-10-03 10:02:11.024926 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-03 10:02:11.069712 | controller | skipping: Conditional result was False 2025-10-03 10:02:11.075469 | 2025-10-03 10:02:11.075538 | TASK [fetch-output : Set log path for single node] 2025-10-03 10:02:11.112166 | controller | ok 2025-10-03 10:02:11.117247 | 2025-10-03 10:02:11.117317 | LOOP [fetch-output : Ensure local output dirs] 2025-10-03 10:02:11.559978 | controller -> localhost | ok: "/var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/logs" 2025-10-03 10:02:11.776914 | controller -> localhost | changed: "/var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/artifacts" 2025-10-03 10:02:11.995826 | controller -> localhost | changed: "/var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/docs" 2025-10-03 10:02:12.009216 | 2025-10-03 10:02:12.009331 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-03 10:02:12.639163 | controller | changed: .d..t...... ./ 2025-10-03 10:02:12.639539 | controller | changed: All items complete 2025-10-03 10:02:12.639574 | 2025-10-03 10:02:13.094737 | controller | changed: .d..t...... ./ 2025-10-03 10:02:13.643303 | controller | changed: .d..t...... ./ 2025-10-03 10:02:13.658890 | 2025-10-03 10:02:13.659046 | TASK [include_role : fetch-output-openshift] 2025-10-03 10:02:13.673744 | controller | skipping: Conditional result was False 2025-10-03 10:02:13.681698 | 2025-10-03 10:02:13.681827 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-03 10:02:14.205728 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.045740 2025-10-03 10:02:14.439846 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008875 2025-10-03 10:02:14.479038 | 2025-10-03 10:02:14.479145 | PLAY [all] 2025-10-03 10:02:14.506212 | 2025-10-03 10:02:14.506337 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-03 10:02:15.014954 | controller | changed 2025-10-03 10:02:15.058633 | 2025-10-03 10:02:15.058741 | PLAY RECAP 2025-10-03 10:02:15.058796 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-03 10:02:15.058824 | 2025-10-03 10:02:15.182379 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-03 10:02:15.183227 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-03 10:02:15.913281 | 2025-10-03 10:02:15.913415 | PLAY [localhost] 2025-10-03 10:02:15.933279 | 2025-10-03 10:02:15.933402 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-03 10:02:16.310683 | localhost | changed 2025-10-03 10:02:16.315291 | 2025-10-03 10:02:16.315367 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-03 10:02:16.347575 | localhost | ok 2025-10-03 10:02:16.355710 | 2025-10-03 10:02:16.355784 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-03 10:02:16.792083 | localhost | changed 2025-10-03 10:02:16.798486 | 2025-10-03 10:02:16.798579 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-03 10:02:17.502831 | localhost | changed 2025-10-03 10:02:17.511652 | 2025-10-03 10:02:17.511772 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-03 10:02:18.000558 | localhost | Identity added: /var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/tmp/ansible.kws32cx2 (/var/lib/zuul/builds/5bb8a26f7a2a4198be8831a24f79a023/work/tmp/ansible.kws32cx2) 2025-10-03 10:02:18.000748 | localhost | ok: Runtime: 0:00:00.007549 2025-10-03 10:02:18.005239 | 2025-10-03 10:02:18.005320 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-03 10:02:18.265198 | localhost | ok: Runtime: 0:00:00.006919 2025-10-03 10:02:18.278250 | 2025-10-03 10:02:18.278483 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-03 10:02:18.351110 | localhost | changed 2025-10-03 10:02:18.356373 | 2025-10-03 10:02:18.356467 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-03 10:02:18.779735 | localhost | changed 2025-10-03 10:02:18.804104 | 2025-10-03 10:02:18.804261 | PLAY [localhost] 2025-10-03 10:02:18.826233 | 2025-10-03 10:02:18.826382 | TASK [Generate bulk log download script] 2025-10-03 10:02:18.847673 | localhost | ok 2025-10-03 10:02:18.867337 | 2025-10-03 10:02:18.867470 | TASK [local-log-download : Check API endpoint is defined] 2025-10-03 10:02:18.909323 | localhost | ok: All assertions passed 2025-10-03 10:02:18.916440 | 2025-10-03 10:02:18.916545 | TASK [local-log-download : Create download script] 2025-10-03 10:02:19.346711 | localhost -> localhost | changed 2025-10-03 10:02:19.365855 | 2025-10-03 10:02:19.366000 | TASK [Register quick-download link] 2025-10-03 10:02:19.397582 | localhost | ok 2025-10-03 10:02:19.460878 | 2025-10-03 10:02:19.460976 | PLAY [logserver.rdoproject.org] 2025-10-03 10:02:19.477374 | 2025-10-03 10:02:19.477460 | TASK [Set zuul-log-path fact] 2025-10-03 10:02:19.516428 | logserver.rdoproject.org | ok 2025-10-03 10:02:19.526299 | 2025-10-03 10:02:19.526384 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-03 10:02:19.553895 | logserver.rdoproject.org | ok 2025-10-03 10:02:19.559220 | 2025-10-03 10:02:19.559283 | TASK [upload-logs : Create log directories] 2025-10-03 10:02:20.210821 | logserver.rdoproject.org | changed 2025-10-03 10:02:20.214397 | 2025-10-03 10:02:20.214461 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-03 10:02:20.525568 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.021136 2025-10-03 10:02:20.530316 | 2025-10-03 10:02:20.530383 | TASK [upload-logs : Upload logs to log server] 2025-10-03 10:02:21.284323 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-03 10:02:21.288011 | 2025-10-03 10:02:21.288148 | LOOP [upload-logs : Compress console log and json output] 2025-10-03 10:02:21.341877 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:21.379722 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:21.386213 | 2025-10-03 10:02:21.386351 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-03 10:02:21.427929 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:21.428166 | 2025-10-03 10:02:21.430802 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-03 10:02:21.438095 | 2025-10-03 10:02:21.438214 | LOOP [upload-logs : Upload console log and json output]