2025-10-02 14:13:04.642219 | Job console starting... 2025-10-02 14:13:04.653545 | Updating repositories 2025-10-02 14:13:04.690000 | Preparing job workspace 2025-10-02 14:13:08.546796 | Running Ansible setup... 2025-10-02 14:13:13.056778 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 14:13:13.782216 | 2025-10-02 14:13:13.782359 | PLAY [localhost] 2025-10-02 14:13:13.792701 | 2025-10-02 14:13:13.792809 | TASK [Gathering Facts] 2025-10-02 14:13:15.002609 | localhost | ok 2025-10-02 14:13:15.020921 | 2025-10-02 14:13:15.021085 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 14:13:15.605884 | localhost -> localhost | changed 2025-10-02 14:13:15.612749 | 2025-10-02 14:13:15.612939 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 14:13:16.876197 | localhost -> localhost | changed 2025-10-02 14:13:16.885604 | 2025-10-02 14:13:16.885686 | TASK [Setup log path fact] 2025-10-02 14:13:16.913647 | localhost | ok 2025-10-02 14:13:16.930156 | 2025-10-02 14:13:16.932980 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 14:13:16.972162 | localhost | ok 2025-10-02 14:13:16.983002 | 2025-10-02 14:13:16.983113 | TASK [emit-job-header : Print job information] 2025-10-02 14:13:17.031957 | # Job Information 2025-10-02 14:13:17.032147 | Ansible Version: 2.15.12 2025-10-02 14:13:17.032185 | Job: cifmw-molecule-openshift_adm 2025-10-02 14:13:17.032217 | Pipeline: github-check 2025-10-02 14:13:17.032241 | Executor: ze01.softwarefactory-project.io 2025-10-02 14:13:17.032264 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 14:13:17.032289 | Log URL (when completed): https://logserver.rdoproject.org/dbb/rdoproject.org/dbbf35ce479b4a07b86710e30f058114/ 2025-10-02 14:13:17.032315 | Event ID: be9565c0-9f99-11f0-9e8d-1085adf9bc04 2025-10-02 14:13:17.036258 | 2025-10-02 14:13:17.036336 | LOOP [emit-job-header : Print node information] 2025-10-02 14:13:17.137829 | localhost | ok: 2025-10-02 14:13:17.138052 | localhost | # Node Information 2025-10-02 14:13:17.138083 | localhost | Inventory Hostname: controller 2025-10-02 14:13:17.138106 | localhost | Hostname: np0005466328 2025-10-02 14:13:17.138125 | localhost | Username: zuul 2025-10-02 14:13:17.138144 | localhost | Distro: CentOS 9 2025-10-02 14:13:17.138162 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 14:13:17.138179 | localhost | Region: RegionOne 2025-10-02 14:13:17.138195 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-02 14:13:17.138211 | localhost | Product Name: OpenStack Nova 2025-10-02 14:13:17.138227 | localhost | Interface IP: 38.102.83.143 2025-10-02 14:13:17.167220 | 2025-10-02 14:13:17.167308 | PLAY [all] 2025-10-02 14:13:17.183834 | 2025-10-02 14:13:17.183955 | TASK [Gather network facts] 2025-10-02 14:13:17.719903 | controller | ok 2025-10-02 14:13:17.747427 | 2025-10-02 14:13:17.747565 | TASK [include_role : start-zuul-console] 2025-10-02 14:13:17.775702 | controller | ok 2025-10-02 14:13:17.793499 | 2025-10-02 14:13:17.793590 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 14:13:18.243112 | controller | ok 2025-10-02 14:13:18.252127 | 2025-10-02 14:13:18.252192 | TASK [include_role : add-build-sshkey] 2025-10-02 14:13:18.280579 | controller | ok 2025-10-02 14:13:18.301504 | 2025-10-02 14:13:18.301655 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 14:13:18.618570 | controller -> localhost | ok 2025-10-02 14:13:18.627676 | 2025-10-02 14:13:18.627829 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 14:13:18.692528 | controller | ok 2025-10-02 14:13:18.730280 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 14:13:18.739496 | 2025-10-02 14:13:18.739610 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 14:13:19.453440 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 14:13:19.453681 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/dbbf35ce479b4a07b86710e30f058114_id_rsa. 2025-10-02 14:13:19.453716 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/dbbf35ce479b4a07b86710e30f058114_id_rsa.pub. 2025-10-02 14:13:19.453741 | controller -> localhost | The key fingerprint is: 2025-10-02 14:13:19.453762 | controller -> localhost | SHA256:S0uWVNpUQv43B5dV1D3bAYxdmYUFDrk7XZoHjZMXDag zuul-build-sshkey 2025-10-02 14:13:19.453783 | controller -> localhost | The key's randomart image is: 2025-10-02 14:13:19.453803 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 14:13:19.453822 | controller -> localhost | | .=.*+=B#| 2025-10-02 14:13:19.453843 | controller -> localhost | | * oo=.**| 2025-10-02 14:13:19.453862 | controller -> localhost | | o o. .o=B| 2025-10-02 14:13:19.453882 | controller -> localhost | | . .E.. =+=| 2025-10-02 14:13:19.453903 | controller -> localhost | | S .ooB.| 2025-10-02 14:13:19.453929 | controller -> localhost | | + o o.+o.| 2025-10-02 14:13:19.453955 | controller -> localhost | | o . . | 2025-10-02 14:13:19.453979 | controller -> localhost | | | 2025-10-02 14:13:19.453998 | controller -> localhost | | | 2025-10-02 14:13:19.454178 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 14:13:19.454234 | controller -> localhost | ok: Runtime: 0:00:00.111856 2025-10-02 14:13:19.460139 | 2025-10-02 14:13:19.460211 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 14:13:19.488238 | controller | ok 2025-10-02 14:13:19.499190 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 14:13:19.507238 | 2025-10-02 14:13:19.507308 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 14:13:19.520731 | controller | skipping: Conditional result was False 2025-10-02 14:13:19.527924 | 2025-10-02 14:13:19.528030 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 14:13:20.027651 | controller | changed 2025-10-02 14:13:20.043447 | 2025-10-02 14:13:20.043597 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 14:13:20.408257 | controller | ok 2025-10-02 14:13:20.415535 | 2025-10-02 14:13:20.415783 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 14:13:21.447979 | controller | changed 2025-10-02 14:13:21.453432 | 2025-10-02 14:13:21.453514 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 14:13:22.864130 | controller | changed 2025-10-02 14:13:22.869599 | 2025-10-02 14:13:22.869667 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 14:13:22.894042 | controller | skipping: Conditional result was False 2025-10-02 14:13:22.900638 | 2025-10-02 14:13:22.900718 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 14:13:23.285067 | controller -> localhost | changed 2025-10-02 14:13:23.296115 | 2025-10-02 14:13:23.296211 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 14:13:23.606955 | controller -> localhost | Identity added: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/dbbf35ce479b4a07b86710e30f058114_id_rsa (zuul-build-sshkey) 2025-10-02 14:13:23.607177 | controller -> localhost | ok: Runtime: 0:00:00.012413 2025-10-02 14:13:23.613141 | 2025-10-02 14:13:23.613210 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 14:13:23.993205 | controller | ok 2025-10-02 14:13:23.998257 | 2025-10-02 14:13:23.998318 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 14:13:24.032348 | controller | skipping: Conditional result was False 2025-10-02 14:13:24.051969 | 2025-10-02 14:13:24.052079 | TASK [include_role : validate-host] 2025-10-02 14:13:24.082461 | controller | ok 2025-10-02 14:13:24.108382 | 2025-10-02 14:13:24.108605 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 14:13:24.158852 | controller | ok 2025-10-02 14:13:24.198381 | 2025-10-02 14:13:24.198513 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 14:13:24.481174 | controller -> localhost | ok 2025-10-02 14:13:24.498374 | 2025-10-02 14:13:24.498537 | TASK [validate-host : Collect information about the host] 2025-10-02 14:13:25.310771 | controller | ok 2025-10-02 14:13:25.325368 | 2025-10-02 14:13:25.325509 | TASK [validate-host : Sanitize hostname] 2025-10-02 14:13:25.386886 | controller | ok 2025-10-02 14:13:25.392065 | 2025-10-02 14:13:25.392146 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 14:13:25.879282 | controller -> localhost | changed 2025-10-02 14:13:25.886729 | 2025-10-02 14:13:25.886874 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 14:13:26.338332 | controller | ok 2025-10-02 14:13:26.343587 | 2025-10-02 14:13:26.343680 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 14:13:26.826974 | controller -> localhost | changed 2025-10-02 14:13:26.838837 | 2025-10-02 14:13:26.838955 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 14:13:26.883317 | controller | skipping: Conditional result was False 2025-10-02 14:13:26.888716 | 2025-10-02 14:13:26.888791 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 14:13:26.934925 | controller | skipping: Conditional result was False 2025-10-02 14:13:26.940479 | 2025-10-02 14:13:26.940560 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 14:13:27.249495 | controller | ok: "logs" 2025-10-02 14:13:27.249767 | controller | ok: All items complete 2025-10-02 14:13:27.249797 | 2025-10-02 14:13:27.514600 | controller | ok: "artifacts" 2025-10-02 14:13:27.742456 | controller | ok: "docs" 2025-10-02 14:13:27.749764 | 2025-10-02 14:13:27.749866 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 14:13:28.136485 | controller | changed: "logs" 2025-10-02 14:13:28.388743 | controller | changed: "artifacts" 2025-10-02 14:13:28.664745 | controller | changed: "docs" 2025-10-02 14:13:28.717269 | 2025-10-02 14:13:28.717373 | PLAY RECAP 2025-10-02 14:13:28.717419 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 14:13:28.717447 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 14:13:28.717466 | 2025-10-02 14:13:29.009208 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 14:13:29.010632 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 14:13:29.944192 | 2025-10-02 14:13:29.944310 | PLAY [localhost] 2025-10-02 14:13:29.961044 | 2025-10-02 14:13:29.961125 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-02 14:13:30.541225 | localhost | ok 2025-10-02 14:13:30.548425 | 2025-10-02 14:13:30.548553 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-02 14:13:31.265904 | localhost | changed 2025-10-02 14:13:31.296121 | 2025-10-02 14:13:31.296213 | PLAY [all] 2025-10-02 14:13:31.334941 | 2025-10-02 14:13:31.335287 | TASK [include_role : prepare-workspace] 2025-10-02 14:13:31.374693 | controller | ok 2025-10-02 14:13:31.426279 | 2025-10-02 14:13:31.426408 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 14:13:31.948884 | controller | ok 2025-10-02 14:13:31.956389 | 2025-10-02 14:13:31.956488 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 14:13:34.519766 | controller | Output suppressed because no_log was given 2025-10-02 14:13:34.533165 | 2025-10-02 14:13:34.533289 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 14:13:34.849483 | controller | changed: "logs" 2025-10-02 14:13:35.065305 | controller | changed: "artifacts" 2025-10-02 14:13:35.292003 | controller | changed: "docs" 2025-10-02 14:13:35.300044 | 2025-10-02 14:13:35.300175 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 14:13:35.606091 | controller | changed: "logs" 2025-10-02 14:13:35.606398 | controller | changed: All items complete 2025-10-02 14:13:35.606442 | 2025-10-02 14:13:35.846113 | controller | changed: "artifacts" 2025-10-02 14:13:36.065935 | controller | changed: "docs" 2025-10-02 14:13:36.085887 | 2025-10-02 14:13:36.085976 | TASK [Check if worker can sudo] 2025-10-02 14:13:37.128888 | controller | ok: Runtime: 0:00:00.059803 2025-10-02 14:13:37.135774 | 2025-10-02 14:13:37.135863 | TASK [configure-mirrors : Gather needed facts] 2025-10-02 14:13:37.254864 | controller | skipping: Conditional result was False 2025-10-02 14:13:37.263833 | 2025-10-02 14:13:37.263961 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-02 14:13:37.481363 | controller | ok 2025-10-02 14:13:37.530217 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-02 14:13:37.538360 | 2025-10-02 14:13:37.538459 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-02 14:13:37.846090 | controller | ok 2025-10-02 14:13:37.854033 | 2025-10-02 14:13:37.854126 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-02 14:13:37.969889 | controller | ok: "/var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-02 14:13:37.982760 | 2025-10-02 14:13:37.982895 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-02 14:13:39.058397 | controller | changed 2025-10-02 14:13:39.067636 | 2025-10-02 14:13:39.067815 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-02 14:13:39.151672 | controller | ok: "/var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-02 14:13:39.151934 | controller | ok: All items complete 2025-10-02 14:13:39.151966 | 2025-10-02 14:13:39.211047 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-02 14:13:39.219899 | 2025-10-02 14:13:39.220066 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-02 14:13:40.298382 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-02 14:13:41.184653 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-02 14:13:41.200251 | 2025-10-02 14:13:41.200372 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-02 14:13:41.745256 | controller | changed: section and option added 2025-10-02 14:13:41.795118 | 2025-10-02 14:13:41.795259 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-02 14:13:42.650575 | controller | 29 files removed 2025-10-02 14:13:42.650793 | controller | ok: Item: dnf clean all Runtime: 0:00:00.528225 2025-10-02 14:13:42.650835 | controller | changed: All items complete 2025-10-02 14:13:42.650858 | 2025-10-02 14:13:54.508596 | 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-02 14:13:54.508688 | controller | DNF version: 4.14.0 2025-10-02 14:13:54.508713 | controller | cachedir: /var/cache/dnf 2025-10-02 14:13:54.508733 | controller | Making cache files for all metadata files. 2025-10-02 14:13:54.508752 | controller | baseos: has expired and will be refreshed. 2025-10-02 14:13:54.508769 | controller | appstream: has expired and will be refreshed. 2025-10-02 14:13:54.508785 | controller | crb: has expired and will be refreshed. 2025-10-02 14:13:54.508808 | controller | extras-common: has expired and will be refreshed. 2025-10-02 14:13:54.508825 | controller | repo: downloading from remote: baseos 2025-10-02 14:13:54.508841 | controller | CentOS Stream 9 - BaseOS 36 MB/s | 8.8 MB 00:00 2025-10-02 14:13:54.508857 | controller | baseos: using metadata from Tue 30 Sep 2025 01:12:56 PM EDT. 2025-10-02 14:13:54.508873 | controller | repo: downloading from remote: appstream 2025-10-02 14:13:54.508889 | controller | CentOS Stream 9 - AppStream 81 MB/s | 25 MB 00:00 2025-10-02 14:13:54.508904 | controller | appstream: using metadata from Tue 30 Sep 2025 01:16:29 PM EDT. 2025-10-02 14:13:54.508920 | controller | repo: downloading from remote: crb 2025-10-02 14:13:54.508936 | controller | CentOS Stream 9 - CRB 9.8 MB/s | 7.1 MB 00:00 2025-10-02 14:13:54.508952 | controller | crb: using metadata from Tue 30 Sep 2025 01:20:54 PM EDT. 2025-10-02 14:13:54.508969 | controller | repo: downloading from remote: extras-common 2025-10-02 14:13:54.508986 | controller | CentOS Stream 9 - Extras packages 115 kB/s | 20 kB 00:00 2025-10-02 14:13:54.509003 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-02 14:13:54.509024 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-02 14:13:54.509085 | controller | Completion plugin: Generating completion cache... 2025-10-02 14:13:54.509105 | controller | Metadata cache created. 2025-10-02 14:13:54.509133 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.555763 2025-10-02 14:13:54.564202 | 2025-10-02 14:13:54.564299 | PLAY RECAP 2025-10-02 14:13:54.564340 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 14:13:54.564367 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 14:13:54.564385 | 2025-10-02 14:13:54.681685 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-02 14:13:54.682506 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 14:13:55.345683 | 2025-10-02 14:13:55.345846 | PLAY [all] 2025-10-02 14:13:55.368190 | 2025-10-02 14:13:55.368293 | TASK [Install binary dependencies] 2025-10-02 14:13:55.417753 | controller | ok 2025-10-02 14:13:55.441442 | 2025-10-02 14:13:55.441550 | TASK [bindep : Include find tasks] 2025-10-02 14:13:55.470725 | controller | ok 2025-10-02 14:13:55.478767 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-02 14:13:55.484821 | 2025-10-02 14:13:55.484895 | TASK [bindep : Look for bindep.txt] 2025-10-02 14:13:55.883602 | controller | ok 2025-10-02 14:13:55.896915 | 2025-10-02 14:13:55.896987 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:55.925838 | controller | ok 2025-10-02 14:13:55.930971 | 2025-10-02 14:13:55.931052 | TASK [bindep : Look for other-requirements.txt] 2025-10-02 14:13:55.944867 | controller | skipping: Conditional result was False 2025-10-02 14:13:55.951419 | 2025-10-02 14:13:55.951523 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:55.977485 | controller | skipping: Conditional result was False 2025-10-02 14:13:55.983337 | 2025-10-02 14:13:55.983413 | TASK [bindep : Look for bindep fallback file] 2025-10-02 14:13:56.017632 | controller | skipping: Conditional result was False 2025-10-02 14:13:56.023759 | 2025-10-02 14:13:56.023840 | TASK [bindep : Define bindep_file fact] 2025-10-02 14:13:56.048606 | controller | skipping: Conditional result was False 2025-10-02 14:13:56.054350 | 2025-10-02 14:13:56.054413 | TASK [bindep : Include bindep tasks] 2025-10-02 14:13:56.084060 | controller | ok 2025-10-02 14:13:56.092221 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-02 14:13:56.099925 | 2025-10-02 14:13:56.099986 | TASK [bindep : Look for bindep command] 2025-10-02 14:13:56.123923 | controller | skipping: Conditional result was False 2025-10-02 14:13:56.131256 | 2025-10-02 14:13:56.131347 | TASK [bindep : Check for system bindep] 2025-10-02 14:13:57.164606 | controller | ok: Runtime: 0:00:00.004436 2025-10-02 14:13:57.170471 | 2025-10-02 14:13:57.170539 | TASK [bindep : Define bindep_command fact] 2025-10-02 14:13:57.204648 | controller | skipping: Conditional result was False 2025-10-02 14:13:57.211255 | 2025-10-02 14:13:57.211320 | TASK [bindep : Include install tasks] 2025-10-02 14:13:57.250747 | controller | ok 2025-10-02 14:13:57.258731 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-02 14:13:57.267965 | 2025-10-02 14:13:57.268043 | TASK [bindep : Create temp dir for bindep] 2025-10-02 14:13:57.665406 | controller | changed 2025-10-02 14:13:57.679188 | 2025-10-02 14:13:57.679350 | TASK [Ensure we have pip dependencies] 2025-10-02 14:13:57.721708 | controller | ok 2025-10-02 14:13:57.754669 | 2025-10-02 14:13:57.754781 | TASK [ensure-pip : Check if pip is installed] 2025-10-02 10:13:58.016591 | controller | /usr/bin/pip3 2025-10-02 10:13:58.037096 | controller | /usr/bin/python3: No module named wheel 2025-10-02 14:13:58.288432 | controller | ok: Runtime: 0:00:00.032511 2025-10-02 14:13:58.294621 | 2025-10-02 14:13:58.294691 | LOOP [ensure-pip : Install pip from packages] 2025-10-02 14:13:58.326460 | controller | ok: "/var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-02 14:13:58.355827 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-02 14:13:58.367422 | 2025-10-02 14:13:58.367535 | TASK [ensure-pip : Install Python 3 pip] 2025-10-02 14:14:00.868625 | controller | changed 2025-10-02 14:14:00.874149 | 2025-10-02 14:14:00.874213 | TASK [ensure-pip : Check for EPEL repository] 2025-10-02 14:14:00.921165 | controller | skipping: Conditional result was False 2025-10-02 14:14:00.927904 | 2025-10-02 14:14:00.927977 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-02 14:14:00.983960 | controller | skipping: Conditional result was False 2025-10-02 14:14:00.991381 | 2025-10-02 14:14:00.991458 | TASK [ensure-pip : Install Python 2 pip] 2025-10-02 14:14:01.035614 | controller | skipping: Conditional result was False 2025-10-02 14:14:01.043147 | 2025-10-02 14:14:01.043228 | TASK [ensure-pip : Ensure setuptools] 2025-10-02 14:14:01.067439 | controller | skipping: Conditional result was False 2025-10-02 14:14:01.073832 | 2025-10-02 14:14:01.073898 | TASK [ensure-pip : Check for ensurepip module] 2025-10-02 14:14:01.606299 | controller | skipping: Conditional result was False 2025-10-02 14:14:01.614458 | 2025-10-02 14:14:01.614537 | TASK [ensure-pip : Ensure python3-venv] 2025-10-02 14:14:01.644173 | controller | skipping: Conditional result was False 2025-10-02 14:14:01.653572 | 2025-10-02 14:14:01.653666 | TASK [ensure-pip : Install pip from source] 2025-10-02 14:14:01.684460 | controller | skipping: Conditional result was False 2025-10-02 14:14:01.690673 | 2025-10-02 14:14:01.690759 | TASK [ensure-pip : Probe for venv python full path] 2025-10-02 10:14:01.974589 | controller | /usr/bin/python3 2025-10-02 14:14:02.237337 | controller | ok: Runtime: 0:00:00.007261 2025-10-02 14:14:02.243483 | 2025-10-02 14:14:02.243550 | TASK [ensure-pip : Set host default] 2025-10-02 14:14:02.311468 | controller | ok 2025-10-02 14:14:02.316777 | 2025-10-02 14:14:02.316843 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-02 14:14:02.378327 | controller | ok 2025-10-02 14:14:02.389516 | 2025-10-02 14:14:02.389587 | TASK [bindep : Install bindep into temporary venv] 2025-10-02 14:14:06.404258 | controller | changed 2025-10-02 14:14:06.425828 | 2025-10-02 14:14:06.425923 | TASK [bindep : Define bindep_command] 2025-10-02 14:14:06.482843 | controller | ok 2025-10-02 14:14:06.497923 | 2025-10-02 14:14:06.498038 | LOOP [bindep : Include package tasks] 2025-10-02 14:14:06.561088 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-02 14:14:06.561481 | controller | ok: All items complete 2025-10-02 14:14:06.561517 | 2025-10-02 14:14:06.587439 | controller | included: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-02 14:14:06.634691 | 2025-10-02 14:14:06.634835 | TASK [bindep : Define bindep_run fact] 2025-10-02 14:14:06.705712 | controller | ok 2025-10-02 14:14:06.717663 | 2025-10-02 14:14:06.717765 | TASK [bindep : Get list of packages to install from bindep] 2025-10-02 10:14:08.145133 | controller | podman 2025-10-02 10:14:08.188402 | controller | python3-jmespath 2025-10-02 10:14:08.188509 | controller | python3-libvirt 2025-10-02 10:14:08.188649 | controller | python3-lxml 2025-10-02 10:14:08.188663 | controller | python3-netaddr 2025-10-02 14:14:08.322872 | controller | ok: Runtime: 0:00:01.073948 2025-10-02 14:14:08.328833 | 2025-10-02 14:14:08.328901 | TASK [bindep : Install distro packages from bindep] 2025-10-02 14:15:12.799326 | controller | changed 2025-10-02 14:15:12.812309 | 2025-10-02 14:15:12.812506 | TASK [bindep : Check that packages are installed] 2025-10-02 14:15:14.382128 | controller | ok: Runtime: 0:00:01.157903 2025-10-02 14:15:14.392451 | 2025-10-02 14:15:14.392635 | TASK [bindep : Fail if we cannot install all packages] 2025-10-02 14:15:14.419353 | controller | skipping: Conditional result was False 2025-10-02 14:15:14.436262 | 2025-10-02 14:15:14.436383 | TASK [Run test-setup role] 2025-10-02 14:15:14.455904 | controller | ok 2025-10-02 14:15:14.483430 | 2025-10-02 14:15:14.483560 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-02 14:15:14.709458 | controller | ok 2025-10-02 14:15:14.737584 | 2025-10-02 14:15:14.737692 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-02 14:15:15.289789 | controller | skipping: Conditional result was False 2025-10-02 14:15:15.319776 | 2025-10-02 14:15:15.319923 | TASK [bindep : Remove bindep temp dir] 2025-10-02 14:15:15.702541 | controller | ok 2025-10-02 14:15:15.715378 | 2025-10-02 14:15:15.715474 | PLAY RECAP 2025-10-02 14:15:15.715517 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-02 14:15:15.715539 | 2025-10-02 14:15:15.985303 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-02 14:15:15.986492 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 14:15:16.641105 | 2025-10-02 14:15:16.641332 | PLAY [all] 2025-10-02 14:15:16.663563 | 2025-10-02 14:15:16.663666 | TASK [Abort when test_command variable is undefined] 2025-10-02 14:15:16.698747 | controller | skipping: Conditional result was False 2025-10-02 14:15:16.704804 | 2025-10-02 14:15:16.704886 | TASK [Convert test_command to list] 2025-10-02 14:15:16.771121 | controller | skipping: Conditional result was False 2025-10-02 14:15:16.779820 | 2025-10-02 14:15:16.779947 | TASK [Use test_command list] 2025-10-02 14:15:16.857644 | controller | ok 2025-10-02 14:15:16.863572 | 2025-10-02 14:15:16.863653 | LOOP [Run test_command] 2025-10-02 14:15:17.317320 | controller | no check to run 2025-10-02 14:15:17.317511 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.008237 2025-10-02 14:15:17.368509 | 2025-10-02 14:15:17.368606 | PLAY RECAP 2025-10-02 14:15:17.368647 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 14:15:17.368670 | 2025-10-02 14:15:17.473784 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-02 14:15:17.474688 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 14:15:18.057121 | 2025-10-02 14:15:18.057233 | PLAY [all] 2025-10-02 14:15:18.077677 | 2025-10-02 14:15:18.077785 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-02 14:15:18.416929 | controller | changed: non-zero return code 2025-10-02 14:15:18.434479 | 2025-10-02 14:15:18.434636 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-02 14:15:18.449553 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.457254 | 2025-10-02 14:15:18.457387 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-02 14:15:18.497132 | 2025-10-02 14:15:18.497289 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-02 14:15:18.518279 | 2025-10-02 14:15:18.518434 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-02 14:15:18.536459 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.542627 | 2025-10-02 14:15:18.542717 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-02 14:15:18.580186 | 2025-10-02 14:15:18.580421 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-02 14:15:18.628199 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.634354 | 2025-10-02 14:15:18.634467 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-02 14:15:18.680093 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.685958 | 2025-10-02 14:15:18.686081 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-02 14:15:18.721146 | controller | skipping: Conditional result was False 2025-10-02 14:15:18.757558 | 2025-10-02 14:15:18.757658 | PLAY RECAP 2025-10-02 14:15:18.757702 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-02 14:15:18.757723 | 2025-10-02 14:15:18.854469 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-02 14:15:18.855317 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 14:15:19.450214 | 2025-10-02 14:15:19.450323 | PLAY [all] 2025-10-02 14:15:19.470672 | 2025-10-02 14:15:19.470756 | TASK [include_role : fetch-output] 2025-10-02 14:15:19.511344 | controller | ok 2025-10-02 14:15:19.530907 | 2025-10-02 14:15:19.531043 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 14:15:19.586399 | controller | skipping: Conditional result was False 2025-10-02 14:15:19.593372 | 2025-10-02 14:15:19.593455 | TASK [fetch-output : Set log path for single node] 2025-10-02 14:15:19.638174 | controller | ok 2025-10-02 14:15:19.643539 | 2025-10-02 14:15:19.643609 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 14:15:20.080396 | controller -> localhost | ok: "/var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/logs" 2025-10-02 14:15:20.389879 | controller -> localhost | changed: "/var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/artifacts" 2025-10-02 14:15:20.670823 | controller -> localhost | changed: "/var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/docs" 2025-10-02 14:15:20.685278 | 2025-10-02 14:15:20.685379 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 14:15:21.375682 | controller | changed: .d..t...... ./ 2025-10-02 14:15:21.375861 | controller | changed: All items complete 2025-10-02 14:15:21.375889 | 2025-10-02 14:15:21.895505 | controller | changed: .d..t...... ./ 2025-10-02 14:15:22.372167 | controller | changed: .d..t...... ./ 2025-10-02 14:15:22.386206 | 2025-10-02 14:15:22.386333 | TASK [include_role : fetch-output-openshift] 2025-10-02 14:15:22.421109 | controller | skipping: Conditional result was False 2025-10-02 14:15:22.428105 | 2025-10-02 14:15:22.428185 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 14:15:22.899279 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007392 2025-10-02 14:15:23.144358 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008588 2025-10-02 14:15:23.191336 | 2025-10-02 14:15:23.191550 | PLAY [all] 2025-10-02 14:15:23.223045 | 2025-10-02 14:15:23.223160 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 14:15:23.695688 | controller | changed 2025-10-02 14:15:23.732092 | 2025-10-02 14:15:23.732213 | PLAY RECAP 2025-10-02 14:15:23.732268 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 14:15:23.732297 | 2025-10-02 14:15:23.891433 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 14:15:23.892300 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 14:15:24.671839 | 2025-10-02 14:15:24.671983 | PLAY [localhost] 2025-10-02 14:15:24.692166 | 2025-10-02 14:15:24.692329 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 14:15:25.176033 | localhost | changed 2025-10-02 14:15:25.184408 | 2025-10-02 14:15:25.184542 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 14:15:25.213716 | localhost | ok 2025-10-02 14:15:25.226953 | 2025-10-02 14:15:25.231144 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 14:15:25.617843 | localhost | changed 2025-10-02 14:15:25.631318 | 2025-10-02 14:15:25.631466 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 14:15:26.333482 | localhost | changed 2025-10-02 14:15:26.349641 | 2025-10-02 14:15:26.349764 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 14:15:26.806675 | localhost | Identity added: /var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/tmp/ansible.7ma6s341 (/var/lib/zuul/builds/dbbf35ce479b4a07b86710e30f058114/work/tmp/ansible.7ma6s341) 2025-10-02 14:15:26.806942 | localhost | ok: Runtime: 0:00:00.008995 2025-10-02 14:15:26.816416 | 2025-10-02 14:15:26.816544 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 14:15:27.164551 | localhost | ok: Runtime: 0:00:00.014649 2025-10-02 14:15:27.176773 | 2025-10-02 14:15:27.176957 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 14:15:27.250831 | localhost | changed 2025-10-02 14:15:27.257080 | 2025-10-02 14:15:27.257216 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 14:15:27.708592 | localhost | changed 2025-10-02 14:15:27.732620 | 2025-10-02 14:15:27.732760 | PLAY [localhost] 2025-10-02 14:15:27.747901 | 2025-10-02 14:15:27.748031 | TASK [Generate bulk log download script] 2025-10-02 14:15:27.766903 | localhost | ok 2025-10-02 14:15:27.781888 | 2025-10-02 14:15:27.781990 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 14:15:27.821998 | localhost | ok: All assertions passed 2025-10-02 14:15:27.827073 | 2025-10-02 14:15:27.827154 | TASK [local-log-download : Create download script] 2025-10-02 14:15:28.331394 | localhost -> localhost | changed 2025-10-02 14:15:28.341716 | 2025-10-02 14:15:28.341821 | TASK [Register quick-download link] 2025-10-02 14:15:28.370733 | localhost | ok 2025-10-02 14:15:28.419260 | 2025-10-02 14:15:28.419429 | PLAY [logserver.rdoproject.org] 2025-10-02 14:15:28.439619 | 2025-10-02 14:15:28.439737 | TASK [Set zuul-log-path fact] 2025-10-02 14:15:28.456165 | logserver.rdoproject.org | ok 2025-10-02 14:15:28.465864 | 2025-10-02 14:15:28.465939 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 14:15:28.493248 | logserver.rdoproject.org | ok 2025-10-02 14:15:28.499383 | 2025-10-02 14:15:28.499469 | TASK [upload-logs : Create log directories] 2025-10-02 14:15:29.168078 | logserver.rdoproject.org | changed 2025-10-02 14:15:29.173412 | 2025-10-02 14:15:29.173545 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 14:15:29.535322 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005418 2025-10-02 14:15:29.544388 | 2025-10-02 14:15:29.544511 | TASK [upload-logs : Upload logs to log server] 2025-10-02 14:15:30.224618 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 14:15:30.227499 | 2025-10-02 14:15:30.227570 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 14:15:30.269958 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:30.278767 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:30.284702 | 2025-10-02 14:15:30.284809 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 14:15:30.323915 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:30.324193 | 2025-10-02 14:15:30.327626 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 14:15:30.333481 | 2025-10-02 14:15:30.333585 | LOOP [upload-logs : Upload console log and json output]