2025-10-13 06:53:37.551276 | Job console starting... 2025-10-13 06:53:37.577796 | Updating repositories 2025-10-13 06:53:37.623060 | Preparing job workspace 2025-10-13 06:53:41.594685 | Running Ansible setup... 2025-10-13 06:53:46.335930 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 06:53:47.334153 | 2025-10-13 06:53:47.334275 | PLAY [localhost] 2025-10-13 06:53:47.343484 | 2025-10-13 06:53:47.343560 | TASK [Gathering Facts] 2025-10-13 06:53:48.800244 | localhost | ok 2025-10-13 06:53:48.843605 | 2025-10-13 06:53:48.843795 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 06:53:49.489219 | localhost -> localhost | changed 2025-10-13 06:53:49.494684 | 2025-10-13 06:53:49.494784 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 06:53:50.694453 | localhost -> localhost | changed 2025-10-13 06:53:50.703875 | 2025-10-13 06:53:50.703955 | TASK [Setup log path fact] 2025-10-13 06:53:50.739191 | localhost | ok 2025-10-13 06:53:50.761425 | 2025-10-13 06:53:50.761521 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 06:53:50.814174 | localhost | ok 2025-10-13 06:53:50.832631 | 2025-10-13 06:53:50.832769 | TASK [emit-job-header : Print job information] 2025-10-13 06:53:50.912113 | # Job Information 2025-10-13 06:53:50.912238 | Ansible Version: 2.15.12 2025-10-13 06:53:50.912266 | Job: cifmw-molecule-federation 2025-10-13 06:53:50.912289 | Pipeline: github-check 2025-10-13 06:53:50.912308 | Executor: ze03.softwarefactory-project.io 2025-10-13 06:53:50.912326 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-13 06:53:50.912345 | Log URL (when completed): https://logserver.rdoproject.org/635/rdoproject.org/635e23f4a68d41228e5a4387362f3ac8/ 2025-10-13 06:53:50.912364 | Event ID: 0a621880-a801-11f0-8fd5-3020d4b2b2c2 2025-10-13 06:53:50.915883 | 2025-10-13 06:53:50.915947 | LOOP [emit-job-header : Print node information] 2025-10-13 06:53:51.064486 | localhost | ok: 2025-10-13 06:53:51.064664 | localhost | # Node Information 2025-10-13 06:53:51.064691 | localhost | Inventory Hostname: controller 2025-10-13 06:53:51.064713 | localhost | Hostname: np0005482613 2025-10-13 06:53:51.064732 | localhost | Username: zuul 2025-10-13 06:53:51.064816 | localhost | Distro: CentOS 9 2025-10-13 06:53:51.064837 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 06:53:51.064854 | localhost | Region: RegionOne 2025-10-13 06:53:51.064870 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 06:53:51.064885 | localhost | Product Name: OpenStack Nova 2025-10-13 06:53:51.064901 | localhost | Interface IP: 38.102.83.230 2025-10-13 06:53:51.091158 | 2025-10-13 06:53:51.091263 | PLAY [all] 2025-10-13 06:53:51.098071 | 2025-10-13 06:53:51.098159 | TASK [Gather network facts] 2025-10-13 06:53:51.602711 | controller | ok 2025-10-13 06:53:51.618616 | 2025-10-13 06:53:51.618708 | TASK [include_role : start-zuul-console] 2025-10-13 06:53:51.637679 | controller | ok 2025-10-13 06:53:51.649881 | 2025-10-13 06:53:51.649983 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 06:53:52.115037 | controller | ok 2025-10-13 06:53:52.139485 | 2025-10-13 06:53:52.139600 | TASK [include_role : add-build-sshkey] 2025-10-13 06:53:52.168853 | controller | ok 2025-10-13 06:53:52.185096 | 2025-10-13 06:53:52.185199 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 06:53:52.464678 | controller -> localhost | ok 2025-10-13 06:53:52.470291 | 2025-10-13 06:53:52.470362 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 06:53:52.509494 | controller | ok 2025-10-13 06:53:52.523959 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 06:53:52.530229 | 2025-10-13 06:53:52.530339 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 06:53:53.095106 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 06:53:53.095298 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/635e23f4a68d41228e5a4387362f3ac8_id_rsa. 2025-10-13 06:53:53.095329 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/635e23f4a68d41228e5a4387362f3ac8_id_rsa.pub. 2025-10-13 06:53:53.095350 | controller -> localhost | The key fingerprint is: 2025-10-13 06:53:53.095369 | controller -> localhost | SHA256:gBJFd1kp1+x107XPh72RdHJNX+rV0/xQb2pJKPHltzE zuul-build-sshkey 2025-10-13 06:53:53.095386 | controller -> localhost | The key's randomart image is: 2025-10-13 06:53:53.095404 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 06:53:53.095421 | controller -> localhost | | .oo . .oo+ . B| 2025-10-13 06:53:53.095439 | controller -> localhost | | . o .o ooo+.*@| 2025-10-13 06:53:53.095456 | controller -> localhost | | . . . o..o.*E#| 2025-10-13 06:53:53.095474 | controller -> localhost | | . . ..o.&X| 2025-10-13 06:53:53.095491 | controller -> localhost | | S *+*| 2025-10-13 06:53:53.095507 | controller -> localhost | | . +| 2025-10-13 06:53:53.095524 | controller -> localhost | | . | 2025-10-13 06:53:53.095541 | controller -> localhost | | | 2025-10-13 06:53:53.095557 | controller -> localhost | | | 2025-10-13 06:53:53.095574 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 06:53:53.095617 | controller -> localhost | ok: Runtime: 0:00:00.145007 2025-10-13 06:53:53.105371 | 2025-10-13 06:53:53.105479 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 06:53:53.144908 | controller | ok 2025-10-13 06:53:53.160336 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 06:53:53.169467 | 2025-10-13 06:53:53.169596 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 06:53:53.214998 | controller | skipping: Conditional result was False 2025-10-13 06:53:53.220313 | 2025-10-13 06:53:53.220380 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 06:53:53.819455 | controller | changed 2025-10-13 06:53:53.837747 | 2025-10-13 06:53:53.839557 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 06:53:54.156475 | controller | ok 2025-10-13 06:53:54.165099 | 2025-10-13 06:53:54.165205 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 06:53:55.195466 | controller | changed 2025-10-13 06:53:55.202119 | 2025-10-13 06:53:55.202199 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 06:53:56.184621 | controller | changed 2025-10-13 06:53:56.194258 | 2025-10-13 06:53:56.194395 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 06:53:56.244405 | controller | skipping: Conditional result was False 2025-10-13 06:53:56.256080 | 2025-10-13 06:53:56.256188 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 06:53:56.900159 | controller -> localhost | changed 2025-10-13 06:53:56.911848 | 2025-10-13 06:53:56.911966 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 06:53:57.406053 | controller -> localhost | Identity added: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/635e23f4a68d41228e5a4387362f3ac8_id_rsa (zuul-build-sshkey) 2025-10-13 06:53:57.406386 | controller -> localhost | ok: Runtime: 0:00:00.010942 2025-10-13 06:53:57.412293 | 2025-10-13 06:53:57.412390 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 06:53:57.854168 | controller | ok 2025-10-13 06:53:57.862633 | 2025-10-13 06:53:57.862810 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 06:53:57.922330 | controller | skipping: Conditional result was False 2025-10-13 06:53:57.941278 | 2025-10-13 06:53:57.941358 | TASK [include_role : validate-host] 2025-10-13 06:53:58.011068 | controller | ok 2025-10-13 06:53:58.134083 | 2025-10-13 06:53:58.134653 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 06:53:58.203882 | controller | ok 2025-10-13 06:53:58.209151 | 2025-10-13 06:53:58.209228 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 06:53:58.560202 | controller -> localhost | ok 2025-10-13 06:53:58.571197 | 2025-10-13 06:53:58.571320 | TASK [validate-host : Collect information about the host] 2025-10-13 06:53:59.378663 | controller | ok 2025-10-13 06:53:59.392006 | 2025-10-13 06:53:59.392112 | TASK [validate-host : Sanitize hostname] 2025-10-13 06:53:59.482407 | controller | ok 2025-10-13 06:53:59.488352 | 2025-10-13 06:53:59.488462 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 06:53:59.986068 | controller -> localhost | changed 2025-10-13 06:53:59.991752 | 2025-10-13 06:53:59.991812 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 06:54:00.431194 | controller | ok 2025-10-13 06:54:00.446101 | 2025-10-13 06:54:00.446188 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 06:54:01.032366 | controller -> localhost | changed 2025-10-13 06:54:01.045103 | 2025-10-13 06:54:01.045216 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 06:54:01.070948 | controller | skipping: Conditional result was False 2025-10-13 06:54:01.081176 | 2025-10-13 06:54:01.081240 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 06:54:01.105789 | controller | skipping: Conditional result was False 2025-10-13 06:54:01.113443 | 2025-10-13 06:54:01.113530 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 06:54:01.412685 | controller | ok: "logs" 2025-10-13 06:54:01.413059 | controller | ok: All items complete 2025-10-13 06:54:01.413111 | 2025-10-13 06:54:01.680057 | controller | ok: "artifacts" 2025-10-13 06:54:01.889980 | controller | ok: "docs" 2025-10-13 06:54:01.902949 | 2025-10-13 06:54:01.903087 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 06:54:02.219313 | controller | changed: "logs" 2025-10-13 06:54:02.451508 | controller | changed: "artifacts" 2025-10-13 06:54:02.671451 | controller | changed: "docs" 2025-10-13 06:54:02.707636 | 2025-10-13 06:54:02.707748 | PLAY RECAP 2025-10-13 06:54:02.707796 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 06:54:02.707823 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 06:54:02.707841 | 2025-10-13 06:54:02.824378 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 06:54:02.825217 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 06:54:03.557661 | 2025-10-13 06:54:03.557805 | PLAY [localhost] 2025-10-13 06:54:03.579776 | 2025-10-13 06:54:03.579878 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 06:54:03.988214 | localhost | ok 2025-10-13 06:54:04.001149 | 2025-10-13 06:54:04.001315 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 06:54:04.745546 | localhost | changed 2025-10-13 06:54:04.781574 | 2025-10-13 06:54:04.781683 | PLAY [all] 2025-10-13 06:54:04.798747 | 2025-10-13 06:54:04.798861 | TASK [include_role : prepare-workspace] 2025-10-13 06:54:04.841488 | controller | ok 2025-10-13 06:54:04.856351 | 2025-10-13 06:54:04.856450 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 06:54:05.268174 | controller | ok 2025-10-13 06:54:05.286343 | 2025-10-13 06:54:05.286457 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 06:54:07.082283 | controller | Output suppressed because no_log was given 2025-10-13 06:54:07.097426 | 2025-10-13 06:54:07.097527 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 06:54:07.377292 | controller | changed: "logs" 2025-10-13 06:54:07.602991 | controller | changed: "artifacts" 2025-10-13 06:54:07.857269 | controller | changed: "docs" 2025-10-13 06:54:07.873792 | 2025-10-13 06:54:07.873908 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 06:54:08.162473 | controller | changed: "logs" 2025-10-13 06:54:08.162859 | controller | changed: All items complete 2025-10-13 06:54:08.162918 | 2025-10-13 06:54:08.396964 | controller | changed: "artifacts" 2025-10-13 06:54:08.657515 | controller | changed: "docs" 2025-10-13 06:54:08.672235 | 2025-10-13 06:54:08.672351 | TASK [Check if worker can sudo] 2025-10-13 06:54:09.218825 | controller | ok: Runtime: 0:00:00.048987 2025-10-13 06:54:09.224076 | 2025-10-13 06:54:09.224143 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 06:54:09.298524 | controller | skipping: Conditional result was False 2025-10-13 06:54:09.305905 | 2025-10-13 06:54:09.305998 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 06:54:09.377716 | controller | ok 2025-10-13 06:54:09.389836 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 06:54:09.446940 | 2025-10-13 06:54:09.447081 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 06:54:09.748601 | controller | ok 2025-10-13 06:54:09.754335 | 2025-10-13 06:54:09.754411 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 06:54:09.878843 | controller | ok: "/var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 06:54:09.887207 | 2025-10-13 06:54:09.887308 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 06:54:10.707230 | controller | changed 2025-10-13 06:54:10.712521 | 2025-10-13 06:54:10.712584 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 06:54:10.783049 | controller | ok: "/var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 06:54:10.783289 | controller | ok: All items complete 2025-10-13 06:54:10.783316 | 2025-10-13 06:54:10.830695 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 06:54:10.845097 | 2025-10-13 06:54:10.845211 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 06:54:11.843259 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 06:54:12.565132 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 06:54:12.582092 | 2025-10-13 06:54:12.582174 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 06:54:13.095577 | controller | changed: section and option added 2025-10-13 06:54:13.146606 | 2025-10-13 06:54:13.146701 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 06:54:14.048520 | controller | 29 files removed 2025-10-13 06:54:14.048741 | controller | ok: Item: dnf clean all Runtime: 0:00:00.474578 2025-10-13 06:54:14.048785 | controller | changed: All items complete 2025-10-13 06:54:14.048806 | 2025-10-13 06:54:24.924263 | 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 06:54:24.924415 | controller | DNF version: 4.14.0 2025-10-13 06:54:24.924468 | controller | cachedir: /var/cache/dnf 2025-10-13 06:54:24.924514 | controller | Making cache files for all metadata files. 2025-10-13 06:54:24.924555 | controller | baseos: has expired and will be refreshed. 2025-10-13 06:54:24.924594 | controller | appstream: has expired and will be refreshed. 2025-10-13 06:54:24.924654 | controller | crb: has expired and will be refreshed. 2025-10-13 06:54:24.924711 | controller | extras-common: has expired and will be refreshed. 2025-10-13 06:54:24.924786 | controller | repo: downloading from remote: baseos 2025-10-13 06:54:24.924826 | controller | CentOS Stream 9 - BaseOS 86 MB/s | 8.8 MB 00:00 2025-10-13 06:54:24.924863 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 06:54:24.924899 | controller | repo: downloading from remote: appstream 2025-10-13 06:54:24.924935 | controller | CentOS Stream 9 - AppStream 122 MB/s | 25 MB 00:00 2025-10-13 06:54:24.924987 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 06:54:24.925033 | controller | repo: downloading from remote: crb 2025-10-13 06:54:24.925078 | controller | CentOS Stream 9 - CRB 84 MB/s | 7.2 MB 00:00 2025-10-13 06:54:24.925124 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 06:54:24.925169 | controller | repo: downloading from remote: extras-common 2025-10-13 06:54:24.925213 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-10-13 06:54:24.925256 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 06:54:24.925300 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 06:54:24.925344 | controller | Completion plugin: Generating completion cache... 2025-10-13 06:54:24.925388 | controller | Metadata cache created. 2025-10-13 06:54:24.925449 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.584525 2025-10-13 06:54:24.943618 | 2025-10-13 06:54:24.943760 | PLAY RECAP 2025-10-13 06:54:24.943823 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 06:54:24.943860 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 06:54:24.943885 | 2025-10-13 06:54:25.065214 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 06:54:25.066984 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 06:54:25.672253 | 2025-10-13 06:54:25.672371 | PLAY [all] 2025-10-13 06:54:25.693624 | 2025-10-13 06:54:25.693747 | TASK [Install binary dependencies] 2025-10-13 06:54:25.743711 | controller | ok 2025-10-13 06:54:25.764075 | 2025-10-13 06:54:25.764230 | TASK [bindep : Include find tasks] 2025-10-13 06:54:25.798523 | controller | ok 2025-10-13 06:54:25.806177 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 06:54:25.812300 | 2025-10-13 06:54:25.812367 | TASK [bindep : Look for bindep.txt] 2025-10-13 06:54:26.249277 | controller | ok 2025-10-13 06:54:26.255719 | 2025-10-13 06:54:26.255815 | TASK [bindep : Define bindep_file fact] 2025-10-13 06:54:26.285479 | controller | ok 2025-10-13 06:54:26.290884 | 2025-10-13 06:54:26.291018 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 06:54:26.315150 | controller | skipping: Conditional result was False 2025-10-13 06:54:26.321134 | 2025-10-13 06:54:26.321215 | TASK [bindep : Define bindep_file fact] 2025-10-13 06:54:26.345382 | controller | skipping: Conditional result was False 2025-10-13 06:54:26.351625 | 2025-10-13 06:54:26.351701 | TASK [bindep : Look for bindep fallback file] 2025-10-13 06:54:26.385813 | controller | skipping: Conditional result was False 2025-10-13 06:54:26.391990 | 2025-10-13 06:54:26.392066 | TASK [bindep : Define bindep_file fact] 2025-10-13 06:54:26.415755 | controller | skipping: Conditional result was False 2025-10-13 06:54:26.423038 | 2025-10-13 06:54:26.423111 | TASK [bindep : Include bindep tasks] 2025-10-13 06:54:26.468221 | controller | ok 2025-10-13 06:54:26.481213 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 06:54:26.489897 | 2025-10-13 06:54:26.489984 | TASK [bindep : Look for bindep command] 2025-10-13 06:54:26.524686 | controller | skipping: Conditional result was False 2025-10-13 06:54:26.531938 | 2025-10-13 06:54:26.532019 | TASK [bindep : Check for system bindep] 2025-10-13 06:54:27.066860 | controller | ok: Runtime: 0:00:00.004529 2025-10-13 06:54:27.075784 | 2025-10-13 06:54:27.076071 | TASK [bindep : Define bindep_command fact] 2025-10-13 06:54:27.101440 | controller | skipping: Conditional result was False 2025-10-13 06:54:27.108993 | 2025-10-13 06:54:27.109118 | TASK [bindep : Include install tasks] 2025-10-13 06:54:27.148785 | controller | ok 2025-10-13 06:54:27.165781 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 06:54:27.179179 | 2025-10-13 06:54:27.179298 | TASK [bindep : Create temp dir for bindep] 2025-10-13 06:54:27.566452 | controller | changed 2025-10-13 06:54:27.571778 | 2025-10-13 06:54:27.571844 | TASK [Ensure we have pip dependencies] 2025-10-13 06:54:27.592146 | controller | ok 2025-10-13 06:54:27.618289 | 2025-10-13 06:54:27.618403 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 02:54:27.936047 | controller | /usr/bin/pip3 2025-10-13 02:54:27.962550 | controller | /usr/bin/python3: No module named wheel 2025-10-13 06:54:28.149039 | controller | ok: Runtime: 0:00:00.036760 2025-10-13 06:54:28.156148 | 2025-10-13 06:54:28.156238 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 06:54:28.202470 | controller | ok: "/var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 06:54:28.211042 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 06:54:28.223061 | 2025-10-13 06:54:28.223216 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 06:54:30.498490 | controller | changed 2025-10-13 06:54:30.504348 | 2025-10-13 06:54:30.504448 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 06:54:30.559341 | controller | skipping: Conditional result was False 2025-10-13 06:54:30.574230 | 2025-10-13 06:54:30.574415 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 06:54:30.621748 | controller | skipping: Conditional result was False 2025-10-13 06:54:30.630448 | 2025-10-13 06:54:30.630576 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 06:54:30.670143 | controller | skipping: Conditional result was False 2025-10-13 06:54:30.680068 | 2025-10-13 06:54:30.680211 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 06:54:30.695283 | controller | skipping: Conditional result was False 2025-10-13 06:54:30.704026 | 2025-10-13 06:54:30.704154 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 06:54:31.243229 | controller | skipping: Conditional result was False 2025-10-13 06:54:31.254106 | 2025-10-13 06:54:31.254194 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 06:54:31.278009 | controller | skipping: Conditional result was False 2025-10-13 06:54:31.285123 | 2025-10-13 06:54:31.285216 | TASK [ensure-pip : Install pip from source] 2025-10-13 06:54:31.308604 | controller | skipping: Conditional result was False 2025-10-13 06:54:31.314908 | 2025-10-13 06:54:31.314985 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 02:54:31.602286 | controller | /usr/bin/python3 2025-10-13 06:54:31.846134 | controller | ok: Runtime: 0:00:00.008437 2025-10-13 06:54:31.859625 | 2025-10-13 06:54:31.859882 | TASK [ensure-pip : Set host default] 2025-10-13 06:54:31.939471 | controller | ok 2025-10-13 06:54:31.951184 | 2025-10-13 06:54:31.951335 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 06:54:32.012449 | controller | ok 2025-10-13 06:54:32.035633 | 2025-10-13 06:54:32.035788 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 06:54:36.277321 | controller | changed 2025-10-13 06:54:36.292681 | 2025-10-13 06:54:36.292868 | TASK [bindep : Define bindep_command] 2025-10-13 06:54:36.335828 | controller | ok 2025-10-13 06:54:36.342988 | 2025-10-13 06:54:36.343071 | LOOP [bindep : Include package tasks] 2025-10-13 06:54:36.426390 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 06:54:36.426713 | controller | ok: All items complete 2025-10-13 06:54:36.426810 | 2025-10-13 06:54:36.444526 | controller | included: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 06:54:36.458691 | 2025-10-13 06:54:36.458798 | TASK [bindep : Define bindep_run fact] 2025-10-13 06:54:36.490539 | controller | ok 2025-10-13 06:54:36.497491 | 2025-10-13 06:54:36.497577 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 02:54:37.879415 | controller | podman 2025-10-13 02:54:37.918342 | controller | python3-jmespath 2025-10-13 02:54:37.918446 | controller | python3-libvirt 2025-10-13 02:54:37.918456 | controller | python3-lxml 2025-10-13 02:54:37.918567 | controller | python3-netaddr 2025-10-13 06:54:38.039117 | controller | ok: Runtime: 0:00:01.130397 2025-10-13 06:54:38.053084 | 2025-10-13 06:54:38.053281 | TASK [bindep : Install distro packages from bindep] 2025-10-13 06:55:39.485485 | controller | changed 2025-10-13 06:55:39.501716 | 2025-10-13 06:55:39.501932 | TASK [bindep : Check that packages are installed] 2025-10-13 06:55:41.082028 | controller | ok: Runtime: 0:00:01.075355 2025-10-13 06:55:41.090621 | 2025-10-13 06:55:41.090718 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 06:55:41.116229 | controller | skipping: Conditional result was False 2025-10-13 06:55:41.132087 | 2025-10-13 06:55:41.132223 | TASK [Run test-setup role] 2025-10-13 06:55:41.156429 | controller | ok 2025-10-13 06:55:41.182362 | 2025-10-13 06:55:41.182501 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 06:55:41.418038 | controller | ok 2025-10-13 06:55:41.425994 | 2025-10-13 06:55:41.426109 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 06:55:41.968313 | controller | skipping: Conditional result was False 2025-10-13 06:55:41.991932 | 2025-10-13 06:55:41.992152 | TASK [bindep : Remove bindep temp dir] 2025-10-13 06:55:42.437398 | controller | ok 2025-10-13 06:55:42.454890 | 2025-10-13 06:55:42.454962 | PLAY RECAP 2025-10-13 06:55:42.455002 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 06:55:42.455023 | 2025-10-13 06:55:42.566284 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 06:55:42.567153 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 06:55:43.206359 | 2025-10-13 06:55:43.206474 | PLAY [all] 2025-10-13 06:55:43.234964 | 2025-10-13 06:55:43.235075 | TASK [Abort when test_command variable is undefined] 2025-10-13 06:55:43.303228 | controller | skipping: Conditional result was False 2025-10-13 06:55:43.309544 | 2025-10-13 06:55:43.309641 | TASK [Convert test_command to list] 2025-10-13 06:55:43.389042 | controller | skipping: Conditional result was False 2025-10-13 06:55:43.395959 | 2025-10-13 06:55:43.396067 | TASK [Use test_command list] 2025-10-13 06:55:43.493348 | controller | ok 2025-10-13 06:55:43.499261 | 2025-10-13 06:55:43.499384 | LOOP [Run test_command] 2025-10-13 06:55:43.901151 | controller | no check to run 2025-10-13 06:55:43.901314 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.005872 2025-10-13 06:55:43.948256 | 2025-10-13 06:55:43.948352 | PLAY RECAP 2025-10-13 06:55:43.948392 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 06:55:43.948413 | 2025-10-13 06:55:44.135421 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 06:55:44.136343 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 06:55:44.792437 | 2025-10-13 06:55:44.792573 | PLAY [all] 2025-10-13 06:55:44.812911 | 2025-10-13 06:55:44.812995 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 06:55:45.154567 | controller | changed: non-zero return code 2025-10-13 06:55:45.165080 | 2025-10-13 06:55:45.165249 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 06:55:45.191424 | controller | skipping: Conditional result was False 2025-10-13 06:55:45.197220 | 2025-10-13 06:55:45.197332 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 06:55:45.239405 | 2025-10-13 06:55:45.239556 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 06:55:45.276032 | 2025-10-13 06:55:45.276191 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 06:55:45.301160 | controller | skipping: Conditional result was False 2025-10-13 06:55:45.313808 | 2025-10-13 06:55:45.313925 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 06:55:45.343611 | 2025-10-13 06:55:45.343791 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 06:55:45.379430 | controller | skipping: Conditional result was False 2025-10-13 06:55:45.384862 | 2025-10-13 06:55:45.384930 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 06:55:45.409825 | controller | skipping: Conditional result was False 2025-10-13 06:55:45.415706 | 2025-10-13 06:55:45.415840 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 06:55:45.460206 | controller | skipping: Conditional result was False 2025-10-13 06:55:45.515301 | 2025-10-13 06:55:45.515412 | PLAY RECAP 2025-10-13 06:55:45.515457 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 06:55:45.515478 | 2025-10-13 06:55:45.659352 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 06:55:45.660153 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 06:55:46.301775 | 2025-10-13 06:55:46.301880 | PLAY [all] 2025-10-13 06:55:46.320242 | 2025-10-13 06:55:46.320316 | TASK [include_role : fetch-output] 2025-10-13 06:55:46.349148 | controller | ok 2025-10-13 06:55:46.366003 | 2025-10-13 06:55:46.366081 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 06:55:46.410486 | controller | skipping: Conditional result was False 2025-10-13 06:55:46.416169 | 2025-10-13 06:55:46.416236 | TASK [fetch-output : Set log path for single node] 2025-10-13 06:55:46.464981 | controller | ok 2025-10-13 06:55:46.470019 | 2025-10-13 06:55:46.470082 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 06:55:46.868229 | controller -> localhost | ok: "/var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/logs" 2025-10-13 06:55:47.076533 | controller -> localhost | changed: "/var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/artifacts" 2025-10-13 06:55:47.302003 | controller -> localhost | changed: "/var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/docs" 2025-10-13 06:55:47.318833 | 2025-10-13 06:55:47.318974 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 06:55:48.066885 | controller | changed: .d..t...... ./ 2025-10-13 06:55:48.067081 | controller | changed: All items complete 2025-10-13 06:55:48.067108 | 2025-10-13 06:55:48.596259 | controller | changed: .d..t...... ./ 2025-10-13 06:55:49.160939 | controller | changed: .d..t...... ./ 2025-10-13 06:55:49.175175 | 2025-10-13 06:55:49.175313 | TASK [include_role : fetch-output-openshift] 2025-10-13 06:55:49.200345 | controller | skipping: Conditional result was False 2025-10-13 06:55:49.213145 | 2025-10-13 06:55:49.213258 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 06:55:49.711508 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.016452 2025-10-13 06:55:49.962371 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.033294 2025-10-13 06:55:50.006917 | 2025-10-13 06:55:50.007020 | PLAY [all] 2025-10-13 06:55:50.021387 | 2025-10-13 06:55:50.021452 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 06:55:50.551437 | controller | changed 2025-10-13 06:55:50.578243 | 2025-10-13 06:55:50.578341 | PLAY RECAP 2025-10-13 06:55:50.578384 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 06:55:50.578405 | 2025-10-13 06:55:50.680133 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 06:55:50.680979 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 06:55:51.495050 | 2025-10-13 06:55:51.495158 | PLAY [localhost] 2025-10-13 06:55:51.522946 | 2025-10-13 06:55:51.523052 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 06:55:51.959596 | localhost | changed 2025-10-13 06:55:51.967354 | 2025-10-13 06:55:51.967545 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 06:55:51.997211 | localhost | ok 2025-10-13 06:55:52.006165 | 2025-10-13 06:55:52.006239 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 06:55:52.455057 | localhost | changed 2025-10-13 06:55:52.461335 | 2025-10-13 06:55:52.461434 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 06:55:53.573481 | localhost | changed 2025-10-13 06:55:53.578659 | 2025-10-13 06:55:53.578729 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 06:55:54.367717 | localhost | Identity added: /var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/tmp/ansible.jhknqhhh (/var/lib/zuul/builds/635e23f4a68d41228e5a4387362f3ac8/work/tmp/ansible.jhknqhhh) 2025-10-13 06:55:54.368075 | localhost | ok: Runtime: 0:00:00.025086 2025-10-13 06:55:54.372413 | 2025-10-13 06:55:54.372478 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 06:55:54.748294 | localhost | ok: Runtime: 0:00:00.018619 2025-10-13 06:55:54.762462 | 2025-10-13 06:55:54.762617 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 06:55:54.909507 | localhost | changed 2025-10-13 06:55:54.914183 | 2025-10-13 06:55:54.914248 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 06:55:55.606651 | localhost | changed 2025-10-13 06:55:55.656969 | 2025-10-13 06:55:55.657097 | PLAY [localhost] 2025-10-13 06:55:55.682159 | 2025-10-13 06:55:55.682251 | TASK [Generate bulk log download script] 2025-10-13 06:55:55.722442 | localhost | ok 2025-10-13 06:55:55.740340 | 2025-10-13 06:55:55.740430 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 06:55:55.775303 | localhost | ok: All assertions passed 2025-10-13 06:55:55.779937 | 2025-10-13 06:55:55.779999 | TASK [local-log-download : Create download script] 2025-10-13 06:55:56.451246 | localhost -> localhost | changed 2025-10-13 06:55:56.489607 | 2025-10-13 06:55:56.489719 | TASK [Register quick-download link] 2025-10-13 06:55:56.518913 | localhost | ok 2025-10-13 06:55:56.543149 | 2025-10-13 06:55:56.543353 | PLAY [logserver.rdoproject.org] 2025-10-13 06:55:56.570077 | 2025-10-13 06:55:56.570182 | TASK [Set zuul-log-path fact] 2025-10-13 06:55:56.607125 | logserver.rdoproject.org | ok 2025-10-13 06:55:56.639472 | 2025-10-13 06:55:56.639600 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 06:55:56.668709 | logserver.rdoproject.org | ok 2025-10-13 06:55:56.683693 | 2025-10-13 06:55:56.683806 | TASK [upload-logs : Create log directories] 2025-10-13 06:55:57.407085 | logserver.rdoproject.org | changed 2025-10-13 06:55:57.412964 | 2025-10-13 06:55:57.413030 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 06:55:57.739960 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.014761 2025-10-13 06:55:57.746669 | 2025-10-13 06:55:57.746766 | TASK [upload-logs : Upload logs to log server] 2025-10-13 06:55:58.785467 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 06:55:58.789293 | 2025-10-13 06:55:58.789361 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 06:55:58.838432 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 06:55:58.849097 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 06:55:58.859046 | 2025-10-13 06:55:58.859168 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 06:55:58.899503 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 06:55:58.899787 | 2025-10-13 06:55:58.900633 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 06:55:58.907554 | 2025-10-13 06:55:58.907680 | LOOP [upload-logs : Upload console log and json output]