2025-10-08 12:09:54.135876 | Job console starting... 2025-10-08 12:09:54.154626 | Updating repositories 2025-10-08 12:09:54.199398 | Preparing job workspace 2025-10-08 12:09:57.790823 | Running Ansible setup... 2025-10-08 12:10:02.056502 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 12:10:02.694990 | 2025-10-08 12:10:02.695139 | PLAY [localhost] 2025-10-08 12:10:02.704055 | 2025-10-08 12:10:02.704134 | TASK [Gathering Facts] 2025-10-08 12:10:03.683130 | localhost | ok 2025-10-08 12:10:03.705361 | 2025-10-08 12:10:03.705609 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-08 12:10:04.160034 | localhost -> localhost | changed 2025-10-08 12:10:04.166324 | 2025-10-08 12:10:04.166401 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-08 12:10:05.023948 | localhost -> localhost | changed 2025-10-08 12:10:05.033676 | 2025-10-08 12:10:05.033826 | TASK [Setup log path fact] 2025-10-08 12:10:05.057170 | localhost | ok 2025-10-08 12:10:05.070765 | 2025-10-08 12:10:05.070908 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 12:10:05.099805 | localhost | ok 2025-10-08 12:10:05.107963 | 2025-10-08 12:10:05.108147 | TASK [emit-job-header : Print job information] 2025-10-08 12:10:05.137247 | # Job Information 2025-10-08 12:10:05.137448 | Ansible Version: 2.15.12 2025-10-08 12:10:05.137487 | Job: cifmw-molecule-cifmw_setup 2025-10-08 12:10:05.137517 | Pipeline: github-check 2025-10-08 12:10:05.137544 | Executor: ze01.softwarefactory-project.io 2025-10-08 12:10:05.137572 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-08 12:10:05.137600 | Log URL (when completed): https://logserver.rdoproject.org/49b/rdoproject.org/49b3ad482f064cb5a0e094d5f5dc2d66/ 2025-10-08 12:10:05.137626 | Event ID: 809f8c00-a43f-11f0-9dc5-9cf6e8dba5cd 2025-10-08 12:10:05.141553 | 2025-10-08 12:10:05.141637 | LOOP [emit-job-header : Print node information] 2025-10-08 12:10:05.272000 | localhost | ok: 2025-10-08 12:10:05.272298 | localhost | # Node Information 2025-10-08 12:10:05.272354 | localhost | Inventory Hostname: controller 2025-10-08 12:10:05.272401 | localhost | Hostname: np0005476060 2025-10-08 12:10:05.272442 | localhost | Username: zuul 2025-10-08 12:10:05.272485 | localhost | Distro: CentOS 9 2025-10-08 12:10:05.272524 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-08 12:10:05.272561 | localhost | Region: RegionOne 2025-10-08 12:10:05.272596 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-08 12:10:05.272632 | localhost | Product Name: OpenStack Nova 2025-10-08 12:10:05.272668 | localhost | Interface IP: 38.129.56.205 2025-10-08 12:10:05.310645 | 2025-10-08 12:10:05.310784 | PLAY [all] 2025-10-08 12:10:05.318108 | 2025-10-08 12:10:05.318201 | TASK [Gather network facts] 2025-10-08 12:10:05.776843 | controller | ok 2025-10-08 12:10:05.791007 | 2025-10-08 12:10:05.791105 | TASK [include_role : start-zuul-console] 2025-10-08 12:10:05.810079 | controller | ok 2025-10-08 12:10:05.822136 | 2025-10-08 12:10:05.822205 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-08 12:10:06.195826 | controller | ok 2025-10-08 12:10:06.230512 | 2025-10-08 12:10:06.230639 | TASK [include_role : add-build-sshkey] 2025-10-08 12:10:06.259533 | controller | ok 2025-10-08 12:10:06.273047 | 2025-10-08 12:10:06.273169 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-08 12:10:06.563054 | controller -> localhost | ok 2025-10-08 12:10:06.568910 | 2025-10-08 12:10:06.568974 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-08 12:10:06.588836 | controller | ok 2025-10-08 12:10:06.603603 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-08 12:10:06.609414 | 2025-10-08 12:10:06.609475 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-08 12:10:07.543091 | controller -> localhost | Generating public/private rsa key pair. 2025-10-08 12:10:07.543728 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/49b3ad482f064cb5a0e094d5f5dc2d66_id_rsa. 2025-10-08 12:10:07.543772 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/49b3ad482f064cb5a0e094d5f5dc2d66_id_rsa.pub. 2025-10-08 12:10:07.543844 | controller -> localhost | The key fingerprint is: 2025-10-08 12:10:07.543871 | controller -> localhost | SHA256:XJS7gu9S9fa0Vm7b7i65Vq4wQfTuqu+qb19jLf3mhs0 zuul-build-sshkey 2025-10-08 12:10:07.544154 | controller -> localhost | The key's randomart image is: 2025-10-08 12:10:07.544194 | controller -> localhost | +---[RSA 3072]----+ 2025-10-08 12:10:07.544289 | controller -> localhost | | ... | 2025-10-08 12:10:07.544319 | controller -> localhost | | ... . | 2025-10-08 12:10:07.544338 | controller -> localhost | | ... . | 2025-10-08 12:10:07.544356 | controller -> localhost | | . .o. . | 2025-10-08 12:10:07.544373 | controller -> localhost | | .S. o. . | 2025-10-08 12:10:07.544390 | controller -> localhost | | . o . oo.oo| 2025-10-08 12:10:07.544407 | controller -> localhost | | o . .oo*@o| 2025-10-08 12:10:07.544423 | controller -> localhost | | . . . *OoE| 2025-10-08 12:10:07.544439 | controller -> localhost | | oo++*=oo&O| 2025-10-08 12:10:07.544455 | controller -> localhost | +----[SHA256]-----+ 2025-10-08 12:10:07.544503 | controller -> localhost | ok: Runtime: 0:00:00.535934 2025-10-08 12:10:07.551552 | 2025-10-08 12:10:07.551639 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-08 12:10:07.575617 | controller | ok 2025-10-08 12:10:07.589571 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-08 12:10:07.600533 | 2025-10-08 12:10:07.601155 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-08 12:10:07.627622 | controller | skipping: Conditional result was False 2025-10-08 12:10:07.635905 | 2025-10-08 12:10:07.635986 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-08 12:10:08.135517 | controller | changed 2025-10-08 12:10:08.141164 | 2025-10-08 12:10:08.141278 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-08 12:10:08.406570 | controller | ok 2025-10-08 12:10:08.416963 | 2025-10-08 12:10:08.417136 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-08 12:10:09.230703 | controller | changed 2025-10-08 12:10:09.236418 | 2025-10-08 12:10:09.236514 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-08 12:10:10.151918 | controller | changed 2025-10-08 12:10:10.157873 | 2025-10-08 12:10:10.157934 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-08 12:10:10.182512 | controller | skipping: Conditional result was False 2025-10-08 12:10:10.188289 | 2025-10-08 12:10:10.188364 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-08 12:10:10.658903 | controller -> localhost | changed 2025-10-08 12:10:10.673668 | 2025-10-08 12:10:10.673902 | TASK [add-build-sshkey : Add back temp key] 2025-10-08 12:10:11.105729 | controller -> localhost | Identity added: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/49b3ad482f064cb5a0e094d5f5dc2d66_id_rsa (zuul-build-sshkey) 2025-10-08 12:10:11.106031 | controller -> localhost | ok: Runtime: 0:00:00.029805 2025-10-08 12:10:11.112068 | 2025-10-08 12:10:11.112139 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-08 12:10:11.602464 | controller | ok 2025-10-08 12:10:11.608183 | 2025-10-08 12:10:11.608280 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-08 12:10:11.642866 | controller | skipping: Conditional result was False 2025-10-08 12:10:11.658764 | 2025-10-08 12:10:11.658875 | TASK [include_role : validate-host] 2025-10-08 12:10:11.693720 | controller | ok 2025-10-08 12:10:11.726258 | 2025-10-08 12:10:11.726368 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-08 12:10:11.771080 | controller | ok 2025-10-08 12:10:11.788416 | 2025-10-08 12:10:11.788584 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-08 12:10:12.138903 | controller -> localhost | ok 2025-10-08 12:10:12.144833 | 2025-10-08 12:10:12.144914 | TASK [validate-host : Collect information about the host] 2025-10-08 12:10:12.969055 | controller | ok 2025-10-08 12:10:12.981120 | 2025-10-08 12:10:12.981210 | TASK [validate-host : Sanitize hostname] 2025-10-08 12:10:13.079125 | controller | ok 2025-10-08 12:10:13.084459 | 2025-10-08 12:10:13.084537 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-08 12:10:13.539736 | controller -> localhost | changed 2025-10-08 12:10:13.561079 | 2025-10-08 12:10:13.561230 | TASK [validate-host : Collect information about zuul worker] 2025-10-08 12:10:13.984948 | controller | ok 2025-10-08 12:10:13.996241 | 2025-10-08 12:10:13.996397 | TASK [validate-host : Write out all zuul information for each host] 2025-10-08 12:10:14.505353 | controller -> localhost | changed 2025-10-08 12:10:14.515417 | 2025-10-08 12:10:14.515516 | TASK [include_role : prepare-workspace-openshift] 2025-10-08 12:10:14.530432 | controller | skipping: Conditional result was False 2025-10-08 12:10:14.536803 | 2025-10-08 12:10:14.536918 | TASK [include_role : remove-zuul-sshkey] 2025-10-08 12:10:14.555305 | controller | skipping: Conditional result was False 2025-10-08 12:10:14.562093 | 2025-10-08 12:10:14.562247 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 12:10:14.834968 | controller | ok: "logs" 2025-10-08 12:10:14.835321 | controller | ok: All items complete 2025-10-08 12:10:14.835357 | 2025-10-08 12:10:15.100878 | controller | ok: "artifacts" 2025-10-08 12:10:15.311138 | controller | ok: "docs" 2025-10-08 12:10:15.330900 | 2025-10-08 12:10:15.331146 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 12:10:15.656258 | controller | changed: "logs" 2025-10-08 12:10:16.376542 | controller | changed: "artifacts" 2025-10-08 12:10:16.633551 | controller | changed: "docs" 2025-10-08 12:10:16.684481 | 2025-10-08 12:10:16.684695 | PLAY RECAP 2025-10-08 12:10:16.684790 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-08 12:10:16.684838 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 12:10:16.684866 | 2025-10-08 12:10:16.823222 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-08 12:10:16.824873 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 12:10:17.454462 | 2025-10-08 12:10:17.454593 | PLAY [localhost] 2025-10-08 12:10:17.470933 | 2025-10-08 12:10:17.471082 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-08 12:10:17.925793 | localhost | ok 2025-10-08 12:10:17.930869 | 2025-10-08 12:10:17.930944 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-08 12:10:18.615702 | localhost | changed 2025-10-08 12:10:18.635886 | 2025-10-08 12:10:18.636034 | PLAY [all] 2025-10-08 12:10:18.651837 | 2025-10-08 12:10:18.651985 | TASK [include_role : prepare-workspace] 2025-10-08 12:10:18.681771 | controller | ok 2025-10-08 12:10:18.695898 | 2025-10-08 12:10:18.695974 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-08 12:10:19.188889 | controller | ok 2025-10-08 12:10:19.198905 | 2025-10-08 12:10:19.199057 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-08 12:10:20.970198 | controller | Output suppressed because no_log was given 2025-10-08 12:10:20.979587 | 2025-10-08 12:10:20.979654 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-08 12:10:21.244117 | controller | changed: "logs" 2025-10-08 12:10:21.490400 | controller | changed: "artifacts" 2025-10-08 12:10:21.700831 | controller | changed: "docs" 2025-10-08 12:10:21.715394 | 2025-10-08 12:10:21.715533 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-08 12:10:22.003680 | controller | changed: "logs" 2025-10-08 12:10:22.004373 | controller | changed: All items complete 2025-10-08 12:10:22.004455 | 2025-10-08 12:10:22.243972 | controller | changed: "artifacts" 2025-10-08 12:10:22.464749 | controller | changed: "docs" 2025-10-08 12:10:22.505534 | 2025-10-08 12:10:22.505789 | TASK [Check if worker can sudo] 2025-10-08 12:10:23.078608 | controller | ok: Runtime: 0:00:00.051128 2025-10-08 12:10:23.092911 | 2025-10-08 12:10:23.093097 | TASK [configure-mirrors : Gather needed facts] 2025-10-08 12:10:23.160669 | controller | skipping: Conditional result was False 2025-10-08 12:10:23.166497 | 2025-10-08 12:10:23.166564 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-08 12:10:23.226618 | controller | ok 2025-10-08 12:10:23.234140 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-08 12:10:23.242216 | 2025-10-08 12:10:23.242317 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-08 12:10:23.542065 | controller | ok 2025-10-08 12:10:23.550294 | 2025-10-08 12:10:23.550410 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-08 12:10:23.624988 | controller | ok: "/var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-08 12:10:23.633840 | 2025-10-08 12:10:23.633938 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-08 12:10:24.543491 | controller | changed 2025-10-08 12:10:24.557593 | 2025-10-08 12:10:24.557778 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-08 12:10:24.645129 | controller | ok: "/var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-08 12:10:24.645293 | controller | ok: All items complete 2025-10-08 12:10:24.645321 | 2025-10-08 12:10:24.691683 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-08 12:10:24.698491 | 2025-10-08 12:10:24.698572 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-08 12:10:25.562546 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-08 12:10:26.393290 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-08 12:10:26.415838 | 2025-10-08 12:10:26.416103 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-08 12:10:26.871404 | controller | changed: section and option added 2025-10-08 12:10:26.891104 | 2025-10-08 12:10:26.891269 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-08 12:10:27.803696 | controller | 29 files removed 2025-10-08 12:10:27.804208 | controller | ok: Item: dnf clean all Runtime: 0:00:00.588321 2025-10-08 12:10:27.804290 | controller | changed: All items complete 2025-10-08 12:10:27.804334 | 2025-10-08 12:10:39.720780 | 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-08 12:10:39.720932 | controller | DNF version: 4.14.0 2025-10-08 12:10:39.720959 | controller | cachedir: /var/cache/dnf 2025-10-08 12:10:39.720980 | controller | Making cache files for all metadata files. 2025-10-08 12:10:39.720998 | controller | baseos: has expired and will be refreshed. 2025-10-08 12:10:39.721031 | controller | appstream: has expired and will be refreshed. 2025-10-08 12:10:39.721054 | controller | crb: has expired and will be refreshed. 2025-10-08 12:10:39.721086 | controller | extras-common: has expired and will be refreshed. 2025-10-08 12:10:39.721103 | controller | repo: downloading from remote: baseos 2025-10-08 12:10:39.721120 | controller | CentOS Stream 9 - BaseOS 55 MB/s | 8.8 MB 00:00 2025-10-08 12:10:39.721136 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-08 12:10:39.721152 | controller | repo: downloading from remote: appstream 2025-10-08 12:10:39.721168 | controller | CentOS Stream 9 - AppStream 43 MB/s | 25 MB 00:00 2025-10-08 12:10:39.721184 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-08 12:10:39.721200 | controller | repo: downloading from remote: crb 2025-10-08 12:10:39.721215 | controller | CentOS Stream 9 - CRB 47 MB/s | 7.1 MB 00:00 2025-10-08 12:10:39.721231 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-08 12:10:39.721247 | controller | repo: downloading from remote: extras-common 2025-10-08 12:10:39.721263 | controller | CentOS Stream 9 - Extras packages 905 kB/s | 20 kB 00:00 2025-10-08 12:10:39.721279 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-08 12:10:39.721294 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-08 12:10:39.721310 | controller | Completion plugin: Generating completion cache... 2025-10-08 12:10:39.721326 | controller | Metadata cache created. 2025-10-08 12:10:39.721352 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.651693 2025-10-08 12:10:39.753412 | 2025-10-08 12:10:39.753598 | PLAY RECAP 2025-10-08 12:10:39.753669 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-08 12:10:39.753705 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-08 12:10:39.753727 | 2025-10-08 12:10:39.919067 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-08 12:10:39.920501 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 12:10:40.527310 | 2025-10-08 12:10:40.527436 | PLAY [all] 2025-10-08 12:10:40.549303 | 2025-10-08 12:10:40.549428 | TASK [Install binary dependencies] 2025-10-08 12:10:40.630234 | controller | ok 2025-10-08 12:10:40.652247 | 2025-10-08 12:10:40.652430 | TASK [bindep : Include find tasks] 2025-10-08 12:10:40.693279 | controller | ok 2025-10-08 12:10:40.701136 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-08 12:10:40.707331 | 2025-10-08 12:10:40.707397 | TASK [bindep : Look for bindep.txt] 2025-10-08 12:10:41.138204 | controller | ok 2025-10-08 12:10:41.145482 | 2025-10-08 12:10:41.145618 | TASK [bindep : Define bindep_file fact] 2025-10-08 12:10:41.176823 | controller | ok 2025-10-08 12:10:41.182444 | 2025-10-08 12:10:41.182535 | TASK [bindep : Look for other-requirements.txt] 2025-10-08 12:10:41.207903 | controller | skipping: Conditional result was False 2025-10-08 12:10:41.215442 | 2025-10-08 12:10:41.215570 | TASK [bindep : Define bindep_file fact] 2025-10-08 12:10:41.241726 | controller | skipping: Conditional result was False 2025-10-08 12:10:41.248335 | 2025-10-08 12:10:41.248446 | TASK [bindep : Look for bindep fallback file] 2025-10-08 12:10:41.273706 | controller | skipping: Conditional result was False 2025-10-08 12:10:41.280293 | 2025-10-08 12:10:41.280401 | TASK [bindep : Define bindep_file fact] 2025-10-08 12:10:41.306930 | controller | skipping: Conditional result was False 2025-10-08 12:10:41.314034 | 2025-10-08 12:10:41.314201 | TASK [bindep : Include bindep tasks] 2025-10-08 12:10:41.349035 | controller | ok 2025-10-08 12:10:41.356473 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-08 12:10:41.365111 | 2025-10-08 12:10:41.365220 | TASK [bindep : Look for bindep command] 2025-10-08 12:10:41.390597 | controller | skipping: Conditional result was False 2025-10-08 12:10:41.397916 | 2025-10-08 12:10:41.398086 | TASK [bindep : Check for system bindep] 2025-10-08 12:10:41.931403 | controller | ok: Runtime: 0:00:00.008375 2025-10-08 12:10:41.940476 | 2025-10-08 12:10:41.940658 | TASK [bindep : Define bindep_command fact] 2025-10-08 12:10:41.978376 | controller | skipping: Conditional result was False 2025-10-08 12:10:41.988291 | 2025-10-08 12:10:41.988500 | TASK [bindep : Include install tasks] 2025-10-08 12:10:42.035221 | controller | ok 2025-10-08 12:10:42.048946 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-08 12:10:42.065270 | 2025-10-08 12:10:42.065482 | TASK [bindep : Create temp dir for bindep] 2025-10-08 12:10:42.475313 | controller | changed 2025-10-08 12:10:42.483872 | 2025-10-08 12:10:42.484028 | TASK [Ensure we have pip dependencies] 2025-10-08 12:10:42.510692 | controller | ok 2025-10-08 12:10:42.552294 | 2025-10-08 12:10:42.552593 | TASK [ensure-pip : Check if pip is installed] 2025-10-08 08:10:42.884006 | controller | /usr/bin/pip3 2025-10-08 08:10:42.907724 | controller | /usr/bin/python3: No module named wheel 2025-10-08 12:10:43.095216 | controller | ok: Runtime: 0:00:00.036736 2025-10-08 12:10:43.104009 | 2025-10-08 12:10:43.104253 | LOOP [ensure-pip : Install pip from packages] 2025-10-08 12:10:43.157346 | controller | ok: "/var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-08 12:10:43.167767 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-08 12:10:43.182460 | 2025-10-08 12:10:43.182650 | TASK [ensure-pip : Install Python 3 pip] 2025-10-08 12:10:45.908312 | controller | changed 2025-10-08 12:10:45.914063 | 2025-10-08 12:10:45.914150 | TASK [ensure-pip : Check for EPEL repository] 2025-10-08 12:10:45.960524 | controller | skipping: Conditional result was False 2025-10-08 12:10:45.967638 | 2025-10-08 12:10:45.967777 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-08 12:10:46.031135 | controller | skipping: Conditional result was False 2025-10-08 12:10:46.040713 | 2025-10-08 12:10:46.040848 | TASK [ensure-pip : Install Python 2 pip] 2025-10-08 12:10:46.099163 | controller | skipping: Conditional result was False 2025-10-08 12:10:46.109286 | 2025-10-08 12:10:46.109411 | TASK [ensure-pip : Ensure setuptools] 2025-10-08 12:10:46.126045 | controller | skipping: Conditional result was False 2025-10-08 12:10:46.133278 | 2025-10-08 12:10:46.133382 | TASK [ensure-pip : Check for ensurepip module] 2025-10-08 12:10:46.669004 | controller | skipping: Conditional result was False 2025-10-08 12:10:46.678602 | 2025-10-08 12:10:46.678749 | TASK [ensure-pip : Ensure python3-venv] 2025-10-08 12:10:46.704581 | controller | skipping: Conditional result was False 2025-10-08 12:10:46.713834 | 2025-10-08 12:10:46.713961 | TASK [ensure-pip : Install pip from source] 2025-10-08 12:10:46.730121 | controller | skipping: Conditional result was False 2025-10-08 12:10:46.744934 | 2025-10-08 12:10:46.745597 | TASK [ensure-pip : Probe for venv python full path] 2025-10-08 08:10:47.038669 | controller | /usr/bin/python3 2025-10-08 12:10:47.311473 | controller | ok: Runtime: 0:00:00.006414 2025-10-08 12:10:47.325008 | 2025-10-08 12:10:47.325262 | TASK [ensure-pip : Set host default] 2025-10-08 12:10:47.380600 | controller | ok 2025-10-08 12:10:47.388074 | 2025-10-08 12:10:47.388225 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-08 12:10:47.453734 | controller | ok 2025-10-08 12:10:47.468081 | 2025-10-08 12:10:47.468221 | TASK [bindep : Install bindep into temporary venv] 2025-10-08 12:10:52.748185 | controller | changed 2025-10-08 12:10:52.760095 | 2025-10-08 12:10:52.760228 | TASK [bindep : Define bindep_command] 2025-10-08 12:10:52.811222 | controller | ok 2025-10-08 12:10:52.824493 | 2025-10-08 12:10:52.824623 | LOOP [bindep : Include package tasks] 2025-10-08 12:10:52.912426 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-08 12:10:52.912873 | controller | ok: All items complete 2025-10-08 12:10:52.912963 | 2025-10-08 12:10:52.940585 | controller | included: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-08 12:10:52.965433 | 2025-10-08 12:10:52.965610 | TASK [bindep : Define bindep_run fact] 2025-10-08 12:10:53.009752 | controller | ok 2025-10-08 12:10:53.016783 | 2025-10-08 12:10:53.016877 | TASK [bindep : Get list of packages to install from bindep] 2025-10-08 08:10:54.556890 | controller | podman 2025-10-08 08:10:54.609705 | controller | python3-jmespath 2025-10-08 08:10:54.609869 | controller | python3-libvirt 2025-10-08 08:10:54.609886 | controller | python3-lxml 2025-10-08 08:10:54.609893 | controller | python3-netaddr 2025-10-08 12:10:55.052258 | controller | ok: Runtime: 0:00:01.334548 2025-10-08 12:10:55.066079 | 2025-10-08 12:10:55.066329 | TASK [bindep : Install distro packages from bindep] 2025-10-08 12:12:04.104827 | controller | changed 2025-10-08 12:12:04.111314 | 2025-10-08 12:12:04.111447 | TASK [bindep : Check that packages are installed] 2025-10-08 12:12:06.183521 | controller | ok: Runtime: 0:00:01.294962 2025-10-08 12:12:06.190713 | 2025-10-08 12:12:06.190845 | TASK [bindep : Fail if we cannot install all packages] 2025-10-08 12:12:06.259141 | controller | skipping: Conditional result was False 2025-10-08 12:12:06.277178 | 2025-10-08 12:12:06.277369 | TASK [Run test-setup role] 2025-10-08 12:12:06.318575 | controller | ok 2025-10-08 12:12:06.345587 | 2025-10-08 12:12:06.347959 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-08 12:12:06.639252 | controller | ok 2025-10-08 12:12:06.652693 | 2025-10-08 12:12:06.652896 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-08 12:12:07.213759 | controller | skipping: Conditional result was False 2025-10-08 12:12:07.250730 | 2025-10-08 12:12:07.250902 | TASK [bindep : Remove bindep temp dir] 2025-10-08 12:12:07.872716 | controller | ok 2025-10-08 12:12:07.927549 | 2025-10-08 12:12:07.927672 | PLAY RECAP 2025-10-08 12:12:07.927719 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-08 12:12:07.927740 | 2025-10-08 12:12:08.075418 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-08 12:12:08.076529 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 12:12:08.696564 | 2025-10-08 12:12:08.696721 | PLAY [all] 2025-10-08 12:12:08.721676 | 2025-10-08 12:12:08.721856 | TASK [Abort when test_command variable is undefined] 2025-10-08 12:12:08.768160 | controller | skipping: Conditional result was False 2025-10-08 12:12:08.775105 | 2025-10-08 12:12:08.775293 | TASK [Convert test_command to list] 2025-10-08 12:12:08.828524 | controller | skipping: Conditional result was False 2025-10-08 12:12:08.838597 | 2025-10-08 12:12:08.838743 | TASK [Use test_command list] 2025-10-08 12:12:08.894730 | controller | ok 2025-10-08 12:12:08.904769 | 2025-10-08 12:12:08.904939 | LOOP [Run test_command] 2025-10-08 12:12:09.329646 | controller | no check to run 2025-10-08 12:12:09.329865 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.007058 2025-10-08 12:12:09.352747 | 2025-10-08 12:12:09.352840 | PLAY RECAP 2025-10-08 12:12:09.352880 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 12:12:09.352900 | 2025-10-08 12:12:09.458371 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-08 12:12:09.459632 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 12:12:10.110429 | 2025-10-08 12:12:10.110573 | PLAY [all] 2025-10-08 12:12:10.132910 | 2025-10-08 12:12:10.133089 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-08 12:12:10.501253 | controller | changed: non-zero return code 2025-10-08 12:12:10.506563 | 2025-10-08 12:12:10.506669 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-08 12:12:10.532771 | controller | skipping: Conditional result was False 2025-10-08 12:12:10.542385 | 2025-10-08 12:12:10.542570 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-08 12:12:10.581817 | 2025-10-08 12:12:10.582087 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-08 12:12:10.618973 | 2025-10-08 12:12:10.619414 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-08 12:12:10.646387 | controller | skipping: Conditional result was False 2025-10-08 12:12:10.655651 | 2025-10-08 12:12:10.655830 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-08 12:12:10.691778 | 2025-10-08 12:12:10.692061 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-08 12:12:10.718979 | controller | skipping: Conditional result was False 2025-10-08 12:12:10.724983 | 2025-10-08 12:12:10.725417 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-08 12:12:10.760976 | controller | skipping: Conditional result was False 2025-10-08 12:12:10.773719 | 2025-10-08 12:12:10.773857 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-08 12:12:10.799869 | controller | skipping: Conditional result was False 2025-10-08 12:12:10.824975 | 2025-10-08 12:12:10.825071 | PLAY RECAP 2025-10-08 12:12:10.825116 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-08 12:12:10.825136 | 2025-10-08 12:12:10.943728 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-08 12:12:10.945101 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 12:12:11.533658 | 2025-10-08 12:12:11.533775 | PLAY [all] 2025-10-08 12:12:11.553404 | 2025-10-08 12:12:11.553540 | TASK [include_role : fetch-output] 2025-10-08 12:12:11.584099 | controller | ok 2025-10-08 12:12:11.605226 | 2025-10-08 12:12:11.605330 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-08 12:12:11.660256 | controller | skipping: Conditional result was False 2025-10-08 12:12:11.667055 | 2025-10-08 12:12:11.667124 | TASK [fetch-output : Set log path for single node] 2025-10-08 12:12:11.710766 | controller | ok 2025-10-08 12:12:11.719578 | 2025-10-08 12:12:11.719712 | LOOP [fetch-output : Ensure local output dirs] 2025-10-08 12:12:12.107803 | controller -> localhost | ok: "/var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/logs" 2025-10-08 12:12:12.329395 | controller -> localhost | changed: "/var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/artifacts" 2025-10-08 12:12:12.553036 | controller -> localhost | changed: "/var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/docs" 2025-10-08 12:12:12.569239 | 2025-10-08 12:12:12.569420 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-08 12:12:13.347469 | controller | changed: .d..t...... ./ 2025-10-08 12:12:13.347681 | controller | changed: All items complete 2025-10-08 12:12:13.347769 | 2025-10-08 12:12:13.864075 | controller | changed: .d..t...... ./ 2025-10-08 12:12:14.363072 | controller | changed: .d..t...... ./ 2025-10-08 12:12:14.389878 | 2025-10-08 12:12:14.390061 | TASK [include_role : fetch-output-openshift] 2025-10-08 12:12:14.420938 | controller | skipping: Conditional result was False 2025-10-08 12:12:14.428380 | 2025-10-08 12:12:14.428507 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-08 12:12:14.871862 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010424 2025-10-08 12:12:15.131512 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.011035 2025-10-08 12:12:15.166959 | 2025-10-08 12:12:15.167136 | PLAY [all] 2025-10-08 12:12:15.189370 | 2025-10-08 12:12:15.189486 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-08 12:12:15.718644 | controller | changed 2025-10-08 12:12:15.744113 | 2025-10-08 12:12:15.744229 | PLAY RECAP 2025-10-08 12:12:15.744330 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-08 12:12:15.744354 | 2025-10-08 12:12:15.884451 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-08 12:12:15.885315 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-08 12:12:16.678790 | 2025-10-08 12:12:16.678927 | PLAY [localhost] 2025-10-08 12:12:16.699803 | 2025-10-08 12:12:16.699944 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-08 12:12:17.212842 | localhost | changed 2025-10-08 12:12:17.224262 | 2025-10-08 12:12:17.224440 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-08 12:12:17.275078 | localhost | ok 2025-10-08 12:12:17.284503 | 2025-10-08 12:12:17.284606 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-08 12:12:17.843763 | localhost | changed 2025-10-08 12:12:17.851559 | 2025-10-08 12:12:17.851632 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-08 12:12:18.687515 | localhost | changed 2025-10-08 12:12:18.694157 | 2025-10-08 12:12:18.694222 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-08 12:12:19.168458 | localhost | Identity added: /var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/tmp/ansible.sitk9o7f (/var/lib/zuul/builds/49b3ad482f064cb5a0e094d5f5dc2d66/work/tmp/ansible.sitk9o7f) 2025-10-08 12:12:19.168833 | localhost | ok: Runtime: 0:00:00.008624 2025-10-08 12:12:19.181403 | 2025-10-08 12:12:19.181601 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-08 12:12:19.491172 | localhost | ok: Runtime: 0:00:00.005706 2025-10-08 12:12:19.496777 | 2025-10-08 12:12:19.496853 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-08 12:12:19.545933 | localhost | changed 2025-10-08 12:12:19.552814 | 2025-10-08 12:12:19.552886 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-08 12:12:20.033008 | localhost | changed 2025-10-08 12:12:20.060464 | 2025-10-08 12:12:20.060599 | PLAY [localhost] 2025-10-08 12:12:20.077776 | 2025-10-08 12:12:20.077884 | TASK [Generate bulk log download script] 2025-10-08 12:12:20.098703 | localhost | ok 2025-10-08 12:12:20.121412 | 2025-10-08 12:12:20.121545 | TASK [local-log-download : Check API endpoint is defined] 2025-10-08 12:12:20.152908 | localhost | ok: All assertions passed 2025-10-08 12:12:20.162238 | 2025-10-08 12:12:20.162357 | TASK [local-log-download : Create download script] 2025-10-08 12:12:20.589142 | localhost -> localhost | changed 2025-10-08 12:12:20.598932 | 2025-10-08 12:12:20.599044 | TASK [Register quick-download link] 2025-10-08 12:12:20.628455 | localhost | ok 2025-10-08 12:12:20.681575 | 2025-10-08 12:12:20.681692 | PLAY [logserver.rdoproject.org] 2025-10-08 12:12:20.691569 | 2025-10-08 12:12:20.691649 | TASK [Set zuul-log-path fact] 2025-10-08 12:12:20.707633 | logserver.rdoproject.org | ok 2025-10-08 12:12:20.717895 | 2025-10-08 12:12:20.718057 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-08 12:12:20.746089 | logserver.rdoproject.org | ok 2025-10-08 12:12:20.752790 | 2025-10-08 12:12:20.752866 | TASK [upload-logs : Create log directories] 2025-10-08 12:12:21.478653 | logserver.rdoproject.org | changed 2025-10-08 12:12:21.481880 | 2025-10-08 12:12:21.481945 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-08 12:12:21.771598 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006565 2025-10-08 12:12:21.777969 | 2025-10-08 12:12:21.778073 | TASK [upload-logs : Upload logs to log server] 2025-10-08 12:12:22.489680 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-08 12:12:22.492719 | 2025-10-08 12:12:22.492787 | LOOP [upload-logs : Compress console log and json output] 2025-10-08 12:12:22.557822 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:22.563758 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:22.572587 | 2025-10-08 12:12:22.572727 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-08 12:12:22.619332 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:22.619594 | 2025-10-08 12:12:22.620228 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-08 12:12:22.632185 | 2025-10-08 12:12:22.632328 | LOOP [upload-logs : Upload console log and json output]