2025-12-01 08:18:28.048391 | Job console starting... 2025-12-01 08:18:28.060845 | Updating repositories 2025-12-01 08:18:28.082861 | Preparing job workspace 2025-12-01 08:18:32.183711 | Running Ansible setup... 2025-12-01 08:18:35.892841 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-01 08:18:36.558771 | 2025-12-01 08:18:36.558979 | PLAY [localhost] 2025-12-01 08:18:36.569065 | 2025-12-01 08:18:36.569221 | TASK [Gathering Facts] 2025-12-01 08:18:37.652444 | localhost | ok 2025-12-01 08:18:37.687639 | 2025-12-01 08:18:37.687863 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-01 08:18:38.085351 | localhost -> localhost | changed 2025-12-01 08:18:38.097762 | 2025-12-01 08:18:38.097964 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-01 08:18:38.991611 | localhost -> localhost | changed 2025-12-01 08:18:39.004588 | 2025-12-01 08:18:39.004723 | TASK [Setup log path fact] 2025-12-01 08:18:39.026401 | localhost | ok 2025-12-01 08:18:39.044270 | 2025-12-01 08:18:39.044423 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 08:18:39.075211 | localhost | ok 2025-12-01 08:18:39.086842 | 2025-12-01 08:18:39.086938 | TASK [emit-job-header : Print job information] 2025-12-01 08:18:39.131896 | # Job Information 2025-12-01 08:18:39.132188 | Ansible Version: 2.15.12 2025-12-01 08:18:39.132246 | Job: cifmw-molecule-cifmw_setup 2025-12-01 08:18:39.132290 | Pipeline: github-check 2025-12-01 08:18:39.132331 | Executor: ze01.softwarefactory-project.io 2025-12-01 08:18:39.132371 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3505 2025-12-01 08:18:39.132415 | Log URL (when completed): https://logserver.rdoproject.org/cea/rdoproject.org/cea3ed2df1b7421b94d15a299cd37656/ 2025-12-01 08:18:39.132456 | Event ID: 2cb40ac0-ce8e-11f0-9e93-bda27212598c 2025-12-01 08:18:39.140393 | 2025-12-01 08:18:39.140546 | LOOP [emit-job-header : Print node information] 2025-12-01 08:18:39.257518 | localhost | ok: 2025-12-01 08:18:39.257796 | localhost | # Node Information 2025-12-01 08:18:39.257852 | localhost | Inventory Hostname: controller 2025-12-01 08:18:39.257902 | localhost | Hostname: np0005540712 2025-12-01 08:18:39.257944 | localhost | Username: zuul 2025-12-01 08:18:39.257989 | localhost | Distro: CentOS 9 2025-12-01 08:18:39.258076 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-01 08:18:39.258124 | localhost | Region: RegionOne 2025-12-01 08:18:39.258163 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-01 08:18:39.258199 | localhost | Product Name: OpenStack Nova 2025-12-01 08:18:39.258235 | localhost | Interface IP: 38.102.83.158 2025-12-01 08:18:39.284124 | 2025-12-01 08:18:39.284245 | PLAY [all] 2025-12-01 08:18:39.291634 | 2025-12-01 08:18:39.291762 | TASK [Gather network facts] 2025-12-01 08:18:39.799689 | controller | ok 2025-12-01 08:18:39.818122 | 2025-12-01 08:18:39.818246 | TASK [include_role : start-zuul-console] 2025-12-01 08:18:39.836941 | controller | ok 2025-12-01 08:18:39.848513 | 2025-12-01 08:18:39.848622 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-01 08:18:40.301483 | controller | ok 2025-12-01 08:18:40.310134 | 2025-12-01 08:18:40.310214 | TASK [include_role : add-build-sshkey] 2025-12-01 08:18:40.340160 | controller | ok 2025-12-01 08:18:40.359439 | 2025-12-01 08:18:40.359603 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-01 08:18:40.633228 | controller -> localhost | ok 2025-12-01 08:18:40.639238 | 2025-12-01 08:18:40.639303 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-01 08:18:40.665994 | controller | ok 2025-12-01 08:18:40.692294 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-01 08:18:40.700423 | 2025-12-01 08:18:40.700508 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-01 08:18:41.304825 | controller -> localhost | Generating public/private rsa key pair. 2025-12-01 08:18:41.305076 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/cea3ed2df1b7421b94d15a299cd37656_id_rsa. 2025-12-01 08:18:41.305111 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/cea3ed2df1b7421b94d15a299cd37656_id_rsa.pub. 2025-12-01 08:18:41.305133 | controller -> localhost | The key fingerprint is: 2025-12-01 08:18:41.305153 | controller -> localhost | SHA256:8aBPyMrIvOgKDgWyxi+PosHjDzey+wUAHWazDzdQKAU zuul-build-sshkey 2025-12-01 08:18:41.305173 | controller -> localhost | The key's randomart image is: 2025-12-01 08:18:41.305192 | controller -> localhost | +---[RSA 3072]----+ 2025-12-01 08:18:41.305211 | controller -> localhost | |E+B+. | 2025-12-01 08:18:41.305248 | controller -> localhost | |ooo+ | 2025-12-01 08:18:41.305286 | controller -> localhost | |ooo o o | 2025-12-01 08:18:41.305312 | controller -> localhost | |oo.+ o o + | 2025-12-01 08:18:41.305335 | controller -> localhost | |.o... + S . | 2025-12-01 08:18:41.305356 | controller -> localhost | |o+.o.. o | 2025-12-01 08:18:41.305376 | controller -> localhost | |+*++o. . | 2025-12-01 08:18:41.305399 | controller -> localhost | |*oX.o | 2025-12-01 08:18:41.305420 | controller -> localhost | |OB=+ | 2025-12-01 08:18:41.305441 | controller -> localhost | +----[SHA256]-----+ 2025-12-01 08:18:41.305506 | controller -> localhost | ok: Runtime: 0:00:00.163594 2025-12-01 08:18:41.311377 | 2025-12-01 08:18:41.311443 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-01 08:18:41.332452 | controller | ok 2025-12-01 08:18:41.346468 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-01 08:18:41.358406 | 2025-12-01 08:18:41.358531 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-01 08:18:41.373066 | controller | skipping: Conditional result was False 2025-12-01 08:18:41.381610 | 2025-12-01 08:18:41.381730 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-01 08:18:41.868556 | controller | changed 2025-12-01 08:18:41.874048 | 2025-12-01 08:18:41.874144 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-01 08:18:42.121973 | controller | ok 2025-12-01 08:18:42.129914 | 2025-12-01 08:18:42.130056 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-01 08:18:43.046291 | controller | changed 2025-12-01 08:18:43.051437 | 2025-12-01 08:18:43.051510 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-01 08:18:43.936994 | controller | changed 2025-12-01 08:18:43.949226 | 2025-12-01 08:18:43.949430 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-01 08:18:43.976671 | controller | skipping: Conditional result was False 2025-12-01 08:18:43.983867 | 2025-12-01 08:18:43.984056 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-01 08:18:44.408769 | controller -> localhost | changed 2025-12-01 08:18:44.419903 | 2025-12-01 08:18:44.420054 | TASK [add-build-sshkey : Add back temp key] 2025-12-01 08:18:44.730781 | controller -> localhost | Identity added: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/cea3ed2df1b7421b94d15a299cd37656_id_rsa (zuul-build-sshkey) 2025-12-01 08:18:44.731031 | controller -> localhost | ok: Runtime: 0:00:00.016297 2025-12-01 08:18:44.737258 | 2025-12-01 08:18:44.737354 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-01 08:18:45.122670 | controller | ok 2025-12-01 08:18:45.136429 | 2025-12-01 08:18:45.136607 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-01 08:18:45.173732 | controller | skipping: Conditional result was False 2025-12-01 08:18:45.197647 | 2025-12-01 08:18:45.197856 | TASK [include_role : validate-host] 2025-12-01 08:18:45.228206 | controller | ok 2025-12-01 08:18:45.258831 | 2025-12-01 08:18:45.258981 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-01 08:18:45.290067 | controller | ok 2025-12-01 08:18:45.296916 | 2025-12-01 08:18:45.297019 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-01 08:18:45.517834 | controller -> localhost | ok 2025-12-01 08:18:45.524106 | 2025-12-01 08:18:45.524186 | TASK [validate-host : Collect information about the host] 2025-12-01 08:18:46.372515 | controller | ok 2025-12-01 08:18:46.386254 | 2025-12-01 08:18:46.386389 | TASK [validate-host : Sanitize hostname] 2025-12-01 08:18:46.438405 | controller | ok 2025-12-01 08:18:46.445807 | 2025-12-01 08:18:46.445950 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-01 08:18:46.932852 | controller -> localhost | changed 2025-12-01 08:18:46.938226 | 2025-12-01 08:18:46.938290 | TASK [validate-host : Collect information about zuul worker] 2025-12-01 08:18:47.371416 | controller | ok 2025-12-01 08:18:47.378789 | 2025-12-01 08:18:47.378898 | TASK [validate-host : Write out all zuul information for each host] 2025-12-01 08:18:47.876702 | controller -> localhost | changed 2025-12-01 08:18:47.890555 | 2025-12-01 08:18:47.890701 | TASK [include_role : prepare-workspace-openshift] 2025-12-01 08:18:47.915849 | controller | skipping: Conditional result was False 2025-12-01 08:18:47.921447 | 2025-12-01 08:18:47.921538 | TASK [include_role : remove-zuul-sshkey] 2025-12-01 08:18:47.934786 | controller | skipping: Conditional result was False 2025-12-01 08:18:47.940899 | 2025-12-01 08:18:47.941007 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-01 08:18:48.181413 | controller | ok: "logs" 2025-12-01 08:18:48.182118 | controller | ok: All items complete 2025-12-01 08:18:48.182208 | 2025-12-01 08:18:48.381744 | controller | ok: "artifacts" 2025-12-01 08:18:48.607058 | controller | ok: "docs" 2025-12-01 08:18:48.622322 | 2025-12-01 08:18:48.622473 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-01 08:18:48.887385 | controller | changed: "logs" 2025-12-01 08:18:49.111420 | controller | changed: "artifacts" 2025-12-01 08:18:49.350076 | controller | changed: "docs" 2025-12-01 08:18:49.385580 | 2025-12-01 08:18:49.385721 | PLAY RECAP 2025-12-01 08:18:49.385771 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-01 08:18:49.385800 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-01 08:18:49.385821 | 2025-12-01 08:18:49.503341 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-01 08:18:49.504210 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-01 08:18:50.137920 | 2025-12-01 08:18:50.138054 | PLAY [localhost] 2025-12-01 08:18:50.154359 | 2025-12-01 08:18:50.154458 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-01 08:18:50.591942 | localhost | ok 2025-12-01 08:18:50.597474 | 2025-12-01 08:18:50.597614 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-01 08:18:51.352189 | localhost | changed 2025-12-01 08:18:51.392280 | 2025-12-01 08:18:51.392473 | PLAY [all] 2025-12-01 08:18:51.418466 | 2025-12-01 08:18:51.418620 | TASK [include_role : prepare-workspace] 2025-12-01 08:18:51.449986 | controller | ok 2025-12-01 08:18:51.480928 | 2025-12-01 08:18:51.481078 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-01 08:18:51.923213 | controller | ok 2025-12-01 08:18:51.930757 | 2025-12-01 08:18:51.930874 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-01 08:18:53.712252 | controller | Output suppressed because no_log was given 2025-12-01 08:18:53.725479 | 2025-12-01 08:18:53.725597 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-01 08:18:53.961479 | controller | changed: "logs" 2025-12-01 08:18:54.185697 | controller | changed: "artifacts" 2025-12-01 08:18:54.399982 | controller | changed: "docs" 2025-12-01 08:18:54.418585 | 2025-12-01 08:18:54.418701 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-01 08:18:54.740489 | controller | changed: "logs" 2025-12-01 08:18:54.740725 | controller | changed: All items complete 2025-12-01 08:18:54.740757 | 2025-12-01 08:18:54.966716 | controller | changed: "artifacts" 2025-12-01 08:18:55.248585 | controller | changed: "docs" 2025-12-01 08:18:55.281123 | 2025-12-01 08:18:55.281321 | TASK [Check if worker can sudo] 2025-12-01 08:18:55.827618 | controller | ok: Runtime: 0:00:00.034797 2025-12-01 08:18:55.843715 | 2025-12-01 08:18:55.843921 | TASK [configure-mirrors : Gather needed facts] 2025-12-01 08:18:55.932570 | controller | skipping: Conditional result was False 2025-12-01 08:18:55.938627 | 2025-12-01 08:18:55.938753 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-01 08:18:56.009149 | controller | ok 2025-12-01 08:18:56.016695 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-01 08:18:56.022853 | 2025-12-01 08:18:56.022912 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-01 08:18:56.381778 | controller | ok 2025-12-01 08:18:56.387210 | 2025-12-01 08:18:56.387272 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-01 08:18:56.445812 | controller | ok: "/var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-01 08:18:56.460518 | 2025-12-01 08:18:56.460645 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-01 08:18:57.387335 | controller | changed 2025-12-01 08:18:57.392991 | 2025-12-01 08:18:57.393077 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-01 08:18:57.444079 | controller | ok: "/var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-01 08:18:57.444279 | controller | ok: All items complete 2025-12-01 08:18:57.444309 | 2025-12-01 08:18:57.500670 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-01 08:18:57.509173 | 2025-12-01 08:18:57.509306 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-01 08:18:58.416425 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-01 08:18:59.179269 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-01 08:18:59.190882 | 2025-12-01 08:18:59.191008 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-01 08:18:59.666286 | controller | changed: section and option added 2025-12-01 08:18:59.695726 | 2025-12-01 08:18:59.695850 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-01 08:19:00.328812 | controller | 29 files removed 2025-12-01 08:19:00.329542 | controller | ok: Item: dnf clean all Runtime: 0:00:00.304209 2025-12-01 08:19:00.329668 | controller | changed: All items complete 2025-12-01 08:19:00.329737 | 2025-12-01 08:19:10.735481 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-01 08:19:10.735602 | controller | DNF version: 4.14.0 2025-12-01 08:19:10.735629 | controller | cachedir: /var/cache/dnf 2025-12-01 08:19:10.735649 | controller | Making cache files for all metadata files. 2025-12-01 08:19:10.735669 | controller | baseos: has expired and will be refreshed. 2025-12-01 08:19:10.735686 | controller | appstream: has expired and will be refreshed. 2025-12-01 08:19:10.735702 | controller | crb: has expired and will be refreshed. 2025-12-01 08:19:10.735729 | controller | extras-common: has expired and will be refreshed. 2025-12-01 08:19:10.735747 | controller | repo: downloading from remote: baseos 2025-12-01 08:19:10.735765 | controller | CentOS Stream 9 - BaseOS 59 MB/s | 8.8 MB 00:00 2025-12-01 08:19:10.735782 | controller | baseos: using metadata from Mon 24 Nov 2025 12:32:03 PM EST. 2025-12-01 08:19:10.735798 | controller | repo: downloading from remote: appstream 2025-12-01 08:19:10.735815 | controller | CentOS Stream 9 - AppStream 104 MB/s | 25 MB 00:00 2025-12-01 08:19:10.735833 | controller | appstream: using metadata from Mon 24 Nov 2025 12:35:27 PM EST. 2025-12-01 08:19:10.735853 | controller | repo: downloading from remote: crb 2025-12-01 08:19:10.735873 | controller | CentOS Stream 9 - CRB 76 MB/s | 7.3 MB 00:00 2025-12-01 08:19:10.735913 | controller | crb: using metadata from Mon 24 Nov 2025 12:39:46 PM EST. 2025-12-01 08:19:10.735947 | controller | repo: downloading from remote: extras-common 2025-12-01 08:19:10.735971 | controller | CentOS Stream 9 - Extras packages 651 kB/s | 20 kB 00:00 2025-12-01 08:19:10.735989 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-01 08:19:10.736005 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-01 08:19:10.736025 | controller | Completion plugin: Generating completion cache... 2025-12-01 08:19:10.736113 | controller | Metadata cache created. 2025-12-01 08:19:10.736148 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.153448 2025-12-01 08:19:10.750395 | 2025-12-01 08:19:10.750489 | PLAY RECAP 2025-12-01 08:19:10.750532 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-01 08:19:10.750559 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-01 08:19:10.750577 | 2025-12-01 08:19:10.855302 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-01 08:19:10.856528 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 08:19:11.461113 | 2025-12-01 08:19:11.461240 | PLAY [all] 2025-12-01 08:19:11.483065 | 2025-12-01 08:19:11.483181 | TASK [Install binary dependencies] 2025-12-01 08:19:11.553267 | controller | ok 2025-12-01 08:19:11.572623 | 2025-12-01 08:19:11.572739 | TASK [bindep : Include find tasks] 2025-12-01 08:19:11.602704 | controller | ok 2025-12-01 08:19:11.611287 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-01 08:19:11.617470 | 2025-12-01 08:19:11.617733 | TASK [bindep : Look for bindep.txt] 2025-12-01 08:19:12.015487 | controller | ok 2025-12-01 08:19:12.022303 | 2025-12-01 08:19:12.022391 | TASK [bindep : Define bindep_file fact] 2025-12-01 08:19:12.067137 | controller | ok 2025-12-01 08:19:12.075822 | 2025-12-01 08:19:12.075985 | TASK [bindep : Look for other-requirements.txt] 2025-12-01 08:19:12.101514 | controller | skipping: Conditional result was False 2025-12-01 08:19:12.110110 | 2025-12-01 08:19:12.110240 | TASK [bindep : Define bindep_file fact] 2025-12-01 08:19:12.145321 | controller | skipping: Conditional result was False 2025-12-01 08:19:12.153862 | 2025-12-01 08:19:12.153965 | TASK [bindep : Look for bindep fallback file] 2025-12-01 08:19:12.179268 | controller | skipping: Conditional result was False 2025-12-01 08:19:12.191767 | 2025-12-01 08:19:12.191938 | TASK [bindep : Define bindep_file fact] 2025-12-01 08:19:12.229401 | controller | skipping: Conditional result was False 2025-12-01 08:19:12.235192 | 2025-12-01 08:19:12.235299 | TASK [bindep : Include bindep tasks] 2025-12-01 08:19:12.264965 | controller | ok 2025-12-01 08:19:12.271439 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-01 08:19:12.279306 | 2025-12-01 08:19:12.279373 | TASK [bindep : Look for bindep command] 2025-12-01 08:19:12.303168 | controller | skipping: Conditional result was False 2025-12-01 08:19:12.310102 | 2025-12-01 08:19:12.310202 | TASK [bindep : Check for system bindep] 2025-12-01 08:19:12.843986 | controller | ok: Runtime: 0:00:00.007806 2025-12-01 08:19:12.857004 | 2025-12-01 08:19:12.857197 | TASK [bindep : Define bindep_command fact] 2025-12-01 08:19:12.894513 | controller | skipping: Conditional result was False 2025-12-01 08:19:12.900922 | 2025-12-01 08:19:12.901015 | TASK [bindep : Include install tasks] 2025-12-01 08:19:12.943948 | controller | ok 2025-12-01 08:19:12.955651 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-01 08:19:12.969837 | 2025-12-01 08:19:12.969960 | TASK [bindep : Create temp dir for bindep] 2025-12-01 08:19:13.357655 | controller | changed 2025-12-01 08:19:13.363329 | 2025-12-01 08:19:13.363403 | TASK [Ensure we have pip dependencies] 2025-12-01 08:19:13.382367 | controller | ok 2025-12-01 08:19:13.407530 | 2025-12-01 08:19:13.407650 | TASK [ensure-pip : Check if pip is installed] 2025-12-01 03:19:13.652347 | controller | /usr/bin/pip3 2025-12-01 03:19:13.672939 | controller | /usr/bin/python3: No module named wheel 2025-12-01 08:19:13.936939 | controller | ok: Runtime: 0:00:00.031872 2025-12-01 08:19:13.945696 | 2025-12-01 08:19:13.945837 | LOOP [ensure-pip : Install pip from packages] 2025-12-01 08:19:13.987457 | controller | ok: "/var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-01 08:19:14.002333 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-01 08:19:14.013819 | 2025-12-01 08:19:14.013901 | TASK [ensure-pip : Install Python 3 pip] 2025-12-01 08:19:15.628882 | controller | changed 2025-12-01 08:19:15.636781 | 2025-12-01 08:19:15.636877 | TASK [ensure-pip : Check for EPEL repository] 2025-12-01 08:19:15.683249 | controller | skipping: Conditional result was False 2025-12-01 08:19:15.691364 | 2025-12-01 08:19:15.691456 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-01 08:19:15.737532 | controller | skipping: Conditional result was False 2025-12-01 08:19:15.747191 | 2025-12-01 08:19:15.747307 | TASK [ensure-pip : Install Python 2 pip] 2025-12-01 08:19:15.792795 | controller | skipping: Conditional result was False 2025-12-01 08:19:15.806363 | 2025-12-01 08:19:15.806537 | TASK [ensure-pip : Ensure setuptools] 2025-12-01 08:19:15.823243 | controller | skipping: Conditional result was False 2025-12-01 08:19:15.836514 | 2025-12-01 08:19:15.836710 | TASK [ensure-pip : Check for ensurepip module] 2025-12-01 08:19:16.385307 | controller | skipping: Conditional result was False 2025-12-01 08:19:16.394128 | 2025-12-01 08:19:16.394284 | TASK [ensure-pip : Ensure python3-venv] 2025-12-01 08:19:16.410450 | controller | skipping: Conditional result was False 2025-12-01 08:19:16.420165 | 2025-12-01 08:19:16.420321 | TASK [ensure-pip : Install pip from source] 2025-12-01 08:19:16.435335 | controller | skipping: Conditional result was False 2025-12-01 08:19:16.444723 | 2025-12-01 08:19:16.444917 | TASK [ensure-pip : Probe for venv python full path] 2025-12-01 03:19:16.694673 | controller | /usr/bin/python3 2025-12-01 08:19:16.988471 | controller | ok: Runtime: 0:00:00.007736 2025-12-01 08:19:16.997078 | 2025-12-01 08:19:16.997221 | TASK [ensure-pip : Set host default] 2025-12-01 08:19:17.077576 | controller | ok 2025-12-01 08:19:17.089344 | 2025-12-01 08:19:17.089525 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-01 08:19:17.150833 | controller | ok 2025-12-01 08:19:17.173620 | 2025-12-01 08:19:17.173845 | TASK [bindep : Install bindep into temporary venv] 2025-12-01 08:19:21.503349 | controller | changed 2025-12-01 08:19:21.511693 | 2025-12-01 08:19:21.511833 | TASK [bindep : Define bindep_command] 2025-12-01 08:19:21.544000 | controller | ok 2025-12-01 08:19:21.551560 | 2025-12-01 08:19:21.551707 | LOOP [bindep : Include package tasks] 2025-12-01 08:19:21.610515 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-01 08:19:21.610690 | controller | ok: All items complete 2025-12-01 08:19:21.610715 | 2025-12-01 08:19:21.643468 | controller | included: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-01 08:19:21.669857 | 2025-12-01 08:19:21.670049 | TASK [bindep : Define bindep_run fact] 2025-12-01 08:19:21.702875 | controller | ok 2025-12-01 08:19:21.709562 | 2025-12-01 08:19:21.709652 | TASK [bindep : Get list of packages to install from bindep] 2025-12-01 03:19:22.935669 | controller | podman 2025-12-01 03:19:22.965944 | controller | python3-jmespath 2025-12-01 03:19:22.965993 | controller | python3-libvirt 2025-12-01 03:19:22.966000 | controller | python3-lxml 2025-12-01 03:19:22.966007 | controller | python3-netaddr 2025-12-01 08:19:23.250788 | controller | ok: Runtime: 0:00:01.013706 2025-12-01 08:19:23.264619 | 2025-12-01 08:19:23.264789 | TASK [bindep : Install distro packages from bindep] 2025-12-01 08:20:23.565298 | controller | changed 2025-12-01 08:20:23.572347 | 2025-12-01 08:20:23.572434 | TASK [bindep : Check that packages are installed] 2025-12-01 08:20:25.101849 | controller | ok: Runtime: 0:00:01.051206 2025-12-01 08:20:25.115842 | 2025-12-01 08:20:25.116118 | TASK [bindep : Fail if we cannot install all packages] 2025-12-01 08:20:25.143307 | controller | skipping: Conditional result was False 2025-12-01 08:20:25.204349 | 2025-12-01 08:20:25.204526 | TASK [Run test-setup role] 2025-12-01 08:20:25.237878 | controller | ok 2025-12-01 08:20:25.268742 | 2025-12-01 08:20:25.268896 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-01 08:20:25.486739 | controller | ok 2025-12-01 08:20:25.496160 | 2025-12-01 08:20:25.496327 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-01 08:20:26.037344 | controller | skipping: Conditional result was False 2025-12-01 08:20:26.067738 | 2025-12-01 08:20:26.067884 | TASK [bindep : Remove bindep temp dir] 2025-12-01 08:20:26.419766 | controller | ok 2025-12-01 08:20:26.440733 | 2025-12-01 08:20:26.440887 | PLAY RECAP 2025-12-01 08:20:26.440963 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-01 08:20:26.441001 | 2025-12-01 08:20:26.563173 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-01 08:20:26.565324 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-01 08:20:27.189665 | 2025-12-01 08:20:27.189785 | PLAY [all] 2025-12-01 08:20:27.209754 | 2025-12-01 08:20:27.209885 | TASK [Abort when test_command variable is undefined] 2025-12-01 08:20:27.254792 | controller | skipping: Conditional result was False 2025-12-01 08:20:27.260659 | 2025-12-01 08:20:27.260742 | TASK [Convert test_command to list] 2025-12-01 08:20:27.317134 | controller | skipping: Conditional result was False 2025-12-01 08:20:27.323987 | 2025-12-01 08:20:27.324094 | TASK [Use test_command list] 2025-12-01 08:20:27.398376 | controller | ok 2025-12-01 08:20:27.406158 | 2025-12-01 08:20:27.406278 | LOOP [Run test_command] 2025-12-01 08:20:27.786537 | controller | no check to run 2025-12-01 08:20:27.786811 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004416 2025-12-01 08:20:27.817543 | 2025-12-01 08:20:27.817671 | PLAY RECAP 2025-12-01 08:20:27.817717 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-01 08:20:27.817738 | 2025-12-01 08:20:27.950230 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-01 08:20:27.951421 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 08:20:28.563129 | 2025-12-01 08:20:28.563265 | PLAY [all] 2025-12-01 08:20:28.590576 | 2025-12-01 08:20:28.590719 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-01 08:20:28.894306 | controller | changed: non-zero return code 2025-12-01 08:20:28.907271 | 2025-12-01 08:20:28.907450 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-01 08:20:28.925324 | controller | skipping: Conditional result was False 2025-12-01 08:20:28.939199 | 2025-12-01 08:20:28.939366 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-01 08:20:28.971427 | 2025-12-01 08:20:28.971713 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-01 08:20:29.008596 | 2025-12-01 08:20:29.008836 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-01 08:20:29.024139 | controller | skipping: Conditional result was False 2025-12-01 08:20:29.033638 | 2025-12-01 08:20:29.033747 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-01 08:20:29.065948 | 2025-12-01 08:20:29.066182 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-01 08:20:29.090908 | controller | skipping: Conditional result was False 2025-12-01 08:20:29.100209 | 2025-12-01 08:20:29.100315 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-01 08:20:29.114988 | controller | skipping: Conditional result was False 2025-12-01 08:20:29.124359 | 2025-12-01 08:20:29.124465 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-01 08:20:29.138682 | controller | skipping: Conditional result was False 2025-12-01 08:20:29.171462 | 2025-12-01 08:20:29.171607 | PLAY RECAP 2025-12-01 08:20:29.171677 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-01 08:20:29.171707 | 2025-12-01 08:20:29.280121 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-01 08:20:29.281268 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-01 08:20:29.876711 | 2025-12-01 08:20:29.876854 | PLAY [all] 2025-12-01 08:20:29.898137 | 2025-12-01 08:20:29.898299 | TASK [include_role : fetch-output] 2025-12-01 08:20:29.939715 | controller | ok 2025-12-01 08:20:29.959096 | 2025-12-01 08:20:29.959246 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-01 08:20:30.035091 | controller | skipping: Conditional result was False 2025-12-01 08:20:30.041293 | 2025-12-01 08:20:30.041393 | TASK [fetch-output : Set log path for single node] 2025-12-01 08:20:30.072557 | controller | ok 2025-12-01 08:20:30.077944 | 2025-12-01 08:20:30.078055 | LOOP [fetch-output : Ensure local output dirs] 2025-12-01 08:20:30.503101 | controller -> localhost | ok: "/var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/logs" 2025-12-01 08:20:30.752603 | controller -> localhost | changed: "/var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/artifacts" 2025-12-01 08:20:30.974651 | controller -> localhost | changed: "/var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/docs" 2025-12-01 08:20:30.985697 | 2025-12-01 08:20:30.985828 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-01 08:20:31.651093 | controller | changed: .d..t...... ./ 2025-12-01 08:20:31.651436 | controller | changed: All items complete 2025-12-01 08:20:31.651496 | 2025-12-01 08:20:32.109979 | controller | changed: .d..t...... ./ 2025-12-01 08:20:32.563903 | controller | changed: .d..t...... ./ 2025-12-01 08:20:32.587353 | 2025-12-01 08:20:32.587530 | TASK [include_role : fetch-output-openshift] 2025-12-01 08:20:32.611991 | controller | skipping: Conditional result was False 2025-12-01 08:20:32.619957 | 2025-12-01 08:20:32.620099 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-01 08:20:33.076573 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007321 2025-12-01 08:20:33.324538 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008860 2025-12-01 08:20:33.376134 | 2025-12-01 08:20:33.376255 | PLAY [all] 2025-12-01 08:20:33.397707 | 2025-12-01 08:20:33.397869 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-01 08:20:33.849128 | controller | changed 2025-12-01 08:20:33.882252 | 2025-12-01 08:20:33.882372 | PLAY RECAP 2025-12-01 08:20:33.882427 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-01 08:20:33.882456 | 2025-12-01 08:20:33.982932 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-01 08:20:33.984051 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-01 08:20:34.647105 | 2025-12-01 08:20:34.647265 | PLAY [localhost] 2025-12-01 08:20:34.666849 | 2025-12-01 08:20:34.666976 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-01 08:20:35.072902 | localhost | changed 2025-12-01 08:20:35.077647 | 2025-12-01 08:20:35.077737 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-01 08:20:35.112699 | localhost | ok 2025-12-01 08:20:35.120805 | 2025-12-01 08:20:35.120894 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-01 08:20:35.454531 | localhost | changed 2025-12-01 08:20:35.459391 | 2025-12-01 08:20:35.459464 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-01 08:20:36.109408 | localhost | changed 2025-12-01 08:20:36.115486 | 2025-12-01 08:20:36.115575 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-01 08:20:36.562680 | localhost | Identity added: /var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/tmp/ansible.lwgq0it9 (/var/lib/zuul/builds/cea3ed2df1b7421b94d15a299cd37656/work/tmp/ansible.lwgq0it9) 2025-12-01 08:20:36.562900 | localhost | ok: Runtime: 0:00:00.009425 2025-12-01 08:20:36.569518 | 2025-12-01 08:20:36.569610 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-01 08:20:36.822359 | localhost | ok: Runtime: 0:00:00.004182 2025-12-01 08:20:36.827091 | 2025-12-01 08:20:36.827156 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-01 08:20:36.881772 | localhost | changed 2025-12-01 08:20:36.891280 | 2025-12-01 08:20:36.891421 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-01 08:20:37.288471 | localhost | changed 2025-12-01 08:20:37.309105 | 2025-12-01 08:20:37.309195 | PLAY [localhost] 2025-12-01 08:20:37.320625 | 2025-12-01 08:20:37.320695 | TASK [Generate bulk log download script] 2025-12-01 08:20:37.339111 | localhost | ok 2025-12-01 08:20:37.350628 | 2025-12-01 08:20:37.350714 | TASK [local-log-download : Check API endpoint is defined] 2025-12-01 08:20:37.378718 | localhost | ok: All assertions passed 2025-12-01 08:20:37.383532 | 2025-12-01 08:20:37.383598 | TASK [local-log-download : Create download script] 2025-12-01 08:20:37.866466 | localhost -> localhost | changed 2025-12-01 08:20:37.885269 | 2025-12-01 08:20:37.885403 | TASK [Register quick-download link] 2025-12-01 08:20:37.919956 | localhost | ok 2025-12-01 08:20:37.978156 | 2025-12-01 08:20:37.978270 | PLAY [logserver.rdoproject.org] 2025-12-01 08:20:37.991991 | 2025-12-01 08:20:37.992099 | TASK [Set zuul-log-path fact] 2025-12-01 08:20:38.010979 | logserver.rdoproject.org | ok 2025-12-01 08:20:38.024207 | 2025-12-01 08:20:38.024309 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-01 08:20:38.062498 | logserver.rdoproject.org | ok 2025-12-01 08:20:38.070167 | 2025-12-01 08:20:38.070252 | TASK [upload-logs : Create log directories] 2025-12-01 08:20:39.003416 | logserver.rdoproject.org | changed 2025-12-01 08:20:39.010592 | 2025-12-01 08:20:39.010744 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-01 08:20:39.385140 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009028 2025-12-01 08:20:39.390888 | 2025-12-01 08:20:39.390970 | TASK [upload-logs : Upload logs to log server] 2025-12-01 08:20:40.052618 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-01 08:20:40.058930 | 2025-12-01 08:20:40.059101 | LOOP [upload-logs : Compress console log and json output] 2025-12-01 08:20:40.132842 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 08:20:40.145591 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 08:20:40.157073 | 2025-12-01 08:20:40.157318 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-01 08:20:40.208142 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 08:20:40.208593 | 2025-12-01 08:20:40.211674 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-01 08:20:40.222436 | 2025-12-01 08:20:40.222578 | LOOP [upload-logs : Upload console log and json output]