2025-11-23 03:37:08.084166 | Job console starting... 2025-11-23 03:37:08.096285 | Updating repositories 2025-11-23 03:37:08.127746 | Preparing job workspace 2025-11-23 03:37:12.100168 | Running Ansible setup... 2025-11-23 03:37:16.132804 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-23 03:37:16.741205 | 2025-11-23 03:37:16.741339 | PLAY [localhost] 2025-11-23 03:37:16.751192 | 2025-11-23 03:37:16.751310 | TASK [Gathering Facts] 2025-11-23 03:37:17.729658 | localhost | ok 2025-11-23 03:37:17.751664 | 2025-11-23 03:37:17.751885 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-23 03:37:18.237370 | localhost -> localhost | changed 2025-11-23 03:37:18.249004 | 2025-11-23 03:37:18.249200 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-23 03:37:19.082573 | localhost -> localhost | changed 2025-11-23 03:37:19.100613 | 2025-11-23 03:37:19.100814 | TASK [Setup log path fact] 2025-11-23 03:37:19.125152 | localhost | ok 2025-11-23 03:37:19.150345 | 2025-11-23 03:37:19.150501 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-23 03:37:19.184437 | localhost | ok 2025-11-23 03:37:19.195174 | 2025-11-23 03:37:19.195259 | TASK [emit-job-header : Print job information] 2025-11-23 03:37:19.235056 | # Job Information 2025-11-23 03:37:19.235236 | Ansible Version: 2.15.12 2025-11-23 03:37:19.235274 | Job: cifmw-molecule-cifmw_setup 2025-11-23 03:37:19.235302 | Pipeline: github-check 2025-11-23 03:37:19.235328 | Executor: ze04.softwarefactory-project.io 2025-11-23 03:37:19.235354 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3497 2025-11-23 03:37:19.235381 | Log URL (when completed): https://logserver.rdoproject.org/68c/rdoproject.org/68c3bd47a43f48d09979080956cfa87b/ 2025-11-23 03:37:19.235407 | Event ID: 88a496a0-c81d-11f0-9a39-b2f9c8374753 2025-11-23 03:37:19.240435 | 2025-11-23 03:37:19.240542 | LOOP [emit-job-header : Print node information] 2025-11-23 03:37:19.374517 | localhost | ok: 2025-11-23 03:37:19.374818 | localhost | # Node Information 2025-11-23 03:37:19.374878 | localhost | Inventory Hostname: controller 2025-11-23 03:37:19.374927 | localhost | Hostname: np0005532529 2025-11-23 03:37:19.374971 | localhost | Username: zuul 2025-11-23 03:37:19.375063 | localhost | Distro: CentOS 9 2025-11-23 03:37:19.375145 | localhost | Provider: vexxhost-nodepool-tripleo 2025-11-23 03:37:19.375200 | localhost | Region: RegionOne 2025-11-23 03:37:19.375239 | localhost | Label: cloud-centos-9-stream-tripleo 2025-11-23 03:37:19.375276 | localhost | Product Name: OpenStack Nova 2025-11-23 03:37:19.375312 | localhost | Interface IP: 38.102.83.64 2025-11-23 03:37:19.420344 | 2025-11-23 03:37:19.420539 | PLAY [all] 2025-11-23 03:37:19.434917 | 2025-11-23 03:37:19.435065 | TASK [Gather network facts] 2025-11-23 03:37:19.989858 | controller | ok 2025-11-23 03:37:20.009873 | 2025-11-23 03:37:20.010012 | TASK [include_role : start-zuul-console] 2025-11-23 03:37:20.033562 | controller | ok 2025-11-23 03:37:20.046924 | 2025-11-23 03:37:20.047017 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-23 03:37:20.483693 | controller | ok 2025-11-23 03:37:20.492477 | 2025-11-23 03:37:20.492538 | TASK [include_role : add-build-sshkey] 2025-11-23 03:37:20.511516 | controller | ok 2025-11-23 03:37:20.526754 | 2025-11-23 03:37:20.527094 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-23 03:37:20.823171 | controller -> localhost | ok 2025-11-23 03:37:20.829313 | 2025-11-23 03:37:20.829405 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-23 03:37:20.859225 | controller | ok 2025-11-23 03:37:20.873078 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-23 03:37:20.879137 | 2025-11-23 03:37:20.879207 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-23 03:37:21.636295 | controller -> localhost | Generating public/private rsa key pair. 2025-11-23 03:37:21.636526 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/68c3bd47a43f48d09979080956cfa87b_id_rsa. 2025-11-23 03:37:21.636559 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/68c3bd47a43f48d09979080956cfa87b_id_rsa.pub. 2025-11-23 03:37:21.636581 | controller -> localhost | The key fingerprint is: 2025-11-23 03:37:21.636600 | controller -> localhost | SHA256:wKq244jQtVVW83ys86WHoufR1Vu413ZY0bfBmxsGBus zuul-build-sshkey 2025-11-23 03:37:21.636619 | controller -> localhost | The key's randomart image is: 2025-11-23 03:37:21.636637 | controller -> localhost | +---[RSA 3072]----+ 2025-11-23 03:37:21.636655 | controller -> localhost | | o. | 2025-11-23 03:37:21.636673 | controller -> localhost | | . . +o.. .| 2025-11-23 03:37:21.636713 | controller -> localhost | | o o .ooo+o| 2025-11-23 03:37:21.636732 | controller -> localhost | | . + . .o..O| 2025-11-23 03:37:21.636750 | controller -> localhost | | o . S Eo .**| 2025-11-23 03:37:21.636768 | controller -> localhost | | . o o +.O*| 2025-11-23 03:37:21.636786 | controller -> localhost | |. + . o Bo*| 2025-11-23 03:37:21.636804 | controller -> localhost | |oo.. ..o +.| 2025-11-23 03:37:21.636821 | controller -> localhost | |o.o. .o. | 2025-11-23 03:37:21.636839 | controller -> localhost | +----[SHA256]-----+ 2025-11-23 03:37:21.636885 | controller -> localhost | ok: Runtime: 0:00:00.292825 2025-11-23 03:37:21.642830 | 2025-11-23 03:37:21.642934 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-23 03:37:21.678140 | controller | ok 2025-11-23 03:37:21.688092 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-23 03:37:21.696355 | 2025-11-23 03:37:21.696458 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-23 03:37:21.734929 | controller | skipping: Conditional result was False 2025-11-23 03:37:21.741073 | 2025-11-23 03:37:21.741164 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-23 03:37:22.248658 | controller | changed 2025-11-23 03:37:22.264452 | 2025-11-23 03:37:22.264621 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-23 03:37:22.578195 | controller | ok 2025-11-23 03:37:22.589626 | 2025-11-23 03:37:22.589851 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-23 03:37:23.564365 | controller | changed 2025-11-23 03:37:23.573295 | 2025-11-23 03:37:23.573465 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-23 03:37:24.537443 | controller | changed 2025-11-23 03:37:24.548493 | 2025-11-23 03:37:24.548641 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-23 03:37:24.575879 | controller | skipping: Conditional result was False 2025-11-23 03:37:24.588527 | 2025-11-23 03:37:24.588743 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-23 03:37:25.013669 | controller -> localhost | changed 2025-11-23 03:37:25.023707 | 2025-11-23 03:37:25.023775 | TASK [add-build-sshkey : Add back temp key] 2025-11-23 03:37:25.331922 | controller -> localhost | Identity added: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/68c3bd47a43f48d09979080956cfa87b_id_rsa (zuul-build-sshkey) 2025-11-23 03:37:25.332150 | controller -> localhost | ok: Runtime: 0:00:00.014102 2025-11-23 03:37:25.339715 | 2025-11-23 03:37:25.339802 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-23 03:37:25.733868 | controller | ok 2025-11-23 03:37:25.745953 | 2025-11-23 03:37:25.746129 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-23 03:37:25.794387 | controller | skipping: Conditional result was False 2025-11-23 03:37:25.817590 | 2025-11-23 03:37:25.817806 | TASK [include_role : validate-host] 2025-11-23 03:37:25.857418 | controller | ok 2025-11-23 03:37:25.893565 | 2025-11-23 03:37:25.893770 | TASK [validate-host : Define zuul_info_dir fact] 2025-11-23 03:37:25.934777 | controller | ok 2025-11-23 03:37:25.939951 | 2025-11-23 03:37:25.940045 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-11-23 03:37:26.210425 | controller -> localhost | ok 2025-11-23 03:37:26.229193 | 2025-11-23 03:37:26.229365 | TASK [validate-host : Collect information about the host] 2025-11-23 03:37:27.103035 | controller | ok 2025-11-23 03:37:27.114849 | 2025-11-23 03:37:27.114956 | TASK [validate-host : Sanitize hostname] 2025-11-23 03:37:27.175316 | controller | ok 2025-11-23 03:37:27.180216 | 2025-11-23 03:37:27.180282 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-11-23 03:37:27.729082 | controller -> localhost | changed 2025-11-23 03:37:27.742474 | 2025-11-23 03:37:27.742644 | TASK [validate-host : Collect information about zuul worker] 2025-11-23 03:37:28.219991 | controller | ok 2025-11-23 03:37:28.226555 | 2025-11-23 03:37:28.226633 | TASK [validate-host : Write out all zuul information for each host] 2025-11-23 03:37:28.721172 | controller -> localhost | changed 2025-11-23 03:37:28.735817 | 2025-11-23 03:37:28.735951 | TASK [include_role : prepare-workspace-openshift] 2025-11-23 03:37:28.753594 | controller | skipping: Conditional result was False 2025-11-23 03:37:28.762513 | 2025-11-23 03:37:28.762600 | TASK [include_role : remove-zuul-sshkey] 2025-11-23 03:37:28.777894 | controller | skipping: Conditional result was False 2025-11-23 03:37:28.786707 | 2025-11-23 03:37:28.786795 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-23 03:37:29.076654 | controller | ok: "logs" 2025-11-23 03:37:29.077876 | controller | ok: All items complete 2025-11-23 03:37:29.077994 | 2025-11-23 03:37:29.333043 | controller | ok: "artifacts" 2025-11-23 03:37:29.596275 | controller | ok: "docs" 2025-11-23 03:37:29.613266 | 2025-11-23 03:37:29.613474 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-23 03:37:29.922001 | controller | changed: "logs" 2025-11-23 03:37:30.155768 | controller | changed: "artifacts" 2025-11-23 03:37:30.382444 | controller | changed: "docs" 2025-11-23 03:37:30.448618 | 2025-11-23 03:37:30.448794 | PLAY RECAP 2025-11-23 03:37:30.448865 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-11-23 03:37:30.448919 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-23 03:37:30.448955 | 2025-11-23 03:37:30.577615 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-23 03:37:30.578462 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-23 03:37:31.230716 | 2025-11-23 03:37:31.230834 | PLAY [localhost] 2025-11-23 03:37:31.247586 | 2025-11-23 03:37:31.247741 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-11-23 03:37:31.757159 | localhost | ok 2025-11-23 03:37:31.763387 | 2025-11-23 03:37:31.763464 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-11-23 03:37:32.474963 | localhost | changed 2025-11-23 03:37:32.502194 | 2025-11-23 03:37:32.502287 | PLAY [all] 2025-11-23 03:37:32.517319 | 2025-11-23 03:37:32.517383 | TASK [include_role : prepare-workspace] 2025-11-23 03:37:32.548013 | controller | ok 2025-11-23 03:37:32.569088 | 2025-11-23 03:37:32.569231 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-23 03:37:33.007480 | controller | ok 2025-11-23 03:37:33.016427 | 2025-11-23 03:37:33.016516 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-23 03:37:35.063373 | controller | Output suppressed because no_log was given 2025-11-23 03:37:35.079456 | 2025-11-23 03:37:35.079603 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-23 03:37:35.366709 | controller | changed: "logs" 2025-11-23 03:37:35.625858 | controller | changed: "artifacts" 2025-11-23 03:37:35.878987 | controller | changed: "docs" 2025-11-23 03:37:35.900495 | 2025-11-23 03:37:35.900674 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-23 03:37:36.164599 | controller | changed: "logs" 2025-11-23 03:37:36.165026 | controller | changed: All items complete 2025-11-23 03:37:36.165098 | 2025-11-23 03:37:36.425868 | controller | changed: "artifacts" 2025-11-23 03:37:36.673584 | controller | changed: "docs" 2025-11-23 03:37:36.706393 | 2025-11-23 03:37:36.706553 | TASK [Check if worker can sudo] 2025-11-23 03:37:37.266874 | controller | ok: Runtime: 0:00:00.060087 2025-11-23 03:37:37.280243 | 2025-11-23 03:37:37.280757 | TASK [configure-mirrors : Gather needed facts] 2025-11-23 03:37:37.369567 | controller | skipping: Conditional result was False 2025-11-23 03:37:37.376631 | 2025-11-23 03:37:37.376785 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-11-23 03:37:37.480337 | controller | ok 2025-11-23 03:37:37.495769 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-11-23 03:37:37.537187 | 2025-11-23 03:37:37.537304 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-11-23 03:37:37.875791 | controller | ok 2025-11-23 03:37:37.884179 | 2025-11-23 03:37:37.884312 | LOOP [configure-mirrors : Include OS-specific variables] 2025-11-23 03:37:37.984254 | controller | ok: "/var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-11-23 03:37:38.002757 | 2025-11-23 03:37:38.002947 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-11-23 03:37:39.034325 | controller | changed 2025-11-23 03:37:39.046069 | 2025-11-23 03:37:39.046207 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-11-23 03:37:39.123419 | controller | ok: "/var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-11-23 03:37:39.123827 | controller | ok: All items complete 2025-11-23 03:37:39.123890 | 2025-11-23 03:37:39.198533 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-11-23 03:37:39.207435 | 2025-11-23 03:37:39.207522 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-11-23 03:37:40.259797 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-11-23 03:37:41.251485 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-11-23 03:37:41.278166 | 2025-11-23 03:37:41.278328 | TASK [configure-mirrors : Disable deltrarpm] 2025-11-23 03:37:41.737789 | controller | changed: section and option added 2025-11-23 03:37:41.777366 | 2025-11-23 03:37:41.777523 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-11-23 03:37:42.645884 | controller | 29 files removed 2025-11-23 03:37:42.646337 | controller | ok: Item: dnf clean all Runtime: 0:00:00.496997 2025-11-23 03:37:42.646429 | controller | changed: All items complete 2025-11-23 03:37:42.646476 | 2025-11-23 03:37:53.423828 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-11-23 03:37:53.423954 | controller | DNF version: 4.14.0 2025-11-23 03:37:53.423995 | controller | cachedir: /var/cache/dnf 2025-11-23 03:37:53.424031 | controller | Making cache files for all metadata files. 2025-11-23 03:37:53.424065 | controller | baseos: has expired and will be refreshed. 2025-11-23 03:37:53.424095 | controller | appstream: has expired and will be refreshed. 2025-11-23 03:37:53.424126 | controller | crb: has expired and will be refreshed. 2025-11-23 03:37:53.424309 | controller | extras-common: has expired and will be refreshed. 2025-11-23 03:37:53.424350 | controller | repo: downloading from remote: baseos 2025-11-23 03:37:53.424379 | controller | CentOS Stream 9 - BaseOS 63 MB/s | 8.8 MB 00:00 2025-11-23 03:37:53.424405 | controller | baseos: using metadata from Mon 17 Nov 2025 10:24:02 AM EST. 2025-11-23 03:37:53.424431 | controller | repo: downloading from remote: appstream 2025-11-23 03:37:53.424456 | controller | CentOS Stream 9 - AppStream 101 MB/s | 25 MB 00:00 2025-11-23 03:37:53.424482 | controller | appstream: using metadata from Mon 17 Nov 2025 10:27:35 AM EST. 2025-11-23 03:37:53.424508 | controller | repo: downloading from remote: crb 2025-11-23 03:37:53.424533 | controller | CentOS Stream 9 - CRB 88 MB/s | 7.3 MB 00:00 2025-11-23 03:37:53.424558 | controller | crb: using metadata from Mon 17 Nov 2025 10:32:16 AM EST. 2025-11-23 03:37:53.424584 | controller | repo: downloading from remote: extras-common 2025-11-23 03:37:53.424610 | controller | CentOS Stream 9 - Extras packages 1.6 MB/s | 20 kB 00:00 2025-11-23 03:37:53.424636 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-11-23 03:37:53.424660 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-11-23 03:37:53.424870 | controller | Completion plugin: Generating completion cache... 2025-11-23 03:37:53.424898 | controller | Metadata cache created. 2025-11-23 03:37:53.424933 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.457951 2025-11-23 03:37:53.456400 | 2025-11-23 03:37:53.456515 | PLAY RECAP 2025-11-23 03:37:53.456572 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-11-23 03:37:53.456611 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-23 03:37:53.456639 | 2025-11-23 03:37:53.586135 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-23 03:37:53.586954 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-23 03:37:54.134654 | 2025-11-23 03:37:54.134780 | PLAY [all] 2025-11-23 03:37:54.155833 | 2025-11-23 03:37:54.155936 | TASK [Install binary dependencies] 2025-11-23 03:37:54.229871 | controller | ok 2025-11-23 03:37:54.256918 | 2025-11-23 03:37:54.257050 | TASK [bindep : Include find tasks] 2025-11-23 03:37:54.299982 | controller | ok 2025-11-23 03:37:54.312782 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-23 03:37:54.322643 | 2025-11-23 03:37:54.322773 | TASK [bindep : Look for bindep.txt] 2025-11-23 03:37:54.794113 | controller | ok 2025-11-23 03:37:54.810183 | 2025-11-23 03:37:54.810374 | TASK [bindep : Define bindep_file fact] 2025-11-23 03:37:54.859488 | controller | ok 2025-11-23 03:37:54.870926 | 2025-11-23 03:37:54.871107 | TASK [bindep : Look for other-requirements.txt] 2025-11-23 03:37:54.919434 | controller | skipping: Conditional result was False 2025-11-23 03:37:54.934626 | 2025-11-23 03:37:54.934886 | TASK [bindep : Define bindep_file fact] 2025-11-23 03:37:54.962795 | controller | skipping: Conditional result was False 2025-11-23 03:37:54.973208 | 2025-11-23 03:37:54.973374 | TASK [bindep : Look for bindep fallback file] 2025-11-23 03:37:55.008906 | controller | skipping: Conditional result was False 2025-11-23 03:37:55.017577 | 2025-11-23 03:37:55.017728 | TASK [bindep : Define bindep_file fact] 2025-11-23 03:37:55.043325 | controller | skipping: Conditional result was False 2025-11-23 03:37:55.051935 | 2025-11-23 03:37:55.052034 | TASK [bindep : Include bindep tasks] 2025-11-23 03:37:55.086215 | controller | ok 2025-11-23 03:37:55.096408 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-11-23 03:37:55.110132 | 2025-11-23 03:37:55.110235 | TASK [bindep : Look for bindep command] 2025-11-23 03:37:55.145554 | controller | skipping: Conditional result was False 2025-11-23 03:37:55.152752 | 2025-11-23 03:37:55.152831 | TASK [bindep : Check for system bindep] 2025-11-23 03:37:55.685045 | controller | ok: Runtime: 0:00:00.010794 2025-11-23 03:37:55.697761 | 2025-11-23 03:37:55.697982 | TASK [bindep : Define bindep_command fact] 2025-11-23 03:37:55.725200 | controller | skipping: Conditional result was False 2025-11-23 03:37:55.737910 | 2025-11-23 03:37:55.738079 | TASK [bindep : Include install tasks] 2025-11-23 03:37:55.775106 | controller | ok 2025-11-23 03:37:55.791219 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-11-23 03:37:55.807458 | 2025-11-23 03:37:55.807581 | TASK [bindep : Create temp dir for bindep] 2025-11-23 03:37:56.245223 | controller | changed 2025-11-23 03:37:56.252698 | 2025-11-23 03:37:56.252787 | TASK [Ensure we have pip dependencies] 2025-11-23 03:37:56.277609 | controller | ok 2025-11-23 03:37:56.313574 | 2025-11-23 03:37:56.313751 | TASK [ensure-pip : Check if pip is installed] 2025-11-22 22:37:56.631998 | controller | /usr/bin/pip3 2025-11-22 22:37:56.672747 | controller | /usr/bin/python3: No module named wheel 2025-11-23 03:37:56.849003 | controller | ok: Runtime: 0:00:00.055022 2025-11-23 03:37:56.864321 | 2025-11-23 03:37:56.864479 | LOOP [ensure-pip : Install pip from packages] 2025-11-23 03:37:56.911976 | controller | ok: "/var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-11-23 03:37:56.934300 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-11-23 03:37:56.945237 | 2025-11-23 03:37:56.945351 | TASK [ensure-pip : Install Python 3 pip] 2025-11-23 03:37:59.116519 | controller | changed 2025-11-23 03:37:59.129160 | 2025-11-23 03:37:59.129334 | TASK [ensure-pip : Check for EPEL repository] 2025-11-23 03:37:59.195305 | controller | skipping: Conditional result was False 2025-11-23 03:37:59.205364 | 2025-11-23 03:37:59.205478 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-11-23 03:37:59.250032 | controller | skipping: Conditional result was False 2025-11-23 03:37:59.261976 | 2025-11-23 03:37:59.262156 | TASK [ensure-pip : Install Python 2 pip] 2025-11-23 03:37:59.309188 | controller | skipping: Conditional result was False 2025-11-23 03:37:59.316225 | 2025-11-23 03:37:59.316328 | TASK [ensure-pip : Ensure setuptools] 2025-11-23 03:37:59.340826 | controller | skipping: Conditional result was False 2025-11-23 03:37:59.346760 | 2025-11-23 03:37:59.346831 | TASK [ensure-pip : Check for ensurepip module] 2025-11-23 03:37:59.881041 | controller | skipping: Conditional result was False 2025-11-23 03:37:59.888510 | 2025-11-23 03:37:59.888605 | TASK [ensure-pip : Ensure python3-venv] 2025-11-23 03:37:59.913095 | controller | skipping: Conditional result was False 2025-11-23 03:37:59.921661 | 2025-11-23 03:37:59.921786 | TASK [ensure-pip : Install pip from source] 2025-11-23 03:37:59.947381 | controller | skipping: Conditional result was False 2025-11-23 03:37:59.962648 | 2025-11-23 03:37:59.962934 | TASK [ensure-pip : Probe for venv python full path] 2025-11-22 22:38:00.292556 | controller | /usr/bin/python3 2025-11-23 03:38:00.520256 | controller | ok: Runtime: 0:00:00.008100 2025-11-23 03:38:00.532558 | 2025-11-23 03:38:00.532789 | TASK [ensure-pip : Set host default] 2025-11-23 03:38:00.584803 | controller | ok 2025-11-23 03:38:00.597574 | 2025-11-23 03:38:00.597804 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-11-23 03:38:00.661280 | controller | ok 2025-11-23 03:38:00.686854 | 2025-11-23 03:38:00.686967 | TASK [bindep : Install bindep into temporary venv] 2025-11-23 03:38:05.289426 | controller | changed 2025-11-23 03:38:05.304925 | 2025-11-23 03:38:05.305130 | TASK [bindep : Define bindep_command] 2025-11-23 03:38:05.331502 | controller | ok 2025-11-23 03:38:05.339270 | 2025-11-23 03:38:05.339376 | LOOP [bindep : Include package tasks] 2025-11-23 03:38:05.385270 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-11-23 03:38:05.385496 | controller | ok: All items complete 2025-11-23 03:38:05.385539 | 2025-11-23 03:38:05.409704 | controller | included: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-11-23 03:38:05.429657 | 2025-11-23 03:38:05.429830 | TASK [bindep : Define bindep_run fact] 2025-11-23 03:38:05.463780 | controller | ok 2025-11-23 03:38:05.472938 | 2025-11-23 03:38:05.473090 | TASK [bindep : Get list of packages to install from bindep] 2025-11-22 22:38:06.909045 | controller | podman 2025-11-22 22:38:06.960037 | controller | python3-jmespath 2025-11-22 22:38:06.960067 | controller | python3-libvirt 2025-11-22 22:38:06.960076 | controller | python3-lxml 2025-11-22 22:38:06.960088 | controller | python3-netaddr 2025-11-23 03:38:07.019931 | controller | ok: Runtime: 0:00:01.195647 2025-11-23 03:38:07.026615 | 2025-11-23 03:38:07.026711 | TASK [bindep : Install distro packages from bindep] 2025-11-23 03:39:06.881639 | controller | changed 2025-11-23 03:39:06.890985 | 2025-11-23 03:39:06.891132 | TASK [bindep : Check that packages are installed] 2025-11-23 03:39:08.436561 | controller | ok: Runtime: 0:00:01.154413 2025-11-23 03:39:08.442419 | 2025-11-23 03:39:08.442492 | TASK [bindep : Fail if we cannot install all packages] 2025-11-23 03:39:08.476741 | controller | skipping: Conditional result was False 2025-11-23 03:39:08.487808 | 2025-11-23 03:39:08.487918 | TASK [Run test-setup role] 2025-11-23 03:39:08.509075 | controller | ok 2025-11-23 03:39:08.528268 | 2025-11-23 03:39:08.528409 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-23 03:39:08.816417 | controller | ok 2025-11-23 03:39:08.822087 | 2025-11-23 03:39:08.822157 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-23 03:39:09.352814 | controller | skipping: Conditional result was False 2025-11-23 03:39:09.397091 | 2025-11-23 03:39:09.397283 | TASK [bindep : Remove bindep temp dir] 2025-11-23 03:39:09.806779 | controller | ok 2025-11-23 03:39:09.821984 | 2025-11-23 03:39:09.822087 | PLAY RECAP 2025-11-23 03:39:09.822148 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-11-23 03:39:09.822180 | 2025-11-23 03:39:09.939666 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-23 03:39:09.942451 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-23 03:39:10.552331 | 2025-11-23 03:39:10.552438 | PLAY [all] 2025-11-23 03:39:10.571348 | 2025-11-23 03:39:10.571431 | TASK [Abort when test_command variable is undefined] 2025-11-23 03:39:10.616080 | controller | skipping: Conditional result was False 2025-11-23 03:39:10.624460 | 2025-11-23 03:39:10.624577 | TASK [Convert test_command to list] 2025-11-23 03:39:10.671395 | controller | skipping: Conditional result was False 2025-11-23 03:39:10.682062 | 2025-11-23 03:39:10.682198 | TASK [Use test_command list] 2025-11-23 03:39:10.745614 | controller | ok 2025-11-23 03:39:10.753587 | 2025-11-23 03:39:10.753713 | LOOP [Run test_command] 2025-11-23 03:39:11.164535 | controller | no check to run 2025-11-23 03:39:11.164891 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005641 2025-11-23 03:39:11.214739 | 2025-11-23 03:39:11.214894 | PLAY RECAP 2025-11-23 03:39:11.214981 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-23 03:39:11.215035 | 2025-11-23 03:39:11.322462 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-23 03:39:11.323493 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-23 03:39:11.908876 | 2025-11-23 03:39:11.909006 | PLAY [all] 2025-11-23 03:39:11.930092 | 2025-11-23 03:39:11.930218 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-23 03:39:12.413212 | controller | changed: non-zero return code 2025-11-23 03:39:12.421367 | 2025-11-23 03:39:12.421508 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-23 03:39:12.447245 | controller | skipping: Conditional result was False 2025-11-23 03:39:12.454994 | 2025-11-23 03:39:12.455096 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-23 03:39:12.478770 | 2025-11-23 03:39:12.478943 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-23 03:39:12.501938 | 2025-11-23 03:39:12.502107 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-23 03:39:12.527414 | controller | skipping: Conditional result was False 2025-11-23 03:39:12.535230 | 2025-11-23 03:39:12.535357 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-23 03:39:12.569730 | 2025-11-23 03:39:12.569940 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-23 03:39:12.595962 | controller | skipping: Conditional result was False 2025-11-23 03:39:12.606322 | 2025-11-23 03:39:12.606481 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-23 03:39:12.632365 | controller | skipping: Conditional result was False 2025-11-23 03:39:12.640206 | 2025-11-23 03:39:12.640354 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-23 03:39:12.666146 | controller | skipping: Conditional result was False 2025-11-23 03:39:12.699795 | 2025-11-23 03:39:12.699979 | PLAY RECAP 2025-11-23 03:39:12.700054 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-23 03:39:12.700089 | 2025-11-23 03:39:12.807267 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-23 03:39:12.808522 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-23 03:39:13.361432 | 2025-11-23 03:39:13.361562 | PLAY [all] 2025-11-23 03:39:13.380020 | 2025-11-23 03:39:13.380094 | TASK [include_role : fetch-output] 2025-11-23 03:39:13.408568 | controller | ok 2025-11-23 03:39:13.424761 | 2025-11-23 03:39:13.424836 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-23 03:39:13.469078 | controller | skipping: Conditional result was False 2025-11-23 03:39:13.476374 | 2025-11-23 03:39:13.476461 | TASK [fetch-output : Set log path for single node] 2025-11-23 03:39:13.511988 | controller | ok 2025-11-23 03:39:13.522472 | 2025-11-23 03:39:13.522572 | LOOP [fetch-output : Ensure local output dirs] 2025-11-23 03:39:13.974986 | controller -> localhost | ok: "/var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/logs" 2025-11-23 03:39:14.203093 | controller -> localhost | changed: "/var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/artifacts" 2025-11-23 03:39:14.446115 | controller -> localhost | changed: "/var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/docs" 2025-11-23 03:39:14.465625 | 2025-11-23 03:39:14.465853 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-23 03:39:15.256520 | controller | changed: .d..t...... ./ 2025-11-23 03:39:15.256980 | controller | changed: All items complete 2025-11-23 03:39:15.257063 | 2025-11-23 03:39:15.830940 | controller | changed: .d..t...... ./ 2025-11-23 03:39:16.342277 | controller | changed: .d..t...... ./ 2025-11-23 03:39:16.359820 | 2025-11-23 03:39:16.360145 | TASK [include_role : fetch-output-openshift] 2025-11-23 03:39:16.378429 | controller | skipping: Conditional result was False 2025-11-23 03:39:16.391563 | 2025-11-23 03:39:16.391768 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-23 03:39:16.854895 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009484 2025-11-23 03:39:17.127010 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012788 2025-11-23 03:39:17.158842 | 2025-11-23 03:39:17.158950 | PLAY [all] 2025-11-23 03:39:17.173754 | 2025-11-23 03:39:17.173854 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-11-23 03:39:17.676055 | controller | changed 2025-11-23 03:39:17.713714 | 2025-11-23 03:39:17.713843 | PLAY RECAP 2025-11-23 03:39:17.713931 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-23 03:39:17.713995 | 2025-11-23 03:39:17.826328 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-23 03:39:17.827239 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-11-23 03:39:18.492230 | 2025-11-23 03:39:18.492379 | PLAY [localhost] 2025-11-23 03:39:18.510983 | 2025-11-23 03:39:18.511085 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-23 03:39:18.927441 | localhost | changed 2025-11-23 03:39:18.932711 | 2025-11-23 03:39:18.932863 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-23 03:39:18.962354 | localhost | ok 2025-11-23 03:39:18.970900 | 2025-11-23 03:39:18.971009 | TASK [add-fileserver : Create SSH private key tempfile] 2025-11-23 03:39:19.346345 | localhost | changed 2025-11-23 03:39:19.352409 | 2025-11-23 03:39:19.352515 | TASK [add-fileserver : Create SSH private key from secret] 2025-11-23 03:39:20.094196 | localhost | changed 2025-11-23 03:39:20.099257 | 2025-11-23 03:39:20.099335 | TASK [add-fileserver : Add fileserver ssh key] 2025-11-23 03:39:20.559039 | localhost | Identity added: /var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/tmp/ansible.sso0jvbz (/var/lib/zuul/builds/68c3bd47a43f48d09979080956cfa87b/work/tmp/ansible.sso0jvbz) 2025-11-23 03:39:20.559264 | localhost | ok: Runtime: 0:00:00.009596 2025-11-23 03:39:20.565543 | 2025-11-23 03:39:20.565648 | TASK [add-fileserver : Remove SSH private key from disk] 2025-11-23 03:39:20.850476 | localhost | ok: Runtime: 0:00:00.005395 2025-11-23 03:39:20.855183 | 2025-11-23 03:39:20.855251 | TASK [add-fileserver : Add fileserver to inventory] 2025-11-23 03:39:20.940324 | localhost | changed 2025-11-23 03:39:20.949584 | 2025-11-23 03:39:20.949815 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-11-23 03:39:21.340840 | localhost | changed 2025-11-23 03:39:21.368966 | 2025-11-23 03:39:21.369093 | PLAY [localhost] 2025-11-23 03:39:21.386816 | 2025-11-23 03:39:21.386951 | TASK [Generate bulk log download script] 2025-11-23 03:39:21.407085 | localhost | ok 2025-11-23 03:39:21.424016 | 2025-11-23 03:39:21.424156 | TASK [local-log-download : Check API endpoint is defined] 2025-11-23 03:39:21.453362 | localhost | ok: All assertions passed 2025-11-23 03:39:21.457886 | 2025-11-23 03:39:21.457963 | TASK [local-log-download : Create download script] 2025-11-23 03:39:21.868224 | localhost -> localhost | changed 2025-11-23 03:39:21.876832 | 2025-11-23 03:39:21.876900 | TASK [Register quick-download link] 2025-11-23 03:39:21.904893 | localhost | ok 2025-11-23 03:39:21.943985 | 2025-11-23 03:39:21.944085 | PLAY [logserver.rdoproject.org] 2025-11-23 03:39:21.954051 | 2025-11-23 03:39:21.954167 | TASK [Set zuul-log-path fact] 2025-11-23 03:39:21.971952 | logserver.rdoproject.org | ok 2025-11-23 03:39:21.981548 | 2025-11-23 03:39:21.981646 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-23 03:39:22.018584 | logserver.rdoproject.org | ok 2025-11-23 03:39:22.024017 | 2025-11-23 03:39:22.024085 | TASK [upload-logs : Create log directories] 2025-11-23 03:39:22.980965 | logserver.rdoproject.org | changed 2025-11-23 03:39:22.989005 | 2025-11-23 03:39:22.989145 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-11-23 03:39:23.337029 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006074 2025-11-23 03:39:23.342138 | 2025-11-23 03:39:23.342488 | TASK [upload-logs : Upload logs to log server] 2025-11-23 03:39:24.122266 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-11-23 03:39:24.129546 | 2025-11-23 03:39:24.129746 | LOOP [upload-logs : Compress console log and json output] 2025-11-23 03:39:24.198033 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-23 03:39:24.218030 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-23 03:39:24.229624 | 2025-11-23 03:39:24.229876 | LOOP [upload-logs : Upload compressed console log and json output] 2025-11-23 03:39:24.285360 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-23 03:39:24.285704 | 2025-11-23 03:39:24.296150 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-23 03:39:24.308508 | 2025-11-23 03:39:24.308732 | LOOP [upload-logs : Upload console log and json output]