2025-11-24 08:34:34.680812 | Job console starting... 2025-11-24 08:34:34.699207 | Updating repositories 2025-11-24 08:34:34.751063 | Preparing job workspace 2025-11-24 08:34:40.067210 | Running Ansible setup... 2025-11-24 08:34:45.366294 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-24 08:34:46.053622 | 2025-11-24 08:34:46.053826 | PLAY [localhost] 2025-11-24 08:34:46.063251 | 2025-11-24 08:34:46.063328 | TASK [Gathering Facts] 2025-11-24 08:34:47.176995 | localhost | ok 2025-11-24 08:34:47.194939 | 2025-11-24 08:34:47.195165 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-24 08:34:47.615518 | localhost -> localhost | changed 2025-11-24 08:34:47.622604 | 2025-11-24 08:34:47.622704 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-24 08:34:48.534207 | localhost -> localhost | changed 2025-11-24 08:34:48.546298 | 2025-11-24 08:34:48.546421 | TASK [Setup log path fact] 2025-11-24 08:34:48.566336 | localhost | ok 2025-11-24 08:34:48.578427 | 2025-11-24 08:34:48.578500 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-24 08:34:48.607326 | localhost | ok 2025-11-24 08:34:48.615257 | 2025-11-24 08:34:48.615327 | TASK [emit-job-header : Print job information] 2025-11-24 08:34:48.666065 | # Job Information 2025-11-24 08:34:48.666226 | Ansible Version: 2.15.12 2025-11-24 08:34:48.666254 | Job: cifmw-molecule-cifmw_setup 2025-11-24 08:34:48.666274 | Pipeline: github-check 2025-11-24 08:34:48.666293 | Executor: ze04.softwarefactory-project.io 2025-11-24 08:34:48.666314 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451 2025-11-24 08:34:48.666335 | Log URL (when completed): https://logserver.rdoproject.org/412/rdoproject.org/41267c6d517540dca0f2c5c9cb7a9f74/ 2025-11-24 08:34:48.666355 | Event ID: 2dae9040-c910-11f0-818a-433f9d14d6bc 2025-11-24 08:34:48.670083 | 2025-11-24 08:34:48.670148 | LOOP [emit-job-header : Print node information] 2025-11-24 08:34:48.786446 | localhost | ok: 2025-11-24 08:34:48.786753 | localhost | # Node Information 2025-11-24 08:34:48.786808 | localhost | Inventory Hostname: controller 2025-11-24 08:34:48.786865 | localhost | Hostname: np0005533175 2025-11-24 08:34:48.786903 | localhost | Username: zuul 2025-11-24 08:34:48.786939 | localhost | Distro: CentOS 9 2025-11-24 08:34:48.786970 | localhost | Provider: vexxhost-nodepool-tripleo 2025-11-24 08:34:48.787001 | localhost | Region: RegionOne 2025-11-24 08:34:48.787032 | localhost | Label: cloud-centos-9-stream-tripleo 2025-11-24 08:34:48.787061 | localhost | Product Name: OpenStack Nova 2025-11-24 08:34:48.787090 | localhost | Interface IP: 38.129.56.3 2025-11-24 08:34:48.828393 | 2025-11-24 08:34:48.828568 | PLAY [all] 2025-11-24 08:34:48.837842 | 2025-11-24 08:34:48.837929 | TASK [Gather network facts] 2025-11-24 08:34:49.330489 | controller | ok 2025-11-24 08:34:49.351652 | 2025-11-24 08:34:49.351761 | TASK [include_role : start-zuul-console] 2025-11-24 08:34:49.390273 | controller | ok 2025-11-24 08:34:49.409756 | 2025-11-24 08:34:49.409849 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-24 08:34:49.930189 | controller | ok 2025-11-24 08:34:49.939161 | 2025-11-24 08:34:49.939225 | TASK [include_role : add-build-sshkey] 2025-11-24 08:34:49.969920 | controller | ok 2025-11-24 08:34:49.984598 | 2025-11-24 08:34:49.984670 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-24 08:34:50.286510 | controller -> localhost | ok 2025-11-24 08:34:50.300499 | 2025-11-24 08:34:50.300652 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-24 08:34:50.341215 | controller | ok 2025-11-24 08:34:50.369617 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-24 08:34:50.378884 | 2025-11-24 08:34:50.378977 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-24 08:34:51.668846 | controller -> localhost | Generating public/private rsa key pair. 2025-11-24 08:34:51.669211 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/41267c6d517540dca0f2c5c9cb7a9f74_id_rsa. 2025-11-24 08:34:51.669280 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/41267c6d517540dca0f2c5c9cb7a9f74_id_rsa.pub. 2025-11-24 08:34:51.669329 | controller -> localhost | The key fingerprint is: 2025-11-24 08:34:51.669371 | controller -> localhost | SHA256:gA/JwAUHk+WXYxvfycrVkEtJNIQ/BdrfaDQ33rB881k zuul-build-sshkey 2025-11-24 08:34:51.669412 | controller -> localhost | The key's randomart image is: 2025-11-24 08:34:51.669452 | controller -> localhost | +---[RSA 3072]----+ 2025-11-24 08:34:51.669491 | controller -> localhost | | .=*+ +*. | 2025-11-24 08:34:51.669531 | controller -> localhost | | o* o ..+ +. | 2025-11-24 08:34:51.669570 | controller -> localhost | | * B ..*.o + | 2025-11-24 08:34:51.669609 | controller -> localhost | | = * +oB B = | 2025-11-24 08:34:51.669713 | controller -> localhost | | o S *.= =.E| 2025-11-24 08:34:51.669765 | controller -> localhost | | . o . .=| 2025-11-24 08:34:51.669803 | controller -> localhost | | o ..| 2025-11-24 08:34:51.669841 | controller -> localhost | | | 2025-11-24 08:34:51.669878 | controller -> localhost | | | 2025-11-24 08:34:51.669914 | controller -> localhost | +----[SHA256]-----+ 2025-11-24 08:34:51.670009 | controller -> localhost | ok: Runtime: 0:00:00.804511 2025-11-24 08:34:51.685814 | 2025-11-24 08:34:51.685964 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-24 08:34:51.718888 | controller | ok 2025-11-24 08:34:51.729626 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-24 08:34:51.737993 | 2025-11-24 08:34:51.738062 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-24 08:34:51.772578 | controller | skipping: Conditional result was False 2025-11-24 08:34:51.778359 | 2025-11-24 08:34:51.778423 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-24 08:34:52.291022 | controller | changed 2025-11-24 08:34:52.299993 | 2025-11-24 08:34:52.300093 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-24 08:34:52.594865 | controller | ok 2025-11-24 08:34:52.608647 | 2025-11-24 08:34:52.608840 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-24 08:34:53.454758 | controller | changed 2025-11-24 08:34:53.464046 | 2025-11-24 08:34:53.464262 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-24 08:34:54.325699 | controller | changed 2025-11-24 08:34:54.333041 | 2025-11-24 08:34:54.333134 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-24 08:34:54.358547 | controller | skipping: Conditional result was False 2025-11-24 08:34:54.366558 | 2025-11-24 08:34:54.366659 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-24 08:34:54.780290 | controller -> localhost | changed 2025-11-24 08:34:54.799171 | 2025-11-24 08:34:54.799306 | TASK [add-build-sshkey : Add back temp key] 2025-11-24 08:34:55.058199 | controller -> localhost | Identity added: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/41267c6d517540dca0f2c5c9cb7a9f74_id_rsa (zuul-build-sshkey) 2025-11-24 08:34:55.058608 | controller -> localhost | ok: Runtime: 0:00:00.010627 2025-11-24 08:34:55.075298 | 2025-11-24 08:34:55.075444 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-24 08:34:55.474174 | controller | ok 2025-11-24 08:34:55.482947 | 2025-11-24 08:34:55.483093 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-24 08:34:55.519533 | controller | skipping: Conditional result was False 2025-11-24 08:34:55.533783 | 2025-11-24 08:34:55.533919 | TASK [include_role : validate-host] 2025-11-24 08:34:55.567056 | controller | ok 2025-11-24 08:34:55.597978 | 2025-11-24 08:34:55.598101 | TASK [validate-host : Define zuul_info_dir fact] 2025-11-24 08:34:55.642595 | controller | ok 2025-11-24 08:34:55.689702 | 2025-11-24 08:34:55.689832 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-11-24 08:34:56.051292 | controller -> localhost | ok 2025-11-24 08:34:56.059289 | 2025-11-24 08:34:56.059395 | TASK [validate-host : Collect information about the host] 2025-11-24 08:34:56.820953 | controller | ok 2025-11-24 08:34:56.829626 | 2025-11-24 08:34:56.829710 | TASK [validate-host : Sanitize hostname] 2025-11-24 08:34:56.890314 | controller | ok 2025-11-24 08:34:56.895654 | 2025-11-24 08:34:56.895758 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-11-24 08:34:57.401379 | controller -> localhost | changed 2025-11-24 08:34:57.414486 | 2025-11-24 08:34:57.414662 | TASK [validate-host : Collect information about zuul worker] 2025-11-24 08:34:57.826967 | controller | ok 2025-11-24 08:34:57.837219 | 2025-11-24 08:34:57.837313 | TASK [validate-host : Write out all zuul information for each host] 2025-11-24 08:34:58.454896 | controller -> localhost | changed 2025-11-24 08:34:58.465187 | 2025-11-24 08:34:58.465272 | TASK [include_role : prepare-workspace-openshift] 2025-11-24 08:34:58.485836 | controller | skipping: Conditional result was False 2025-11-24 08:34:58.494152 | 2025-11-24 08:34:58.494247 | TASK [include_role : remove-zuul-sshkey] 2025-11-24 08:34:58.509019 | controller | skipping: Conditional result was False 2025-11-24 08:34:58.516953 | 2025-11-24 08:34:58.517042 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-24 08:34:58.809300 | controller | ok: "logs" 2025-11-24 08:34:58.809610 | controller | ok: All items complete 2025-11-24 08:34:58.809644 | 2025-11-24 08:34:59.080305 | controller | ok: "artifacts" 2025-11-24 08:34:59.316082 | controller | ok: "docs" 2025-11-24 08:34:59.335337 | 2025-11-24 08:34:59.335549 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-24 08:34:59.599038 | controller | changed: "logs" 2025-11-24 08:34:59.838794 | controller | changed: "artifacts" 2025-11-24 08:35:00.089927 | controller | changed: "docs" 2025-11-24 08:35:00.135813 | 2025-11-24 08:35:00.136013 | PLAY RECAP 2025-11-24 08:35:00.136084 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-11-24 08:35:00.136121 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-24 08:35:00.136147 | 2025-11-24 08:35:00.266256 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-11-24 08:35:00.267135 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-24 08:35:00.865072 | 2025-11-24 08:35:00.865192 | PLAY [localhost] 2025-11-24 08:35:00.882193 | 2025-11-24 08:35:00.882295 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-11-24 08:35:01.300931 | localhost | ok 2025-11-24 08:35:01.307968 | 2025-11-24 08:35:01.308082 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-11-24 08:35:02.011188 | localhost | changed 2025-11-24 08:35:02.056251 | 2025-11-24 08:35:02.056387 | PLAY [all] 2025-11-24 08:35:02.079184 | 2025-11-24 08:35:02.079287 | TASK [include_role : prepare-workspace] 2025-11-24 08:35:02.112488 | controller | ok 2025-11-24 08:35:02.133543 | 2025-11-24 08:35:02.133645 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-24 08:35:02.566491 | controller | ok 2025-11-24 08:35:02.576658 | 2025-11-24 08:35:02.576772 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-24 08:35:04.484247 | controller | Output suppressed because no_log was given 2025-11-24 08:35:04.500985 | 2025-11-24 08:35:04.501131 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-24 08:35:04.803552 | controller | changed: "logs" 2025-11-24 08:35:04.999915 | controller | changed: "artifacts" 2025-11-24 08:35:05.268814 | controller | changed: "docs" 2025-11-24 08:35:05.281737 | 2025-11-24 08:35:05.281852 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-24 08:35:05.539993 | controller | changed: "logs" 2025-11-24 08:35:05.540281 | controller | changed: All items complete 2025-11-24 08:35:05.540313 | 2025-11-24 08:35:05.783522 | controller | changed: "artifacts" 2025-11-24 08:35:06.017745 | controller | changed: "docs" 2025-11-24 08:35:06.037574 | 2025-11-24 08:35:06.037711 | TASK [Check if worker can sudo] 2025-11-24 08:35:06.590969 | controller | ok: Runtime: 0:00:00.043989 2025-11-24 08:35:06.596929 | 2025-11-24 08:35:06.597003 | TASK [configure-mirrors : Gather needed facts] 2025-11-24 08:35:06.734118 | controller | skipping: Conditional result was False 2025-11-24 08:35:06.742845 | 2025-11-24 08:35:06.743048 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-11-24 08:35:06.945087 | controller | ok 2025-11-24 08:35:06.953444 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-11-24 08:35:06.959337 | 2025-11-24 08:35:06.959414 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-11-24 08:35:07.227207 | controller | ok 2025-11-24 08:35:07.243016 | 2025-11-24 08:35:07.243141 | LOOP [configure-mirrors : Include OS-specific variables] 2025-11-24 08:35:07.381123 | controller | ok: "/var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-11-24 08:35:07.392650 | 2025-11-24 08:35:07.392778 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-11-24 08:35:08.290309 | controller | changed 2025-11-24 08:35:08.297772 | 2025-11-24 08:35:08.297855 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-11-24 08:35:08.385706 | controller | ok: "/var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-11-24 08:35:08.385881 | controller | ok: All items complete 2025-11-24 08:35:08.385908 | 2025-11-24 08:35:08.445841 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-11-24 08:35:08.452903 | 2025-11-24 08:35:08.452991 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-11-24 08:35:09.347772 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-11-24 08:35:10.170964 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-11-24 08:35:10.187583 | 2025-11-24 08:35:10.187703 | TASK [configure-mirrors : Disable deltrarpm] 2025-11-24 08:35:10.707122 | controller | changed: section and option added 2025-11-24 08:35:10.734328 | 2025-11-24 08:35:10.734450 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-11-24 08:35:11.584943 | controller | 29 files removed 2025-11-24 08:35:11.585153 | controller | ok: Item: dnf clean all Runtime: 0:00:00.495130 2025-11-24 08:35:11.585191 | controller | changed: All items complete 2025-11-24 08:35:11.585211 | 2025-11-24 08:35:22.628285 | 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-24 08:35:22.634713 | controller | DNF version: 4.14.0 2025-11-24 08:35:22.634758 | controller | cachedir: /var/cache/dnf 2025-11-24 08:35:22.634780 | controller | Making cache files for all metadata files. 2025-11-24 08:35:22.634798 | controller | baseos: has expired and will be refreshed. 2025-11-24 08:35:22.634814 | controller | appstream: has expired and will be refreshed. 2025-11-24 08:35:22.634830 | controller | crb: has expired and will be refreshed. 2025-11-24 08:35:22.634854 | controller | extras-common: has expired and will be refreshed. 2025-11-24 08:35:22.634871 | controller | repo: downloading from remote: baseos 2025-11-24 08:35:22.634886 | controller | CentOS Stream 9 - BaseOS 66 MB/s | 8.8 MB 00:00 2025-11-24 08:35:22.634901 | controller | baseos: using metadata from Mon 17 Nov 2025 10:24:02 AM EST. 2025-11-24 08:35:22.634916 | controller | repo: downloading from remote: appstream 2025-11-24 08:35:22.634931 | controller | CentOS Stream 9 - AppStream 76 MB/s | 25 MB 00:00 2025-11-24 08:35:22.634947 | controller | appstream: using metadata from Mon 17 Nov 2025 10:27:35 AM EST. 2025-11-24 08:35:22.634962 | controller | repo: downloading from remote: crb 2025-11-24 08:35:22.634976 | controller | CentOS Stream 9 - CRB 65 MB/s | 7.3 MB 00:00 2025-11-24 08:35:22.634992 | controller | crb: using metadata from Mon 17 Nov 2025 10:32:16 AM EST. 2025-11-24 08:35:22.635008 | controller | repo: downloading from remote: extras-common 2025-11-24 08:35:22.635023 | controller | CentOS Stream 9 - Extras packages 1.4 MB/s | 20 kB 00:00 2025-11-24 08:35:22.635039 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-11-24 08:35:22.635054 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-11-24 08:35:22.635069 | controller | Completion plugin: Generating completion cache... 2025-11-24 08:35:22.635084 | controller | Metadata cache created. 2025-11-24 08:35:22.635113 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.741548 2025-11-24 08:35:22.652271 | 2025-11-24 08:35:22.652417 | PLAY RECAP 2025-11-24 08:35:22.652468 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-11-24 08:35:22.652493 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-24 08:35:22.652509 | 2025-11-24 08:35:26.695400 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-11-24 08:35:26.696386 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-24 08:35:27.245721 | 2025-11-24 08:35:27.245834 | PLAY [all] 2025-11-24 08:35:27.273985 | 2025-11-24 08:35:27.274091 | TASK [Install binary dependencies] 2025-11-24 08:35:27.324349 | controller | ok 2025-11-24 08:35:27.347766 | 2025-11-24 08:35:27.347899 | TASK [bindep : Include find tasks] 2025-11-24 08:35:27.378885 | controller | ok 2025-11-24 08:35:27.387777 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-24 08:35:27.394191 | 2025-11-24 08:35:27.394258 | TASK [bindep : Look for bindep.txt] 2025-11-24 08:35:27.809065 | controller | ok 2025-11-24 08:35:27.838046 | 2025-11-24 08:35:27.838211 | TASK [bindep : Define bindep_file fact] 2025-11-24 08:35:27.882852 | controller | ok 2025-11-24 08:35:27.892010 | 2025-11-24 08:35:27.892105 | TASK [bindep : Look for other-requirements.txt] 2025-11-24 08:35:27.927738 | controller | skipping: Conditional result was False 2025-11-24 08:35:27.936224 | 2025-11-24 08:35:27.936316 | TASK [bindep : Define bindep_file fact] 2025-11-24 08:35:27.972390 | controller | skipping: Conditional result was False 2025-11-24 08:35:27.980602 | 2025-11-24 08:35:27.980724 | TASK [bindep : Look for bindep fallback file] 2025-11-24 08:35:28.016871 | controller | skipping: Conditional result was False 2025-11-24 08:35:28.026052 | 2025-11-24 08:35:28.026149 | TASK [bindep : Define bindep_file fact] 2025-11-24 08:35:28.052514 | controller | skipping: Conditional result was False 2025-11-24 08:35:28.062558 | 2025-11-24 08:35:28.062653 | TASK [bindep : Include bindep tasks] 2025-11-24 08:35:28.106836 | controller | ok 2025-11-24 08:35:28.117564 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-11-24 08:35:28.130041 | 2025-11-24 08:35:28.130131 | TASK [bindep : Look for bindep command] 2025-11-24 08:35:28.165715 | controller | skipping: Conditional result was False 2025-11-24 08:35:28.175143 | 2025-11-24 08:35:28.175234 | TASK [bindep : Check for system bindep] 2025-11-24 08:35:28.719617 | controller | ok: Runtime: 0:00:00.005894 2025-11-24 08:35:28.733080 | 2025-11-24 08:35:28.733300 | TASK [bindep : Define bindep_command fact] 2025-11-24 08:35:28.770835 | controller | skipping: Conditional result was False 2025-11-24 08:35:28.781261 | 2025-11-24 08:35:28.781461 | TASK [bindep : Include install tasks] 2025-11-24 08:35:28.815731 | controller | ok 2025-11-24 08:35:28.824835 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-11-24 08:35:28.833740 | 2025-11-24 08:35:28.833803 | TASK [bindep : Create temp dir for bindep] 2025-11-24 08:35:29.240603 | controller | changed 2025-11-24 08:35:29.253850 | 2025-11-24 08:35:29.254012 | TASK [Ensure we have pip dependencies] 2025-11-24 08:35:29.287748 | controller | ok 2025-11-24 08:35:29.334314 | 2025-11-24 08:35:29.334511 | TASK [ensure-pip : Check if pip is installed] 2025-11-24 03:35:29.640123 | controller | /usr/bin/pip3 2025-11-24 03:35:29.662213 | controller | /usr/bin/python3: No module named wheel 2025-11-24 08:35:29.876635 | controller | ok: Runtime: 0:00:00.032320 2025-11-24 08:35:29.894272 | 2025-11-24 08:35:29.894468 | LOOP [ensure-pip : Install pip from packages] 2025-11-24 08:35:29.953474 | controller | ok: "/var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-11-24 08:35:29.974481 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-11-24 08:35:29.989411 | 2025-11-24 08:35:29.989518 | TASK [ensure-pip : Install Python 3 pip] 2025-11-24 08:35:32.160555 | controller | changed 2025-11-24 08:35:32.189986 | 2025-11-24 08:35:32.190243 | TASK [ensure-pip : Check for EPEL repository] 2025-11-24 08:35:32.258471 | controller | skipping: Conditional result was False 2025-11-24 08:35:32.268256 | 2025-11-24 08:35:32.268354 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-11-24 08:35:32.325445 | controller | skipping: Conditional result was False 2025-11-24 08:35:32.335617 | 2025-11-24 08:35:32.335735 | TASK [ensure-pip : Install Python 2 pip] 2025-11-24 08:35:32.414413 | controller | skipping: Conditional result was False 2025-11-24 08:35:32.432039 | 2025-11-24 08:35:32.432528 | TASK [ensure-pip : Ensure setuptools] 2025-11-24 08:35:32.471124 | controller | skipping: Conditional result was False 2025-11-24 08:35:32.487224 | 2025-11-24 08:35:32.487375 | TASK [ensure-pip : Check for ensurepip module] 2025-11-24 08:35:33.037897 | controller | skipping: Conditional result was False 2025-11-24 08:35:33.050647 | 2025-11-24 08:35:33.050820 | TASK [ensure-pip : Ensure python3-venv] 2025-11-24 08:35:33.078206 | controller | skipping: Conditional result was False 2025-11-24 08:35:33.090079 | 2025-11-24 08:35:33.090179 | TASK [ensure-pip : Install pip from source] 2025-11-24 08:35:33.117626 | controller | skipping: Conditional result was False 2025-11-24 08:35:33.129250 | 2025-11-24 08:35:33.129350 | TASK [ensure-pip : Probe for venv python full path] 2025-11-24 03:35:33.434820 | controller | /usr/bin/python3 2025-11-24 08:35:33.676598 | controller | ok: Runtime: 0:00:00.005052 2025-11-24 08:35:33.693286 | 2025-11-24 08:35:33.693489 | TASK [ensure-pip : Set host default] 2025-11-24 08:35:33.744279 | controller | ok 2025-11-24 08:35:33.755875 | 2025-11-24 08:35:33.756046 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-11-24 08:35:33.813274 | controller | ok 2025-11-24 08:35:33.825737 | 2025-11-24 08:35:33.825887 | TASK [bindep : Install bindep into temporary venv] 2025-11-24 08:35:40.556369 | controller | changed 2025-11-24 08:35:40.569991 | 2025-11-24 08:35:40.570191 | TASK [bindep : Define bindep_command] 2025-11-24 08:35:40.623660 | controller | ok 2025-11-24 08:35:40.637385 | 2025-11-24 08:35:40.637626 | LOOP [bindep : Include package tasks] 2025-11-24 08:35:40.722046 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-11-24 08:35:40.722788 | controller | ok: All items complete 2025-11-24 08:35:40.722881 | 2025-11-24 08:35:40.753024 | controller | included: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-11-24 08:35:40.779062 | 2025-11-24 08:35:40.779214 | TASK [bindep : Define bindep_run fact] 2025-11-24 08:35:40.825568 | controller | ok 2025-11-24 08:35:40.833410 | 2025-11-24 08:35:40.833501 | TASK [bindep : Get list of packages to install from bindep] 2025-11-24 03:35:42.343516 | controller | podman 2025-11-24 03:35:42.396831 | controller | python3-jmespath 2025-11-24 03:35:42.397044 | controller | python3-libvirt 2025-11-24 03:35:42.397054 | controller | python3-lxml 2025-11-24 03:35:42.397061 | controller | python3-netaddr 2025-11-24 08:35:42.875432 | controller | ok: Runtime: 0:00:01.250845 2025-11-24 08:35:42.881752 | 2025-11-24 08:35:42.881822 | TASK [bindep : Install distro packages from bindep] 2025-11-24 08:36:50.509669 | controller | changed 2025-11-24 08:36:50.521445 | 2025-11-24 08:36:50.521586 | TASK [bindep : Check that packages are installed] 2025-11-24 08:36:52.093530 | controller | ok: Runtime: 0:00:01.228779 2025-11-24 08:36:52.106327 | 2025-11-24 08:36:52.106483 | TASK [bindep : Fail if we cannot install all packages] 2025-11-24 08:36:52.144739 | controller | skipping: Conditional result was False 2025-11-24 08:36:52.169328 | 2025-11-24 08:36:52.169497 | TASK [Run test-setup role] 2025-11-24 08:36:52.195037 | controller | ok 2025-11-24 08:36:52.219977 | 2025-11-24 08:36:52.220087 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-24 08:36:52.492791 | controller | ok 2025-11-24 08:36:52.505982 | 2025-11-24 08:36:52.506167 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-24 08:36:53.054819 | controller | skipping: Conditional result was False 2025-11-24 08:36:53.075734 | 2025-11-24 08:36:53.075870 | TASK [bindep : Remove bindep temp dir] 2025-11-24 08:36:53.487814 | controller | ok 2025-11-24 08:36:53.511807 | 2025-11-24 08:36:53.511961 | PLAY RECAP 2025-11-24 08:36:53.512045 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-11-24 08:36:53.512089 | 2025-11-24 08:36:53.637255 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-24 08:36:53.638446 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-24 08:36:54.167109 | 2025-11-24 08:36:54.167223 | PLAY [all] 2025-11-24 08:36:54.186712 | 2025-11-24 08:36:54.186790 | TASK [Abort when test_command variable is undefined] 2025-11-24 08:36:54.232025 | controller | skipping: Conditional result was False 2025-11-24 08:36:54.238931 | 2025-11-24 08:36:54.239024 | TASK [Convert test_command to list] 2025-11-24 08:36:54.297869 | controller | skipping: Conditional result was False 2025-11-24 08:36:54.310101 | 2025-11-24 08:36:54.310242 | TASK [Use test_command list] 2025-11-24 08:36:54.387458 | controller | ok 2025-11-24 08:36:54.395538 | 2025-11-24 08:36:54.395622 | LOOP [Run test_command] 2025-11-24 08:36:54.819190 | controller | no check to run 2025-11-24 08:36:54.819611 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004279 2025-11-24 08:36:54.872097 | 2025-11-24 08:36:54.872242 | PLAY RECAP 2025-11-24 08:36:54.872321 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-24 08:36:54.872362 | 2025-11-24 08:36:54.989669 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-11-24 08:36:54.990716 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-24 08:36:55.599457 | 2025-11-24 08:36:55.599585 | PLAY [all] 2025-11-24 08:36:55.620276 | 2025-11-24 08:36:55.620369 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-24 08:36:55.958047 | controller | changed: non-zero return code 2025-11-24 08:36:55.971631 | 2025-11-24 08:36:55.971939 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-24 08:36:56.000739 | controller | skipping: Conditional result was False 2025-11-24 08:36:56.014128 | 2025-11-24 08:36:56.014516 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-24 08:36:56.045729 | 2025-11-24 08:36:56.046052 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-24 08:36:56.076997 | 2025-11-24 08:36:56.077353 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-24 08:36:56.094332 | controller | skipping: Conditional result was False 2025-11-24 08:36:56.107773 | 2025-11-24 08:36:56.107983 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-24 08:36:56.140103 | 2025-11-24 08:36:56.140414 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-24 08:36:56.156903 | controller | skipping: Conditional result was False 2025-11-24 08:36:56.165829 | 2025-11-24 08:36:56.165982 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-24 08:36:56.181556 | controller | skipping: Conditional result was False 2025-11-24 08:36:56.190773 | 2025-11-24 08:36:56.190933 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-24 08:36:56.206368 | controller | skipping: Conditional result was False 2025-11-24 08:36:56.243831 | 2025-11-24 08:36:56.243975 | PLAY RECAP 2025-11-24 08:36:56.244034 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-24 08:36:56.244064 | 2025-11-24 08:36:56.363460 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-24 08:36:56.365302 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-24 08:36:56.976508 | 2025-11-24 08:36:56.976635 | PLAY [all] 2025-11-24 08:36:56.996821 | 2025-11-24 08:36:56.996916 | TASK [include_role : fetch-output] 2025-11-24 08:36:57.027163 | controller | ok 2025-11-24 08:36:57.047451 | 2025-11-24 08:36:57.047602 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-24 08:36:57.095153 | controller | skipping: Conditional result was False 2025-11-24 08:36:57.104499 | 2025-11-24 08:36:57.104734 | TASK [fetch-output : Set log path for single node] 2025-11-24 08:36:57.146733 | controller | ok 2025-11-24 08:36:57.151920 | 2025-11-24 08:36:57.151994 | LOOP [fetch-output : Ensure local output dirs] 2025-11-24 08:36:57.606575 | controller -> localhost | ok: "/var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/logs" 2025-11-24 08:36:57.920001 | controller -> localhost | changed: "/var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/artifacts" 2025-11-24 08:36:58.144657 | controller -> localhost | changed: "/var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/docs" 2025-11-24 08:36:58.157119 | 2025-11-24 08:36:58.157322 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-24 08:36:58.952792 | controller | changed: .d..t...... ./ 2025-11-24 08:36:58.953246 | controller | changed: All items complete 2025-11-24 08:36:58.953310 | 2025-11-24 08:36:59.493391 | controller | changed: .d..t...... ./ 2025-11-24 08:37:00.065430 | controller | changed: .d..t...... ./ 2025-11-24 08:37:00.096432 | 2025-11-24 08:37:00.096625 | TASK [include_role : fetch-output-openshift] 2025-11-24 08:37:00.124120 | controller | skipping: Conditional result was False 2025-11-24 08:37:00.139379 | 2025-11-24 08:37:00.139551 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-24 08:37:00.630597 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.010800 2025-11-24 08:37:00.937056 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007435 2025-11-24 08:37:00.993670 | 2025-11-24 08:37:00.993850 | PLAY [all] 2025-11-24 08:37:01.022184 | 2025-11-24 08:37:01.022408 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-11-24 08:37:01.522927 | controller | changed 2025-11-24 08:37:01.573438 | 2025-11-24 08:37:01.573549 | PLAY RECAP 2025-11-24 08:37:01.573606 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-11-24 08:37:01.573634 | 2025-11-24 08:37:01.739220 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-11-24 08:37:01.741025 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-11-24 08:37:02.407006 | 2025-11-24 08:37:02.407134 | PLAY [localhost] 2025-11-24 08:37:02.425852 | 2025-11-24 08:37:02.425944 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-24 08:37:02.884616 | localhost | changed 2025-11-24 08:37:02.889737 | 2025-11-24 08:37:02.889821 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-24 08:37:02.930856 | localhost | ok 2025-11-24 08:37:02.938832 | 2025-11-24 08:37:02.938901 | TASK [add-fileserver : Create SSH private key tempfile] 2025-11-24 08:37:03.366623 | localhost | changed 2025-11-24 08:37:03.378084 | 2025-11-24 08:37:03.378233 | TASK [add-fileserver : Create SSH private key from secret] 2025-11-24 08:37:04.177809 | localhost | changed 2025-11-24 08:37:04.183513 | 2025-11-24 08:37:04.183585 | TASK [add-fileserver : Add fileserver ssh key] 2025-11-24 08:37:04.670854 | localhost | Identity added: /var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/tmp/ansible.7h68u6xt (/var/lib/zuul/builds/41267c6d517540dca0f2c5c9cb7a9f74/work/tmp/ansible.7h68u6xt) 2025-11-24 08:37:04.671211 | localhost | ok: Runtime: 0:00:00.015507 2025-11-24 08:37:04.682832 | 2025-11-24 08:37:04.682977 | TASK [add-fileserver : Remove SSH private key from disk] 2025-11-24 08:37:05.015255 | localhost | ok: Runtime: 0:00:00.010324 2025-11-24 08:37:05.023462 | 2025-11-24 08:37:05.023553 | TASK [add-fileserver : Add fileserver to inventory] 2025-11-24 08:37:05.103097 | localhost | changed 2025-11-24 08:37:05.114822 | 2025-11-24 08:37:05.114968 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-11-24 08:37:05.597625 | localhost | changed 2025-11-24 08:37:05.620820 | 2025-11-24 08:37:05.620914 | PLAY [localhost] 2025-11-24 08:37:05.634467 | 2025-11-24 08:37:05.634536 | TASK [Generate bulk log download script] 2025-11-24 08:37:05.656747 | localhost | ok 2025-11-24 08:37:05.670549 | 2025-11-24 08:37:05.671020 | TASK [local-log-download : Check API endpoint is defined] 2025-11-24 08:37:05.722319 | localhost | ok: All assertions passed 2025-11-24 08:37:05.727457 | 2025-11-24 08:37:05.727540 | TASK [local-log-download : Create download script] 2025-11-24 08:37:06.204222 | localhost -> localhost | changed 2025-11-24 08:37:06.229810 | 2025-11-24 08:37:06.230132 | TASK [Register quick-download link] 2025-11-24 08:37:06.320722 | localhost | ok 2025-11-24 08:37:06.341550 | 2025-11-24 08:37:06.341655 | PLAY [logserver.rdoproject.org] 2025-11-24 08:37:06.353519 | 2025-11-24 08:37:06.353600 | TASK [Set zuul-log-path fact] 2025-11-24 08:37:06.382305 | logserver.rdoproject.org | ok 2025-11-24 08:37:06.393168 | 2025-11-24 08:37:06.393238 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-24 08:37:06.432398 | logserver.rdoproject.org | ok 2025-11-24 08:37:06.441044 | 2025-11-24 08:37:06.441130 | TASK [upload-logs : Create log directories] 2025-11-24 08:37:07.150166 | logserver.rdoproject.org | changed 2025-11-24 08:37:07.157577 | 2025-11-24 08:37:07.157780 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-11-24 08:37:07.538331 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.010759 2025-11-24 08:37:07.549456 | 2025-11-24 08:37:07.549600 | TASK [upload-logs : Upload logs to log server] 2025-11-24 08:37:08.313196 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-11-24 08:37:08.320565 | 2025-11-24 08:37:08.320775 | LOOP [upload-logs : Compress console log and json output] 2025-11-24 08:37:08.395283 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-24 08:37:08.411617 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-24 08:37:08.430936 | 2025-11-24 08:37:08.431167 | LOOP [upload-logs : Upload compressed console log and json output] 2025-11-24 08:37:08.486983 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-24 08:37:08.487423 | 2025-11-24 08:37:08.490317 | logserver.rdoproject.org | skipping: Conditional result was False 2025-11-24 08:37:08.504648 | 2025-11-24 08:37:08.504779 | LOOP [upload-logs : Upload console log and json output]