2025-12-05 15:33:29.851577 | Job console starting... 2025-12-05 15:33:29.861551 | Updating repositories 2025-12-05 15:33:29.900924 | Preparing job workspace 2025-12-05 15:33:35.139306 | Running Ansible setup... 2025-12-05 15:33:39.076111 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:33:39.725393 | 2025-12-05 15:33:39.725511 | PLAY [localhost] 2025-12-05 15:33:39.734025 | 2025-12-05 15:33:39.734094 | TASK [Gathering Facts] 2025-12-05 15:33:40.901025 | localhost | ok 2025-12-05 15:33:40.939309 | 2025-12-05 15:33:40.939449 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 15:33:41.590889 | localhost -> localhost | changed 2025-12-05 15:33:41.596501 | 2025-12-05 15:33:41.596566 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 15:33:42.792475 | localhost -> localhost | changed 2025-12-05 15:33:42.801520 | 2025-12-05 15:33:42.801583 | TASK [Setup log path fact] 2025-12-05 15:33:42.819650 | localhost | ok 2025-12-05 15:33:42.833806 | 2025-12-05 15:33:42.833877 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:33:42.861294 | localhost | ok 2025-12-05 15:33:42.869162 | 2025-12-05 15:33:42.869223 | TASK [emit-job-header : Print job information] 2025-12-05 15:33:42.919820 | # Job Information 2025-12-05 15:33:42.919941 | Ansible Version: 2.15.12 2025-12-05 15:33:42.919966 | Job: cifmw-molecule-openshift_adm 2025-12-05 15:33:42.919986 | Pipeline: github-check 2025-12-05 15:33:42.920004 | Executor: ze04.softwarefactory-project.io 2025-12-05 15:33:42.920022 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539 2025-12-05 15:33:42.920040 | Log URL (when completed): https://logserver.rdoproject.org/4a6/rdoproject.org/4a6000d2770c4f78b7b5dd2b3683d634/ 2025-12-05 15:33:42.920058 | Event ID: 757b9e30-d1ef-11f0-97eb-f505e6ea5a00 2025-12-05 15:33:42.923720 | 2025-12-05 15:33:42.923789 | LOOP [emit-job-header : Print node information] 2025-12-05 15:33:43.016874 | localhost | ok: 2025-12-05 15:33:43.017037 | localhost | # Node Information 2025-12-05 15:33:43.017063 | localhost | Inventory Hostname: controller 2025-12-05 15:33:43.017086 | localhost | Hostname: np0005547430 2025-12-05 15:33:43.017106 | localhost | Username: zuul 2025-12-05 15:33:43.017125 | localhost | Distro: CentOS 9 2025-12-05 15:33:43.017143 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 15:33:43.017160 | localhost | Region: RegionOne 2025-12-05 15:33:43.017177 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 15:33:43.017193 | localhost | Product Name: OpenStack Nova 2025-12-05 15:33:43.017209 | localhost | Interface IP: 38.102.83.233 2025-12-05 15:33:43.042936 | 2025-12-05 15:33:43.043026 | PLAY [all] 2025-12-05 15:33:43.049411 | 2025-12-05 15:33:43.049472 | TASK [Gather network facts] 2025-12-05 15:33:43.508657 | controller | ok 2025-12-05 15:33:43.536658 | 2025-12-05 15:33:43.536762 | TASK [include_role : start-zuul-console] 2025-12-05 15:33:43.575653 | controller | ok 2025-12-05 15:33:43.587327 | 2025-12-05 15:33:43.587390 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 15:33:43.950657 | controller | ok 2025-12-05 15:33:43.959598 | 2025-12-05 15:33:43.959653 | TASK [include_role : add-build-sshkey] 2025-12-05 15:33:43.988279 | controller | ok 2025-12-05 15:33:44.011950 | 2025-12-05 15:33:44.012047 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 15:33:44.267057 | controller -> localhost | ok 2025-12-05 15:33:44.276009 | 2025-12-05 15:33:44.276120 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 15:33:44.299903 | controller | ok 2025-12-05 15:33:44.314388 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 15:33:44.320626 | 2025-12-05 15:33:44.320702 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 15:33:44.962451 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 15:33:44.962633 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/4a6000d2770c4f78b7b5dd2b3683d634_id_rsa. 2025-12-05 15:33:44.962663 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/4a6000d2770c4f78b7b5dd2b3683d634_id_rsa.pub. 2025-12-05 15:33:44.962711 | controller -> localhost | The key fingerprint is: 2025-12-05 15:33:44.962732 | controller -> localhost | SHA256:Jj1NIhEnW0ugO62FWWQfDlBrCsa1gGQ7uCtwwPR0fYY zuul-build-sshkey 2025-12-05 15:33:44.962751 | controller -> localhost | The key's randomart image is: 2025-12-05 15:33:44.962770 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 15:33:44.962788 | controller -> localhost | |.=..o+@o* | 2025-12-05 15:33:44.962807 | controller -> localhost | |*.+o.= E = | 2025-12-05 15:33:44.962825 | controller -> localhost | |o++.o * B . | 2025-12-05 15:33:44.962843 | controller -> localhost | | +.. O o + | 2025-12-05 15:33:44.962861 | controller -> localhost | |o . * + S . | 2025-12-05 15:33:44.962879 | controller -> localhost | |.o + o . | 2025-12-05 15:33:44.962896 | controller -> localhost | |o . | 2025-12-05 15:33:44.962916 | controller -> localhost | |. | 2025-12-05 15:33:44.962934 | controller -> localhost | | | 2025-12-05 15:33:44.962952 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 15:33:44.962995 | controller -> localhost | ok: Runtime: 0:00:00.185464 2025-12-05 15:33:44.968860 | 2025-12-05 15:33:44.968920 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 15:33:44.997440 | controller | ok 2025-12-05 15:33:45.010118 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 15:33:45.020146 | 2025-12-05 15:33:45.020206 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 15:33:45.046090 | controller | skipping: Conditional result was False 2025-12-05 15:33:45.051616 | 2025-12-05 15:33:45.051749 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 15:33:45.509631 | controller | changed 2025-12-05 15:33:45.518667 | 2025-12-05 15:33:45.518752 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 15:33:45.789846 | controller | ok 2025-12-05 15:33:45.794826 | 2025-12-05 15:33:45.794886 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 15:33:46.635503 | controller | changed 2025-12-05 15:33:46.643343 | 2025-12-05 15:33:46.643513 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 15:33:47.472822 | controller | changed 2025-12-05 15:33:47.478820 | 2025-12-05 15:33:47.478885 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 15:33:47.503501 | controller | skipping: Conditional result was False 2025-12-05 15:33:47.510032 | 2025-12-05 15:33:47.510096 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 15:33:47.925775 | controller -> localhost | changed 2025-12-05 15:33:47.942300 | 2025-12-05 15:33:47.942394 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 15:33:48.243274 | controller -> localhost | Identity added: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/4a6000d2770c4f78b7b5dd2b3683d634_id_rsa (zuul-build-sshkey) 2025-12-05 15:33:48.243457 | controller -> localhost | ok: Runtime: 0:00:00.007496 2025-12-05 15:33:48.249143 | 2025-12-05 15:33:48.249203 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 15:33:48.617250 | controller | ok 2025-12-05 15:33:48.621956 | 2025-12-05 15:33:48.622016 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 15:33:48.667769 | controller | skipping: Conditional result was False 2025-12-05 15:33:48.682295 | 2025-12-05 15:33:48.682379 | TASK [include_role : validate-host] 2025-12-05 15:33:48.716150 | controller | ok 2025-12-05 15:33:48.735131 | 2025-12-05 15:33:48.735195 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 15:33:48.762863 | controller | ok 2025-12-05 15:33:48.767357 | 2025-12-05 15:33:48.767412 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 15:33:49.143393 | controller -> localhost | ok 2025-12-05 15:33:49.150272 | 2025-12-05 15:33:49.150344 | TASK [validate-host : Collect information about the host] 2025-12-05 15:33:49.909321 | controller | ok 2025-12-05 15:33:49.920999 | 2025-12-05 15:33:49.921058 | TASK [validate-host : Sanitize hostname] 2025-12-05 15:33:49.979621 | controller | ok 2025-12-05 15:33:49.984461 | 2025-12-05 15:33:49.984519 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 15:33:50.531317 | controller -> localhost | changed 2025-12-05 15:33:50.536699 | 2025-12-05 15:33:50.536766 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 15:33:50.997125 | controller | ok 2025-12-05 15:33:51.002911 | 2025-12-05 15:33:51.002976 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 15:33:51.542463 | controller -> localhost | changed 2025-12-05 15:33:51.556044 | 2025-12-05 15:33:51.556127 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 15:33:51.601723 | controller | skipping: Conditional result was False 2025-12-05 15:33:51.608333 | 2025-12-05 15:33:51.608395 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 15:33:51.671418 | controller | skipping: Conditional result was False 2025-12-05 15:33:51.677372 | 2025-12-05 15:33:51.677437 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:33:51.986431 | controller | ok: "logs" 2025-12-05 15:33:51.986668 | controller | ok: All items complete 2025-12-05 15:33:51.986712 | 2025-12-05 15:33:52.204535 | controller | ok: "artifacts" 2025-12-05 15:33:52.419414 | controller | ok: "docs" 2025-12-05 15:33:52.430476 | 2025-12-05 15:33:52.430550 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:33:52.698905 | controller | changed: "logs" 2025-12-05 15:33:52.952747 | controller | changed: "artifacts" 2025-12-05 15:33:53.174222 | controller | changed: "docs" 2025-12-05 15:33:53.248615 | 2025-12-05 15:33:53.248793 | PLAY RECAP 2025-12-05 15:33:53.248847 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 15:33:53.248879 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:33:53.248900 | 2025-12-05 15:33:53.511570 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:33:53.512384 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:33:54.304579 | 2025-12-05 15:33:54.304697 | PLAY [localhost] 2025-12-05 15:33:54.325132 | 2025-12-05 15:33:54.325203 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 15:33:54.712836 | localhost | ok 2025-12-05 15:33:54.719568 | 2025-12-05 15:33:54.719647 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 15:33:55.530901 | localhost | changed 2025-12-05 15:33:55.559453 | 2025-12-05 15:33:55.559579 | PLAY [all] 2025-12-05 15:33:55.577210 | 2025-12-05 15:33:55.577281 | TASK [include_role : prepare-workspace] 2025-12-05 15:33:55.622493 | controller | ok 2025-12-05 15:33:55.637751 | 2025-12-05 15:33:55.637824 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 15:33:56.074861 | controller | ok 2025-12-05 15:33:56.098157 | 2025-12-05 15:33:56.098238 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 15:33:57.827724 | controller | Output suppressed because no_log was given 2025-12-05 15:33:57.837318 | 2025-12-05 15:33:57.837385 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:33:58.094751 | controller | changed: "logs" 2025-12-05 15:33:58.301399 | controller | changed: "artifacts" 2025-12-05 15:33:58.531924 | controller | changed: "docs" 2025-12-05 15:33:58.548773 | 2025-12-05 15:33:58.548958 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:33:58.829206 | controller | changed: "logs" 2025-12-05 15:33:58.829641 | controller | changed: All items complete 2025-12-05 15:33:58.829722 | 2025-12-05 15:33:59.046475 | controller | changed: "artifacts" 2025-12-05 15:33:59.299570 | controller | changed: "docs" 2025-12-05 15:33:59.315601 | 2025-12-05 15:33:59.315719 | TASK [Check if worker can sudo] 2025-12-05 15:33:59.857029 | controller | ok: Runtime: 0:00:00.036383 2025-12-05 15:33:59.863012 | 2025-12-05 15:33:59.863107 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 15:33:59.928351 | controller | skipping: Conditional result was False 2025-12-05 15:33:59.934715 | 2025-12-05 15:33:59.934788 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 15:34:00.027775 | controller | ok 2025-12-05 15:34:00.048711 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 15:34:00.056490 | 2025-12-05 15:34:00.056574 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 15:34:00.407062 | controller | ok 2025-12-05 15:34:00.417609 | 2025-12-05 15:34:00.417714 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 15:34:00.473425 | controller | ok: "/var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 15:34:00.489667 | 2025-12-05 15:34:00.489769 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 15:34:01.333957 | controller | changed 2025-12-05 15:34:01.349540 | 2025-12-05 15:34:01.349674 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 15:34:01.416055 | controller | ok: "/var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 15:34:01.416214 | controller | ok: All items complete 2025-12-05 15:34:01.416240 | 2025-12-05 15:34:01.469742 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 15:34:01.479255 | 2025-12-05 15:34:01.479324 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 15:34:02.316203 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 15:34:03.194206 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 15:34:03.218097 | 2025-12-05 15:34:03.218245 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 15:34:03.840073 | controller | changed: section and option added 2025-12-05 15:34:03.859488 | 2025-12-05 15:34:03.859557 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 15:34:04.496506 | controller | 29 files removed 2025-12-05 15:34:04.496767 | controller | ok: Item: dnf clean all Runtime: 0:00:00.282588 2025-12-05 15:34:04.496878 | controller | changed: All items complete 2025-12-05 15:34:04.496903 | 2025-12-05 15:34:15.573853 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-05 15:34:15.573980 | controller | DNF version: 4.14.0 2025-12-05 15:34:15.574014 | controller | cachedir: /var/cache/dnf 2025-12-05 15:34:15.574042 | controller | Making cache files for all metadata files. 2025-12-05 15:34:15.574069 | controller | baseos: has expired and will be refreshed. 2025-12-05 15:34:15.574094 | controller | appstream: has expired and will be refreshed. 2025-12-05 15:34:15.574118 | controller | crb: has expired and will be refreshed. 2025-12-05 15:34:15.574154 | controller | extras-common: has expired and will be refreshed. 2025-12-05 15:34:15.574179 | controller | repo: downloading from remote: baseos 2025-12-05 15:34:15.574203 | controller | CentOS Stream 9 - BaseOS 57 MB/s | 8.8 MB 00:00 2025-12-05 15:34:15.574227 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 15:34:15.574250 | controller | repo: downloading from remote: appstream 2025-12-05 15:34:15.574274 | controller | CentOS Stream 9 - AppStream 84 MB/s | 25 MB 00:00 2025-12-05 15:34:15.574297 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 15:34:15.574320 | controller | repo: downloading from remote: crb 2025-12-05 15:34:15.574343 | controller | CentOS Stream 9 - CRB 73 MB/s | 7.3 MB 00:00 2025-12-05 15:34:15.574367 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 15:34:15.574391 | controller | repo: downloading from remote: extras-common 2025-12-05 15:34:15.574414 | controller | CentOS Stream 9 - Extras packages 630 kB/s | 20 kB 00:00 2025-12-05 15:34:15.574438 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 15:34:15.574461 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 15:34:15.574485 | controller | Completion plugin: Generating completion cache... 2025-12-05 15:34:15.574508 | controller | Metadata cache created. 2025-12-05 15:34:15.574542 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.833023 2025-12-05 15:34:15.600404 | 2025-12-05 15:34:15.600541 | PLAY RECAP 2025-12-05 15:34:15.600624 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 15:34:15.600709 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:34:15.600760 | 2025-12-05 15:34:15.763275 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:34:15.764109 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:34:16.373009 | 2025-12-05 15:34:16.373178 | PLAY [all] 2025-12-05 15:34:16.393209 | 2025-12-05 15:34:16.393348 | TASK [Install binary dependencies] 2025-12-05 15:34:16.456980 | controller | ok 2025-12-05 15:34:16.497380 | 2025-12-05 15:34:16.497500 | TASK [bindep : Include find tasks] 2025-12-05 15:34:16.527300 | controller | ok 2025-12-05 15:34:16.535011 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 15:34:16.554447 | 2025-12-05 15:34:16.554513 | TASK [bindep : Look for bindep.txt] 2025-12-05 15:34:16.918661 | controller | ok 2025-12-05 15:34:16.931922 | 2025-12-05 15:34:16.932015 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:17.007611 | controller | ok 2025-12-05 15:34:17.012900 | 2025-12-05 15:34:17.012964 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 15:34:17.039345 | controller | skipping: Conditional result was False 2025-12-05 15:34:17.045080 | 2025-12-05 15:34:17.045148 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:17.069150 | controller | skipping: Conditional result was False 2025-12-05 15:34:17.075283 | 2025-12-05 15:34:17.075347 | TASK [bindep : Look for bindep fallback file] 2025-12-05 15:34:17.099197 | controller | skipping: Conditional result was False 2025-12-05 15:34:17.105363 | 2025-12-05 15:34:17.105428 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:17.129402 | controller | skipping: Conditional result was False 2025-12-05 15:34:17.135190 | 2025-12-05 15:34:17.135255 | TASK [bindep : Include bindep tasks] 2025-12-05 15:34:17.166073 | controller | ok 2025-12-05 15:34:17.172632 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 15:34:17.180337 | 2025-12-05 15:34:17.180396 | TASK [bindep : Look for bindep command] 2025-12-05 15:34:17.204049 | controller | skipping: Conditional result was False 2025-12-05 15:34:17.210346 | 2025-12-05 15:34:17.210406 | TASK [bindep : Check for system bindep] 2025-12-05 15:34:17.738951 | controller | ok: Runtime: 0:00:00.005943 2025-12-05 15:34:17.751270 | 2025-12-05 15:34:17.751407 | TASK [bindep : Define bindep_command fact] 2025-12-05 15:34:17.789015 | controller | skipping: Conditional result was False 2025-12-05 15:34:17.802312 | 2025-12-05 15:34:17.802448 | TASK [bindep : Include install tasks] 2025-12-05 15:34:17.865725 | controller | ok 2025-12-05 15:34:17.889300 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 15:34:17.906499 | 2025-12-05 15:34:17.906627 | TASK [bindep : Create temp dir for bindep] 2025-12-05 15:34:18.255151 | controller | changed 2025-12-05 15:34:18.266360 | 2025-12-05 15:34:18.266442 | TASK [Ensure we have pip dependencies] 2025-12-05 15:34:18.297890 | controller | ok 2025-12-05 15:34:18.330896 | 2025-12-05 15:34:18.331027 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 10:34:18.625304 | controller | /usr/bin/pip3 2025-12-05 10:34:18.645363 | controller | /usr/bin/python3: No module named wheel 2025-12-05 15:34:18.861297 | controller | ok: Runtime: 0:00:00.029517 2025-12-05 15:34:18.867136 | 2025-12-05 15:34:18.867201 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 15:34:18.913312 | controller | ok: "/var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 15:34:18.929790 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 15:34:18.945746 | 2025-12-05 15:34:18.946165 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 15:34:20.861049 | controller | changed 2025-12-05 15:34:20.866443 | 2025-12-05 15:34:20.866503 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 15:34:20.927835 | controller | skipping: Conditional result was False 2025-12-05 15:34:20.942374 | 2025-12-05 15:34:20.942476 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 15:34:20.989279 | controller | skipping: Conditional result was False 2025-12-05 15:34:21.002985 | 2025-12-05 15:34:21.003082 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 15:34:21.049353 | controller | skipping: Conditional result was False 2025-12-05 15:34:21.061965 | 2025-12-05 15:34:21.062108 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 15:34:21.077921 | controller | skipping: Conditional result was False 2025-12-05 15:34:21.087270 | 2025-12-05 15:34:21.087357 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 15:34:21.624239 | controller | skipping: Conditional result was False 2025-12-05 15:34:21.638370 | 2025-12-05 15:34:21.638530 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 15:34:21.676431 | controller | skipping: Conditional result was False 2025-12-05 15:34:21.690265 | 2025-12-05 15:34:21.690407 | TASK [ensure-pip : Install pip from source] 2025-12-05 15:34:21.728299 | controller | skipping: Conditional result was False 2025-12-05 15:34:21.745303 | 2025-12-05 15:34:21.745402 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 10:34:22.052361 | controller | /usr/bin/python3 2025-12-05 15:34:22.296255 | controller | ok: Runtime: 0:00:00.004127 2025-12-05 15:34:22.308363 | 2025-12-05 15:34:22.308496 | TASK [ensure-pip : Set host default] 2025-12-05 15:34:22.387087 | controller | ok 2025-12-05 15:34:22.398247 | 2025-12-05 15:34:22.398382 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 15:34:22.456055 | controller | ok 2025-12-05 15:34:22.469662 | 2025-12-05 15:34:22.469782 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 15:34:26.886358 | controller | changed 2025-12-05 15:34:26.897997 | 2025-12-05 15:34:26.898138 | TASK [bindep : Define bindep_command] 2025-12-05 15:34:26.946279 | controller | ok 2025-12-05 15:34:26.960634 | 2025-12-05 15:34:26.960842 | LOOP [bindep : Include package tasks] 2025-12-05 15:34:27.030109 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 15:34:27.030394 | controller | ok: All items complete 2025-12-05 15:34:27.030433 | 2025-12-05 15:34:27.050272 | controller | included: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 15:34:27.066155 | 2025-12-05 15:34:27.066243 | TASK [bindep : Define bindep_run fact] 2025-12-05 15:34:27.097750 | controller | ok 2025-12-05 15:34:27.104791 | 2025-12-05 15:34:27.104879 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 10:34:28.482488 | controller | podman 2025-12-05 10:34:28.522835 | controller | python3-jmespath 2025-12-05 10:34:28.522900 | controller | python3-libvirt 2025-12-05 10:34:28.522910 | controller | python3-lxml 2025-12-05 10:34:28.522921 | controller | python3-netaddr 2025-12-05 15:34:28.639513 | controller | ok: Runtime: 0:00:01.131988 2025-12-05 15:34:28.645340 | 2025-12-05 15:34:28.645405 | TASK [bindep : Install distro packages from bindep] 2025-12-05 15:35:43.262146 | controller | changed 2025-12-05 15:35:43.269164 | 2025-12-05 15:35:43.269232 | TASK [bindep : Check that packages are installed] 2025-12-05 15:35:44.882440 | controller | ok: Runtime: 0:00:01.157130 2025-12-05 15:35:44.888264 | 2025-12-05 15:35:44.888326 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 15:35:44.934100 | controller | skipping: Conditional result was False 2025-12-05 15:35:44.947414 | 2025-12-05 15:35:44.947484 | TASK [Run test-setup role] 2025-12-05 15:35:44.976232 | controller | ok 2025-12-05 15:35:45.010275 | 2025-12-05 15:35:45.010376 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 15:35:45.278915 | controller | ok 2025-12-05 15:35:45.287075 | 2025-12-05 15:35:45.287141 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 15:35:45.846820 | controller | skipping: Conditional result was False 2025-12-05 15:35:45.883545 | 2025-12-05 15:35:45.883647 | TASK [bindep : Remove bindep temp dir] 2025-12-05 15:35:46.245633 | controller | ok 2025-12-05 15:35:46.283144 | 2025-12-05 15:35:46.283275 | PLAY RECAP 2025-12-05 15:35:46.283342 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 15:35:46.283369 | 2025-12-05 15:35:46.443297 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:35:46.444207 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:35:47.079660 | 2025-12-05 15:35:47.079783 | PLAY [all] 2025-12-05 15:35:47.099704 | 2025-12-05 15:35:47.099781 | TASK [Abort when test_command variable is undefined] 2025-12-05 15:35:47.144488 | controller | skipping: Conditional result was False 2025-12-05 15:35:47.151239 | 2025-12-05 15:35:47.151315 | TASK [Convert test_command to list] 2025-12-05 15:35:47.186218 | controller | skipping: Conditional result was False 2025-12-05 15:35:47.193069 | 2025-12-05 15:35:47.193152 | TASK [Use test_command list] 2025-12-05 15:35:47.243078 | controller | ok 2025-12-05 15:35:47.249535 | 2025-12-05 15:35:47.249620 | LOOP [Run test_command] 2025-12-05 15:35:47.683773 | controller | no check to run 2025-12-05 15:35:47.683945 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004409 2025-12-05 15:35:47.737167 | 2025-12-05 15:35:47.737266 | PLAY RECAP 2025-12-05 15:35:47.737352 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:35:47.737376 | 2025-12-05 15:35:47.838396 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:35:47.839382 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:35:48.513769 | 2025-12-05 15:35:48.513869 | PLAY [all] 2025-12-05 15:35:48.533910 | 2025-12-05 15:35:48.533990 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 15:35:48.919454 | controller | changed: non-zero return code 2025-12-05 15:35:48.927419 | 2025-12-05 15:35:48.927491 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 15:35:48.957010 | controller | skipping: Conditional result was False 2025-12-05 15:35:48.963193 | 2025-12-05 15:35:48.963271 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 15:35:48.983733 | 2025-12-05 15:35:48.983869 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 15:35:49.016883 | 2025-12-05 15:35:49.017027 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 15:35:49.039964 | controller | skipping: Conditional result was False 2025-12-05 15:35:49.046695 | 2025-12-05 15:35:49.046760 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 15:35:49.080557 | 2025-12-05 15:35:49.080737 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 15:35:49.095204 | controller | skipping: Conditional result was False 2025-12-05 15:35:49.101376 | 2025-12-05 15:35:49.101444 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 15:35:49.115499 | controller | skipping: Conditional result was False 2025-12-05 15:35:49.121402 | 2025-12-05 15:35:49.121468 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 15:35:49.144845 | controller | skipping: Conditional result was False 2025-12-05 15:35:49.183432 | 2025-12-05 15:35:49.183518 | PLAY RECAP 2025-12-05 15:35:49.183559 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 15:35:49.183579 | 2025-12-05 15:35:49.272852 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:35:49.273660 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:35:49.849351 | 2025-12-05 15:35:49.849465 | PLAY [all] 2025-12-05 15:35:49.868006 | 2025-12-05 15:35:49.868075 | TASK [include_role : fetch-output] 2025-12-05 15:35:49.896941 | controller | ok 2025-12-05 15:35:49.928203 | 2025-12-05 15:35:49.928303 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 15:35:49.972302 | controller | skipping: Conditional result was False 2025-12-05 15:35:49.977851 | 2025-12-05 15:35:49.977915 | TASK [fetch-output : Set log path for single node] 2025-12-05 15:35:50.006843 | controller | ok 2025-12-05 15:35:50.011842 | 2025-12-05 15:35:50.011904 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 15:35:50.580803 | controller -> localhost | ok: "/var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/logs" 2025-12-05 15:35:50.777894 | controller -> localhost | changed: "/var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/artifacts" 2025-12-05 15:35:51.062574 | controller -> localhost | changed: "/var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/docs" 2025-12-05 15:35:51.070924 | 2025-12-05 15:35:51.071036 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 15:35:51.687223 | controller | changed: .d..t...... ./ 2025-12-05 15:35:51.687422 | controller | changed: All items complete 2025-12-05 15:35:51.687449 | 2025-12-05 15:35:52.178194 | controller | changed: .d..t...... ./ 2025-12-05 15:35:52.664104 | controller | changed: .d..t...... ./ 2025-12-05 15:35:52.693398 | 2025-12-05 15:35:52.693611 | TASK [include_role : fetch-output-openshift] 2025-12-05 15:35:52.708136 | controller | skipping: Conditional result was False 2025-12-05 15:35:52.714807 | 2025-12-05 15:35:52.714874 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 15:35:53.128932 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008992 2025-12-05 15:35:53.370988 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.038040 2025-12-05 15:35:53.448487 | 2025-12-05 15:35:53.448582 | PLAY [all] 2025-12-05 15:35:53.465021 | 2025-12-05 15:35:53.465156 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 15:35:53.970182 | controller | changed 2025-12-05 15:35:54.013374 | 2025-12-05 15:35:54.013450 | PLAY RECAP 2025-12-05 15:35:54.013508 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:35:54.013536 | 2025-12-05 15:35:54.116611 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:35:54.122114 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 15:35:54.712986 | 2025-12-05 15:35:54.713091 | PLAY [localhost] 2025-12-05 15:35:54.730569 | 2025-12-05 15:35:54.730661 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 15:35:55.110638 | localhost | changed 2025-12-05 15:35:55.115769 | 2025-12-05 15:35:55.116275 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 15:35:55.137706 | localhost | ok 2025-12-05 15:35:55.145743 | 2025-12-05 15:35:55.145809 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 15:35:55.524070 | localhost | changed 2025-12-05 15:35:55.534725 | 2025-12-05 15:35:55.534868 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 15:35:56.292082 | localhost | changed 2025-12-05 15:35:56.311250 | 2025-12-05 15:35:56.311381 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 15:35:56.716302 | localhost | Identity added: /var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/tmp/ansible.ttswqwyj (/var/lib/zuul/builds/4a6000d2770c4f78b7b5dd2b3683d634/work/tmp/ansible.ttswqwyj) 2025-12-05 15:35:56.716491 | localhost | ok: Runtime: 0:00:00.007921 2025-12-05 15:35:56.720874 | 2025-12-05 15:35:56.720938 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 15:35:56.988397 | localhost | ok: Runtime: 0:00:00.009063 2025-12-05 15:35:56.994090 | 2025-12-05 15:35:56.994154 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 15:35:57.050905 | localhost | changed 2025-12-05 15:35:57.062049 | 2025-12-05 15:35:57.062133 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 15:35:57.466399 | localhost | changed 2025-12-05 15:35:57.490746 | 2025-12-05 15:35:57.490852 | PLAY [localhost] 2025-12-05 15:35:57.502710 | 2025-12-05 15:35:57.502789 | TASK [Generate bulk log download script] 2025-12-05 15:35:57.522509 | localhost | ok 2025-12-05 15:35:57.534570 | 2025-12-05 15:35:57.534637 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 15:35:57.561987 | localhost | ok: All assertions passed 2025-12-05 15:35:57.566527 | 2025-12-05 15:35:57.566585 | TASK [local-log-download : Create download script] 2025-12-05 15:35:57.957660 | localhost -> localhost | changed 2025-12-05 15:35:57.970178 | 2025-12-05 15:35:57.970259 | TASK [Register quick-download link] 2025-12-05 15:35:57.990989 | localhost | ok 2025-12-05 15:35:58.057285 | 2025-12-05 15:35:58.057411 | PLAY [logserver.rdoproject.org] 2025-12-05 15:35:58.071418 | 2025-12-05 15:35:58.071496 | TASK [Set zuul-log-path fact] 2025-12-05 15:35:58.090268 | logserver.rdoproject.org | ok 2025-12-05 15:35:58.100252 | 2025-12-05 15:35:58.100314 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:35:58.158124 | logserver.rdoproject.org | ok 2025-12-05 15:35:58.164069 | 2025-12-05 15:35:58.164130 | TASK [upload-logs : Create log directories] 2025-12-05 15:35:58.884021 | logserver.rdoproject.org | changed 2025-12-05 15:35:58.887181 | 2025-12-05 15:35:58.887241 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 15:35:59.187265 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005475 2025-12-05 15:35:59.197706 | 2025-12-05 15:35:59.197841 | TASK [upload-logs : Upload logs to log server] 2025-12-05 15:35:59.870175 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 15:35:59.874184 | 2025-12-05 15:35:59.874249 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 15:35:59.914374 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:59.926392 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:59.931726 | 2025-12-05 15:35:59.931837 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 15:35:59.975120 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:59.975379 | 2025-12-05 15:35:59.978745 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:59.983955 | 2025-12-05 15:35:59.984063 | LOOP [upload-logs : Upload console log and json output]