2025-10-13 13:59:14.244392 | Job console starting... 2025-10-13 13:59:14.258110 | Updating repositories 2025-10-13 13:59:14.282374 | Preparing job workspace 2025-10-13 13:59:18.387805 | Running Ansible setup... 2025-10-13 13:59:22.532569 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 13:59:23.197592 | 2025-10-13 13:59:23.197761 | PLAY [localhost] 2025-10-13 13:59:23.211644 | 2025-10-13 13:59:23.211797 | TASK [Gathering Facts] 2025-10-13 13:59:24.151524 | localhost | ok 2025-10-13 13:59:24.166388 | 2025-10-13 13:59:24.166488 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 13:59:24.620457 | localhost -> localhost | changed 2025-10-13 13:59:24.632718 | 2025-10-13 13:59:24.632916 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 13:59:25.547485 | localhost -> localhost | changed 2025-10-13 13:59:25.566612 | 2025-10-13 13:59:25.566852 | TASK [Setup log path fact] 2025-10-13 13:59:25.591824 | localhost | ok 2025-10-13 13:59:25.612900 | 2025-10-13 13:59:25.613104 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 13:59:25.646721 | localhost | ok 2025-10-13 13:59:25.660669 | 2025-10-13 13:59:25.660785 | TASK [emit-job-header : Print job information] 2025-10-13 13:59:25.704826 | # Job Information 2025-10-13 13:59:25.705506 | Ansible Version: 2.15.12 2025-10-13 13:59:25.705596 | Job: cifmw-molecule-cifmw_helpers 2025-10-13 13:59:25.705647 | Pipeline: github-check 2025-10-13 13:59:25.705769 | Executor: ze03.softwarefactory-project.io 2025-10-13 13:59:25.705828 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3404 2025-10-13 13:59:25.705878 | Log URL (when completed): https://logserver.rdoproject.org/979/rdoproject.org/979ae36f74314b14b5b0112c117bcfab/ 2025-10-13 13:59:25.705921 | Event ID: a5099c60-a83c-11f0-85ff-c2ebbdb05321 2025-10-13 13:59:25.712126 | 2025-10-13 13:59:25.712223 | LOOP [emit-job-header : Print node information] 2025-10-13 13:59:25.807359 | localhost | ok: 2025-10-13 13:59:25.807576 | localhost | # Node Information 2025-10-13 13:59:25.807611 | localhost | Inventory Hostname: controller 2025-10-13 13:59:25.807645 | localhost | Hostname: np0005484992 2025-10-13 13:59:25.807671 | localhost | Username: zuul 2025-10-13 13:59:25.807691 | localhost | Distro: CentOS 9 2025-10-13 13:59:25.807708 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 13:59:25.807745 | localhost | Region: RegionOne 2025-10-13 13:59:25.807778 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 13:59:25.807798 | localhost | Product Name: OpenStack Nova 2025-10-13 13:59:25.807815 | localhost | Interface IP: 38.102.83.64 2025-10-13 13:59:25.863286 | 2025-10-13 13:59:25.863528 | PLAY [all] 2025-10-13 13:59:25.879286 | 2025-10-13 13:59:25.879493 | TASK [Gather network facts] 2025-10-13 13:59:26.420634 | controller | ok 2025-10-13 13:59:26.455646 | 2025-10-13 13:59:26.455798 | TASK [include_role : start-zuul-console] 2025-10-13 13:59:26.485475 | controller | ok 2025-10-13 13:59:26.511290 | 2025-10-13 13:59:26.511452 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 13:59:26.987525 | controller | ok 2025-10-13 13:59:27.009148 | 2025-10-13 13:59:27.009309 | TASK [include_role : add-build-sshkey] 2025-10-13 13:59:27.048364 | controller | ok 2025-10-13 13:59:27.077481 | 2025-10-13 13:59:27.077635 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 13:59:27.341396 | controller -> localhost | ok 2025-10-13 13:59:27.351826 | 2025-10-13 13:59:27.352032 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 13:59:27.387337 | controller | ok 2025-10-13 13:59:27.408228 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 13:59:27.417917 | 2025-10-13 13:59:27.418029 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 13:59:28.080330 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 13:59:28.080780 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/979ae36f74314b14b5b0112c117bcfab_id_rsa. 2025-10-13 13:59:28.080888 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/979ae36f74314b14b5b0112c117bcfab_id_rsa.pub. 2025-10-13 13:59:28.080949 | controller -> localhost | The key fingerprint is: 2025-10-13 13:59:28.080995 | controller -> localhost | SHA256:MibaTI5DKhZEaCq2BzeBtPynr/Y9wS2FDRJ/zTLQ0Zg zuul-build-sshkey 2025-10-13 13:59:28.081039 | controller -> localhost | The key's randomart image is: 2025-10-13 13:59:28.081082 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 13:59:28.081124 | controller -> localhost | |oo. .....= | 2025-10-13 13:59:28.081167 | controller -> localhost | |+o.. ....Eo. | 2025-10-13 13:59:28.081209 | controller -> localhost | |o+ . ..++ o | 2025-10-13 13:59:28.081251 | controller -> localhost | |+o.o ..oo | 2025-10-13 13:59:28.081292 | controller -> localhost | |o.=.+.= S | 2025-10-13 13:59:28.081334 | controller -> localhost | | +.Ooo * . | 2025-10-13 13:59:28.081374 | controller -> localhost | |o.=.+ o | 2025-10-13 13:59:28.081421 | controller -> localhost | |o o. .. | 2025-10-13 13:59:28.081462 | controller -> localhost | | ..oo .. | 2025-10-13 13:59:28.081502 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 13:59:28.081595 | controller -> localhost | ok: Runtime: 0:00:00.156815 2025-10-13 13:59:28.095372 | 2025-10-13 13:59:28.095513 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 13:59:28.133640 | controller | ok 2025-10-13 13:59:28.155544 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 13:59:28.168795 | 2025-10-13 13:59:28.168893 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 13:59:28.193987 | controller | skipping: Conditional result was False 2025-10-13 13:59:28.203271 | 2025-10-13 13:59:28.203390 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 13:59:28.758361 | controller | changed 2025-10-13 13:59:28.769372 | 2025-10-13 13:59:28.769552 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 13:59:29.048235 | controller | ok 2025-10-13 13:59:29.054848 | 2025-10-13 13:59:29.054927 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 13:59:29.975099 | controller | changed 2025-10-13 13:59:29.986751 | 2025-10-13 13:59:29.986961 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 13:59:30.849716 | controller | changed 2025-10-13 13:59:30.860942 | 2025-10-13 13:59:30.861106 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 13:59:30.898720 | controller | skipping: Conditional result was False 2025-10-13 13:59:30.911577 | 2025-10-13 13:59:30.911806 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 13:59:31.379513 | controller -> localhost | changed 2025-10-13 13:59:31.399775 | 2025-10-13 13:59:31.399880 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 13:59:31.742637 | controller -> localhost | Identity added: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/979ae36f74314b14b5b0112c117bcfab_id_rsa (zuul-build-sshkey) 2025-10-13 13:59:31.743056 | controller -> localhost | ok: Runtime: 0:00:00.017076 2025-10-13 13:59:31.755886 | 2025-10-13 13:59:31.756019 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 13:59:32.155034 | controller | ok 2025-10-13 13:59:32.166582 | 2025-10-13 13:59:32.166759 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 13:59:32.204828 | controller | skipping: Conditional result was False 2025-10-13 13:59:32.228195 | 2025-10-13 13:59:32.228395 | TASK [include_role : validate-host] 2025-10-13 13:59:32.267293 | controller | ok 2025-10-13 13:59:32.303225 | 2025-10-13 13:59:32.303340 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 13:59:32.345964 | controller | ok 2025-10-13 13:59:32.352639 | 2025-10-13 13:59:32.352757 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 13:59:32.653680 | controller -> localhost | ok 2025-10-13 13:59:32.663742 | 2025-10-13 13:59:32.663845 | TASK [validate-host : Collect information about the host] 2025-10-13 13:59:33.596007 | controller | ok 2025-10-13 13:59:33.609223 | 2025-10-13 13:59:33.609336 | TASK [validate-host : Sanitize hostname] 2025-10-13 13:59:33.681867 | controller | ok 2025-10-13 13:59:33.688581 | 2025-10-13 13:59:33.688665 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 13:59:34.183359 | controller -> localhost | changed 2025-10-13 13:59:34.188996 | 2025-10-13 13:59:34.189073 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 13:59:34.647949 | controller | ok 2025-10-13 13:59:34.653799 | 2025-10-13 13:59:34.653877 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 13:59:35.117522 | controller -> localhost | changed 2025-10-13 13:59:35.137892 | 2025-10-13 13:59:35.138022 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 13:59:35.165024 | controller | skipping: Conditional result was False 2025-10-13 13:59:35.176099 | 2025-10-13 13:59:35.176235 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 13:59:35.202531 | controller | skipping: Conditional result was False 2025-10-13 13:59:35.213882 | 2025-10-13 13:59:35.214052 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 13:59:35.556509 | controller | ok: "logs" 2025-10-13 13:59:35.557027 | controller | ok: All items complete 2025-10-13 13:59:35.557092 | 2025-10-13 13:59:36.682646 | controller | ok: "artifacts" 2025-10-13 13:59:36.985927 | controller | ok: "docs" 2025-10-13 13:59:37.001674 | 2025-10-13 13:59:37.001878 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 13:59:37.434949 | controller | changed: "logs" 2025-10-13 13:59:37.705123 | controller | changed: "artifacts" 2025-10-13 13:59:37.989607 | controller | changed: "docs" 2025-10-13 13:59:38.028298 | 2025-10-13 13:59:38.028459 | PLAY RECAP 2025-10-13 13:59:38.028543 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 13:59:38.028595 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 13:59:38.028636 | 2025-10-13 13:59:38.161518 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 13:59:38.163273 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 13:59:38.783464 | 2025-10-13 13:59:38.783632 | PLAY [localhost] 2025-10-13 13:59:38.800015 | 2025-10-13 13:59:38.800135 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 13:59:39.234987 | localhost | ok 2025-10-13 13:59:39.240163 | 2025-10-13 13:59:39.240243 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 13:59:39.988542 | localhost | changed 2025-10-13 13:59:40.014416 | 2025-10-13 13:59:40.014514 | PLAY [all] 2025-10-13 13:59:40.038589 | 2025-10-13 13:59:40.038764 | TASK [include_role : prepare-workspace] 2025-10-13 13:59:40.062231 | controller | ok 2025-10-13 13:59:40.077612 | 2025-10-13 13:59:40.077722 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 13:59:40.544153 | controller | ok 2025-10-13 13:59:40.559897 | 2025-10-13 13:59:40.560065 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 13:59:42.523265 | controller | Output suppressed because no_log was given 2025-10-13 13:59:42.544411 | 2025-10-13 13:59:42.544637 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 13:59:42.872122 | controller | changed: "logs" 2025-10-13 13:59:43.137117 | controller | changed: "artifacts" 2025-10-13 13:59:43.379444 | controller | changed: "docs" 2025-10-13 13:59:43.394191 | 2025-10-13 13:59:43.394303 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 13:59:43.719201 | controller | changed: "logs" 2025-10-13 13:59:43.719802 | controller | changed: All items complete 2025-10-13 13:59:43.719887 | 2025-10-13 13:59:43.991319 | controller | changed: "artifacts" 2025-10-13 13:59:44.222261 | controller | changed: "docs" 2025-10-13 13:59:44.256607 | 2025-10-13 13:59:44.256845 | TASK [Check if worker can sudo] 2025-10-13 13:59:45.312825 | controller | ok: Runtime: 0:00:00.162669 2025-10-13 13:59:45.319998 | 2025-10-13 13:59:45.320084 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 13:59:45.407893 | controller | skipping: Conditional result was False 2025-10-13 13:59:45.422877 | 2025-10-13 13:59:45.423110 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 13:59:45.569617 | controller | ok 2025-10-13 13:59:45.578961 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 13:59:45.635395 | 2025-10-13 13:59:45.635568 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 13:59:45.937371 | controller | ok 2025-10-13 13:59:45.946033 | 2025-10-13 13:59:45.946203 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 13:59:46.049274 | controller | ok: "/var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 13:59:46.067327 | 2025-10-13 13:59:46.067704 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 13:59:47.082174 | controller | changed 2025-10-13 13:59:47.087924 | 2025-10-13 13:59:47.088024 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 13:59:47.145223 | controller | ok: "/var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 13:59:47.145419 | controller | ok: All items complete 2025-10-13 13:59:47.145453 | 2025-10-13 13:59:47.187367 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 13:59:47.194563 | 2025-10-13 13:59:47.194643 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 13:59:48.234844 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 13:59:49.255048 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 13:59:49.276375 | 2025-10-13 13:59:49.276535 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 13:59:49.832361 | controller | changed: section and option added 2025-10-13 13:59:49.873133 | 2025-10-13 13:59:49.873279 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 13:59:50.792886 | controller | 29 files removed 2025-10-13 13:59:50.793289 | controller | ok: Item: dnf clean all Runtime: 0:00:00.545334 2025-10-13 13:59:50.793402 | controller | changed: All items complete 2025-10-13 13:59:50.793457 | 2025-10-13 14:00:02.041471 | 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-13 14:00:02.041591 | controller | DNF version: 4.14.0 2025-10-13 14:00:02.041621 | controller | cachedir: /var/cache/dnf 2025-10-13 14:00:02.041646 | controller | Making cache files for all metadata files. 2025-10-13 14:00:02.041670 | controller | baseos: has expired and will be refreshed. 2025-10-13 14:00:02.041692 | controller | appstream: has expired and will be refreshed. 2025-10-13 14:00:02.041715 | controller | crb: has expired and will be refreshed. 2025-10-13 14:00:02.041786 | controller | extras-common: has expired and will be refreshed. 2025-10-13 14:00:02.041814 | controller | repo: downloading from remote: baseos 2025-10-13 14:00:02.041837 | controller | CentOS Stream 9 - BaseOS 76 MB/s | 8.8 MB 00:00 2025-10-13 14:00:02.041859 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 14:00:02.041881 | controller | repo: downloading from remote: appstream 2025-10-13 14:00:02.041903 | controller | CentOS Stream 9 - AppStream 89 MB/s | 25 MB 00:00 2025-10-13 14:00:02.041926 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 14:00:02.041950 | controller | repo: downloading from remote: crb 2025-10-13 14:00:02.041968 | controller | CentOS Stream 9 - CRB 40 MB/s | 7.2 MB 00:00 2025-10-13 14:00:02.041986 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 14:00:02.042004 | controller | repo: downloading from remote: extras-common 2025-10-13 14:00:02.042021 | controller | CentOS Stream 9 - Extras packages 133 kB/s | 20 kB 00:00 2025-10-13 14:00:02.042037 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 14:00:02.042054 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 14:00:02.042070 | controller | Completion plugin: Generating completion cache... 2025-10-13 14:00:02.042088 | controller | Metadata cache created. 2025-10-13 14:00:02.042115 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.960116 2025-10-13 14:00:02.056795 | 2025-10-13 14:00:02.056873 | PLAY RECAP 2025-10-13 14:00:02.056912 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 14:00:02.056938 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 14:00:02.056956 | 2025-10-13 14:00:02.167341 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 14:00:02.168513 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:00:02.772294 | 2025-10-13 14:00:02.772426 | PLAY [all] 2025-10-13 14:00:02.793416 | 2025-10-13 14:00:02.793517 | TASK [Install binary dependencies] 2025-10-13 14:00:02.862859 | controller | ok 2025-10-13 14:00:02.883254 | 2025-10-13 14:00:02.883373 | TASK [bindep : Include find tasks] 2025-10-13 14:00:02.922534 | controller | ok 2025-10-13 14:00:02.930421 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 14:00:02.936126 | 2025-10-13 14:00:02.936188 | TASK [bindep : Look for bindep.txt] 2025-10-13 14:00:03.349143 | controller | ok 2025-10-13 14:00:03.365176 | 2025-10-13 14:00:03.365373 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:00:03.412512 | controller | ok 2025-10-13 14:00:03.421151 | 2025-10-13 14:00:03.421273 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 14:00:03.448055 | controller | skipping: Conditional result was False 2025-10-13 14:00:03.460052 | 2025-10-13 14:00:03.460423 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:00:03.488118 | controller | skipping: Conditional result was False 2025-10-13 14:00:03.498164 | 2025-10-13 14:00:03.498297 | TASK [bindep : Look for bindep fallback file] 2025-10-13 14:00:03.555263 | controller | skipping: Conditional result was False 2025-10-13 14:00:03.565363 | 2025-10-13 14:00:03.565505 | TASK [bindep : Define bindep_file fact] 2025-10-13 14:00:03.591756 | controller | skipping: Conditional result was False 2025-10-13 14:00:03.601418 | 2025-10-13 14:00:03.601561 | TASK [bindep : Include bindep tasks] 2025-10-13 14:00:03.659472 | controller | ok 2025-10-13 14:00:03.667057 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 14:00:03.675664 | 2025-10-13 14:00:03.675780 | TASK [bindep : Look for bindep command] 2025-10-13 14:00:03.730831 | controller | skipping: Conditional result was False 2025-10-13 14:00:03.739664 | 2025-10-13 14:00:03.739786 | TASK [bindep : Check for system bindep] 2025-10-13 14:00:04.278451 | controller | ok: Runtime: 0:00:00.006118 2025-10-13 14:00:04.284901 | 2025-10-13 14:00:04.284974 | TASK [bindep : Define bindep_command fact] 2025-10-13 14:00:04.310420 | controller | skipping: Conditional result was False 2025-10-13 14:00:04.318834 | 2025-10-13 14:00:04.318962 | TASK [bindep : Include install tasks] 2025-10-13 14:00:04.348594 | controller | ok 2025-10-13 14:00:04.356399 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 14:00:04.366078 | 2025-10-13 14:00:04.366167 | TASK [bindep : Create temp dir for bindep] 2025-10-13 14:00:04.778829 | controller | changed 2025-10-13 14:00:04.790500 | 2025-10-13 14:00:04.790645 | TASK [Ensure we have pip dependencies] 2025-10-13 14:00:04.822397 | controller | ok 2025-10-13 14:00:04.876007 | 2025-10-13 14:00:04.876176 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 10:00:05.169612 | controller | /usr/bin/pip3 2025-10-13 10:00:05.220177 | controller | /usr/bin/python3: No module named wheel 2025-10-13 14:00:05.415637 | controller | ok: Runtime: 0:00:00.067923 2025-10-13 14:00:05.429798 | 2025-10-13 14:00:05.429960 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 14:00:05.460534 | controller | ok: "/var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 14:00:05.476616 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 14:00:05.491477 | 2025-10-13 14:00:05.491594 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 14:00:08.015117 | controller | changed 2025-10-13 14:00:08.026357 | 2025-10-13 14:00:08.026495 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 14:00:08.098310 | controller | skipping: Conditional result was False 2025-10-13 14:00:08.113418 | 2025-10-13 14:00:08.113566 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 14:00:08.164458 | controller | skipping: Conditional result was False 2025-10-13 14:00:08.174257 | 2025-10-13 14:00:08.174375 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 14:00:08.220275 | controller | skipping: Conditional result was False 2025-10-13 14:00:08.228949 | 2025-10-13 14:00:08.229044 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 14:00:08.244283 | controller | skipping: Conditional result was False 2025-10-13 14:00:08.252201 | 2025-10-13 14:00:08.252289 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 14:00:08.791477 | controller | skipping: Conditional result was False 2025-10-13 14:00:08.802009 | 2025-10-13 14:00:08.802271 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 14:00:08.848817 | controller | skipping: Conditional result was False 2025-10-13 14:00:08.857178 | 2025-10-13 14:00:08.857298 | TASK [ensure-pip : Install pip from source] 2025-10-13 14:00:08.881938 | controller | skipping: Conditional result was False 2025-10-13 14:00:08.892323 | 2025-10-13 14:00:08.892433 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 10:00:09.211004 | controller | /usr/bin/python3 2025-10-13 14:00:09.436062 | controller | ok: Runtime: 0:00:00.008182 2025-10-13 14:00:09.449019 | 2025-10-13 14:00:09.449162 | TASK [ensure-pip : Set host default] 2025-10-13 14:00:09.533046 | controller | ok 2025-10-13 14:00:09.545163 | 2025-10-13 14:00:09.545340 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 14:00:09.631695 | controller | ok 2025-10-13 14:00:09.656116 | 2025-10-13 14:00:09.656223 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 14:00:14.495776 | controller | changed 2025-10-13 14:00:14.504074 | 2025-10-13 14:00:14.504220 | TASK [bindep : Define bindep_command] 2025-10-13 14:00:14.550263 | controller | ok 2025-10-13 14:00:14.557952 | 2025-10-13 14:00:14.558376 | LOOP [bindep : Include package tasks] 2025-10-13 14:00:14.617497 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 14:00:14.618588 | controller | ok: All items complete 2025-10-13 14:00:14.618629 | 2025-10-13 14:00:14.640862 | controller | included: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 14:00:14.653746 | 2025-10-13 14:00:14.653837 | TASK [bindep : Define bindep_run fact] 2025-10-13 14:00:14.696391 | controller | ok 2025-10-13 14:00:14.704322 | 2025-10-13 14:00:14.704435 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 10:00:16.206292 | controller | podman 2025-10-13 10:00:16.259125 | controller | python3-jmespath 2025-10-13 10:00:16.259219 | controller | python3-libvirt 2025-10-13 10:00:16.259226 | controller | python3-lxml 2025-10-13 10:00:16.259236 | controller | python3-netaddr 2025-10-13 14:00:16.743804 | controller | ok: Runtime: 0:00:01.211584 2025-10-13 14:00:16.752913 | 2025-10-13 14:00:16.753044 | TASK [bindep : Install distro packages from bindep] 2025-10-13 14:01:28.399385 | controller | changed 2025-10-13 14:01:28.421701 | 2025-10-13 14:01:28.422024 | TASK [bindep : Check that packages are installed] 2025-10-13 14:01:29.973164 | controller | ok: Runtime: 0:00:01.126731 2025-10-13 14:01:29.987230 | 2025-10-13 14:01:29.987403 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 14:01:30.026212 | controller | skipping: Conditional result was False 2025-10-13 14:01:30.047087 | 2025-10-13 14:01:30.047258 | TASK [Run test-setup role] 2025-10-13 14:01:30.072635 | controller | ok 2025-10-13 14:01:30.102142 | 2025-10-13 14:01:30.102321 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 14:01:30.352190 | controller | ok 2025-10-13 14:01:30.360324 | 2025-10-13 14:01:30.360548 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 14:01:30.906041 | controller | skipping: Conditional result was False 2025-10-13 14:01:30.952361 | 2025-10-13 14:01:30.952537 | TASK [bindep : Remove bindep temp dir] 2025-10-13 14:01:31.349326 | controller | ok 2025-10-13 14:01:31.374174 | 2025-10-13 14:01:31.374296 | PLAY RECAP 2025-10-13 14:01:31.374389 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 14:01:31.374438 | 2025-10-13 14:01:31.490427 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 14:01:31.492203 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:01:32.122073 | 2025-10-13 14:01:32.122191 | PLAY [all] 2025-10-13 14:01:32.141887 | 2025-10-13 14:01:32.142005 | TASK [Abort when test_command variable is undefined] 2025-10-13 14:01:32.167264 | controller | skipping: Conditional result was False 2025-10-13 14:01:32.173072 | 2025-10-13 14:01:32.173154 | TASK [Convert test_command to list] 2025-10-13 14:01:32.217858 | controller | skipping: Conditional result was False 2025-10-13 14:01:32.226510 | 2025-10-13 14:01:32.226598 | TASK [Use test_command list] 2025-10-13 14:01:32.283362 | controller | ok 2025-10-13 14:01:32.295975 | 2025-10-13 14:01:32.296117 | LOOP [Run test_command] 2025-10-13 14:01:32.734640 | controller | no check to run 2025-10-13 14:01:32.734900 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006124 2025-10-13 14:01:32.777679 | 2025-10-13 14:01:32.777820 | PLAY RECAP 2025-10-13 14:01:32.777882 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:01:32.777913 | 2025-10-13 14:01:32.887974 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 14:01:32.888991 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:01:33.463299 | 2025-10-13 14:01:33.463421 | PLAY [all] 2025-10-13 14:01:33.485408 | 2025-10-13 14:01:33.485521 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 14:01:33.921604 | controller | changed: non-zero return code 2025-10-13 14:01:33.934777 | 2025-10-13 14:01:33.934995 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 14:01:33.963559 | controller | skipping: Conditional result was False 2025-10-13 14:01:33.978006 | 2025-10-13 14:01:33.978234 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 14:01:34.022000 | 2025-10-13 14:01:34.022292 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 14:01:34.066430 | 2025-10-13 14:01:34.066791 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 14:01:34.096364 | controller | skipping: Conditional result was False 2025-10-13 14:01:34.114937 | 2025-10-13 14:01:34.115154 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 14:01:34.154799 | 2025-10-13 14:01:34.155051 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 14:01:34.182534 | controller | skipping: Conditional result was False 2025-10-13 14:01:34.191437 | 2025-10-13 14:01:34.191572 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 14:01:34.218200 | controller | skipping: Conditional result was False 2025-10-13 14:01:34.226339 | 2025-10-13 14:01:34.226442 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 14:01:34.252506 | controller | skipping: Conditional result was False 2025-10-13 14:01:34.286702 | 2025-10-13 14:01:34.286879 | PLAY RECAP 2025-10-13 14:01:34.286940 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 14:01:34.286968 | 2025-10-13 14:01:34.415335 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 14:01:34.416512 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:01:35.089429 | 2025-10-13 14:01:35.089561 | PLAY [all] 2025-10-13 14:01:35.109941 | 2025-10-13 14:01:35.110087 | TASK [include_role : fetch-output] 2025-10-13 14:01:35.160418 | controller | ok 2025-10-13 14:01:35.179264 | 2025-10-13 14:01:35.179402 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 14:01:35.235499 | controller | skipping: Conditional result was False 2025-10-13 14:01:35.249248 | 2025-10-13 14:01:35.249471 | TASK [fetch-output : Set log path for single node] 2025-10-13 14:01:35.292125 | controller | ok 2025-10-13 14:01:35.304825 | 2025-10-13 14:01:35.305217 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 14:01:35.774304 | controller -> localhost | ok: "/var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/logs" 2025-10-13 14:01:36.047789 | controller -> localhost | changed: "/var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/artifacts" 2025-10-13 14:01:36.273339 | controller -> localhost | changed: "/var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/docs" 2025-10-13 14:01:36.286359 | 2025-10-13 14:01:36.286519 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 14:01:37.024318 | controller | changed: .d..t...... ./ 2025-10-13 14:01:37.024896 | controller | changed: All items complete 2025-10-13 14:01:37.024973 | 2025-10-13 14:01:37.580102 | controller | changed: .d..t...... ./ 2025-10-13 14:01:38.158719 | controller | changed: .d..t...... ./ 2025-10-13 14:01:38.184062 | 2025-10-13 14:01:38.184253 | TASK [include_role : fetch-output-openshift] 2025-10-13 14:01:38.220015 | controller | skipping: Conditional result was False 2025-10-13 14:01:38.234912 | 2025-10-13 14:01:38.235068 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 14:01:38.719349 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.015751 2025-10-13 14:01:39.033881 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013830 2025-10-13 14:01:39.064426 | 2025-10-13 14:01:39.064548 | PLAY [all] 2025-10-13 14:01:39.081930 | 2025-10-13 14:01:39.082052 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 14:01:39.557676 | controller | changed 2025-10-13 14:01:39.609452 | 2025-10-13 14:01:39.609600 | PLAY RECAP 2025-10-13 14:01:39.609673 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 14:01:39.609714 | 2025-10-13 14:01:39.758124 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 14:01:39.759917 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 14:01:40.409522 | 2025-10-13 14:01:40.409679 | PLAY [localhost] 2025-10-13 14:01:40.429151 | 2025-10-13 14:01:40.429283 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 14:01:40.885600 | localhost | changed 2025-10-13 14:01:40.890519 | 2025-10-13 14:01:40.890598 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 14:01:40.935288 | localhost | ok 2025-10-13 14:01:40.953982 | 2025-10-13 14:01:40.954133 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 14:01:41.454399 | localhost | changed 2025-10-13 14:01:41.463140 | 2025-10-13 14:01:41.463339 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 14:01:42.255533 | localhost | changed 2025-10-13 14:01:42.261574 | 2025-10-13 14:01:42.261697 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 14:01:42.739678 | localhost | Identity added: /var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/tmp/ansible.nhp5fyh8 (/var/lib/zuul/builds/979ae36f74314b14b5b0112c117bcfab/work/tmp/ansible.nhp5fyh8) 2025-10-13 14:01:42.739885 | localhost | ok: Runtime: 0:00:00.009550 2025-10-13 14:01:42.744677 | 2025-10-13 14:01:42.744838 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 14:01:43.058583 | localhost | ok: Runtime: 0:00:00.005367 2025-10-13 14:01:43.064635 | 2025-10-13 14:01:43.064701 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 14:01:43.114287 | localhost | changed 2025-10-13 14:01:43.118719 | 2025-10-13 14:01:43.118826 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 14:01:43.547812 | localhost | changed 2025-10-13 14:01:43.570649 | 2025-10-13 14:01:43.570774 | PLAY [localhost] 2025-10-13 14:01:43.583860 | 2025-10-13 14:01:43.583951 | TASK [Generate bulk log download script] 2025-10-13 14:01:43.603208 | localhost | ok 2025-10-13 14:01:43.617032 | 2025-10-13 14:01:43.617155 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 14:01:43.656688 | localhost | ok: All assertions passed 2025-10-13 14:01:43.661652 | 2025-10-13 14:01:43.661720 | TASK [local-log-download : Create download script] 2025-10-13 14:01:44.176383 | localhost -> localhost | changed 2025-10-13 14:01:44.186495 | 2025-10-13 14:01:44.186646 | TASK [Register quick-download link] 2025-10-13 14:01:44.206774 | localhost | ok 2025-10-13 14:01:44.251688 | 2025-10-13 14:01:44.251832 | PLAY [logserver.rdoproject.org] 2025-10-13 14:01:44.261711 | 2025-10-13 14:01:44.261814 | TASK [Set zuul-log-path fact] 2025-10-13 14:01:44.279998 | logserver.rdoproject.org | ok 2025-10-13 14:01:44.289418 | 2025-10-13 14:01:44.289491 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 14:01:44.319705 | logserver.rdoproject.org | ok 2025-10-13 14:01:44.326892 | 2025-10-13 14:01:44.327021 | TASK [upload-logs : Create log directories] 2025-10-13 14:01:45.000891 | logserver.rdoproject.org | changed 2025-10-13 14:01:45.006072 | 2025-10-13 14:01:45.006204 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 14:01:45.401485 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007402 2025-10-13 14:01:45.408213 | 2025-10-13 14:01:45.408330 | TASK [upload-logs : Upload logs to log server] 2025-10-13 14:01:46.177148 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 14:01:46.184287 | 2025-10-13 14:01:46.184473 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 14:01:46.230535 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:01:46.239901 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:01:46.255900 | 2025-10-13 14:01:46.256229 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 14:01:46.297762 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:01:46.298130 | 2025-10-13 14:01:46.301934 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 14:01:46.309707 | 2025-10-13 14:01:46.310022 | LOOP [upload-logs : Upload console log and json output]