2025-09-30 09:15:19.197300 | Job console starting... 2025-09-30 09:15:19.208753 | Updating repositories 2025-09-30 09:15:19.243203 | Preparing job workspace 2025-09-30 09:15:23.236664 | Running Ansible setup... 2025-09-30 09:15:27.108369 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 09:15:27.687236 | 2025-09-30 09:15:27.687353 | PLAY [localhost] 2025-09-30 09:15:27.695661 | 2025-09-30 09:15:27.695755 | TASK [Gathering Facts] 2025-09-30 09:15:28.602534 | localhost | ok 2025-09-30 09:15:28.622389 | 2025-09-30 09:15:28.622497 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-30 09:15:29.070015 | localhost -> localhost | changed 2025-09-30 09:15:29.084263 | 2025-09-30 09:15:29.084445 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-30 09:15:29.904260 | localhost -> localhost | changed 2025-09-30 09:15:29.923792 | 2025-09-30 09:15:29.923935 | TASK [Setup log path fact] 2025-09-30 09:15:29.950856 | localhost | ok 2025-09-30 09:15:29.972136 | 2025-09-30 09:15:29.972224 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 09:15:30.013325 | localhost | ok 2025-09-30 09:15:30.024843 | 2025-09-30 09:15:30.024935 | TASK [emit-job-header : Print job information] 2025-09-30 09:15:30.076106 | # Job Information 2025-09-30 09:15:30.076265 | Ansible Version: 2.15.12 2025-09-30 09:15:30.076303 | Job: cifmw-molecule-adoption_osp_deploy 2025-09-30 09:15:30.076330 | Pipeline: github-check 2025-09-30 09:15:30.076355 | Executor: ze04.softwarefactory-project.io 2025-09-30 09:15:30.076381 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3307 2025-09-30 09:15:30.076407 | Log URL (when completed): https://logserver.rdoproject.org/acc/rdoproject.org/acc3a4218efd487c8d4ebdecb2c96998/ 2025-09-30 09:15:30.076432 | Event ID: 407d6870-9dd9-11f0-8acc-405b294a9c64 2025-09-30 09:15:30.082164 | 2025-09-30 09:15:30.082294 | LOOP [emit-job-header : Print node information] 2025-09-30 09:15:30.185193 | localhost | ok: 2025-09-30 09:15:30.185368 | localhost | # Node Information 2025-09-30 09:15:30.185394 | localhost | Inventory Hostname: controller 2025-09-30 09:15:30.185416 | localhost | Hostname: np0005462268 2025-09-30 09:15:30.185435 | localhost | Username: zuul 2025-09-30 09:15:30.185454 | localhost | Distro: CentOS 9 2025-09-30 09:15:30.185473 | localhost | Provider: vexxhost-nodepool-tripleo 2025-09-30 09:15:30.185490 | localhost | Region: RegionOne 2025-09-30 09:15:30.185507 | localhost | Label: cloud-centos-9-stream-tripleo 2025-09-30 09:15:30.185523 | localhost | Product Name: OpenStack Nova 2025-09-30 09:15:30.185540 | localhost | Interface IP: 38.102.83.45 2025-09-30 09:15:30.218540 | 2025-09-30 09:15:30.218725 | PLAY [all] 2025-09-30 09:15:30.228596 | 2025-09-30 09:15:30.228707 | TASK [Gather network facts] 2025-09-30 09:15:30.709855 | controller | ok 2025-09-30 09:15:30.730535 | 2025-09-30 09:15:30.730615 | TASK [include_role : start-zuul-console] 2025-09-30 09:15:30.754013 | controller | ok 2025-09-30 09:15:30.771544 | 2025-09-30 09:15:30.771629 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-30 09:15:31.194508 | controller | ok 2025-09-30 09:15:31.217922 | 2025-09-30 09:15:31.218093 | TASK [include_role : add-build-sshkey] 2025-09-30 09:15:31.239102 | controller | ok 2025-09-30 09:15:31.256930 | 2025-09-30 09:15:31.257021 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-30 09:15:31.494384 | controller -> localhost | ok 2025-09-30 09:15:31.500341 | 2025-09-30 09:15:31.500402 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-30 09:15:31.528186 | controller | ok 2025-09-30 09:15:31.543231 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-30 09:15:31.549036 | 2025-09-30 09:15:31.549098 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-30 09:15:32.393050 | controller -> localhost | Generating public/private rsa key pair. 2025-09-30 09:15:32.393261 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/acc3a4218efd487c8d4ebdecb2c96998_id_rsa. 2025-09-30 09:15:32.393293 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/acc3a4218efd487c8d4ebdecb2c96998_id_rsa.pub. 2025-09-30 09:15:32.393316 | controller -> localhost | The key fingerprint is: 2025-09-30 09:15:32.393335 | controller -> localhost | SHA256:ZF7Y6Q0Dzn+DKDdnf16Tbrcl7op0GokOUPSAoGcRcXY zuul-build-sshkey 2025-09-30 09:15:32.393355 | controller -> localhost | The key's randomart image is: 2025-09-30 09:15:32.393374 | controller -> localhost | +---[RSA 3072]----+ 2025-09-30 09:15:32.393392 | controller -> localhost | | =+o.E . | 2025-09-30 09:15:32.393411 | controller -> localhost | | . +.o = + . | 2025-09-30 09:15:32.393429 | controller -> localhost | |. o . B * | 2025-09-30 09:15:32.393448 | controller -> localhost | | o . + = = | 2025-09-30 09:15:32.393466 | controller -> localhost | | . . S * + | 2025-09-30 09:15:32.393484 | controller -> localhost | | . o = + . .| 2025-09-30 09:15:32.393501 | controller -> localhost | | . . + o ooo| 2025-09-30 09:15:32.393519 | controller -> localhost | | o . = +.++| 2025-09-30 09:15:32.393536 | controller -> localhost | | . o .o=oo| 2025-09-30 09:15:32.393553 | controller -> localhost | +----[SHA256]-----+ 2025-09-30 09:15:32.393596 | controller -> localhost | ok: Runtime: 0:00:00.413722 2025-09-30 09:15:32.399604 | 2025-09-30 09:15:32.399694 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-30 09:15:32.419909 | controller | ok 2025-09-30 09:15:32.430519 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-30 09:15:32.438265 | 2025-09-30 09:15:32.438325 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-30 09:15:32.462723 | controller | skipping: Conditional result was False 2025-09-30 09:15:32.468276 | 2025-09-30 09:15:32.468346 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-30 09:15:32.909324 | controller | changed 2025-09-30 09:15:32.914189 | 2025-09-30 09:15:32.914250 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-30 09:15:33.234890 | controller | ok 2025-09-30 09:15:33.247166 | 2025-09-30 09:15:33.247307 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-30 09:15:34.162059 | controller | changed 2025-09-30 09:15:34.173496 | 2025-09-30 09:15:34.173630 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-30 09:15:35.069638 | controller | changed 2025-09-30 09:15:35.081710 | 2025-09-30 09:15:35.081845 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-30 09:15:35.109653 | controller | skipping: Conditional result was False 2025-09-30 09:15:35.124152 | 2025-09-30 09:15:35.124292 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-30 09:15:35.560137 | controller -> localhost | changed 2025-09-30 09:15:35.591892 | 2025-09-30 09:15:35.592075 | TASK [add-build-sshkey : Add back temp key] 2025-09-30 09:15:35.894271 | controller -> localhost | Identity added: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/acc3a4218efd487c8d4ebdecb2c96998_id_rsa (zuul-build-sshkey) 2025-09-30 09:15:35.894582 | controller -> localhost | ok: Runtime: 0:00:00.017184 2025-09-30 09:15:35.909735 | 2025-09-30 09:15:35.909886 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-30 09:15:36.295535 | controller | ok 2025-09-30 09:15:36.309499 | 2025-09-30 09:15:36.309643 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-30 09:15:36.348279 | controller | skipping: Conditional result was False 2025-09-30 09:15:36.372160 | 2025-09-30 09:15:36.372359 | TASK [include_role : validate-host] 2025-09-30 09:15:36.411303 | controller | ok 2025-09-30 09:15:36.447330 | 2025-09-30 09:15:36.447453 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-30 09:15:36.489413 | controller | ok 2025-09-30 09:15:36.496059 | 2025-09-30 09:15:36.496140 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-30 09:15:36.766672 | controller -> localhost | ok 2025-09-30 09:15:36.779496 | 2025-09-30 09:15:36.779630 | TASK [validate-host : Collect information about the host] 2025-09-30 09:15:37.582196 | controller | ok 2025-09-30 09:15:37.605970 | 2025-09-30 09:15:37.606198 | TASK [validate-host : Sanitize hostname] 2025-09-30 09:15:37.670259 | controller | ok 2025-09-30 09:15:37.684642 | 2025-09-30 09:15:37.684781 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-30 09:15:38.121308 | controller -> localhost | changed 2025-09-30 09:15:38.133426 | 2025-09-30 09:15:38.133597 | TASK [validate-host : Collect information about zuul worker] 2025-09-30 09:15:38.576265 | controller | ok 2025-09-30 09:15:38.587876 | 2025-09-30 09:15:38.588013 | TASK [validate-host : Write out all zuul information for each host] 2025-09-30 09:15:39.123593 | controller -> localhost | changed 2025-09-30 09:15:39.133034 | 2025-09-30 09:15:39.133101 | TASK [include_role : prepare-workspace-openshift] 2025-09-30 09:15:39.157338 | controller | skipping: Conditional result was False 2025-09-30 09:15:39.162638 | 2025-09-30 09:15:39.162727 | TASK [include_role : remove-zuul-sshkey] 2025-09-30 09:15:39.176391 | controller | skipping: Conditional result was False 2025-09-30 09:15:39.182994 | 2025-09-30 09:15:39.183094 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-09-30 09:15:39.421984 | controller | ok: "logs" 2025-09-30 09:15:39.422201 | controller | ok: All items complete 2025-09-30 09:15:39.422230 | 2025-09-30 09:15:39.666122 | controller | ok: "artifacts" 2025-09-30 09:15:39.940071 | controller | ok: "docs" 2025-09-30 09:15:39.961049 | 2025-09-30 09:15:39.961247 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-09-30 09:15:40.266748 | controller | changed: "logs" 2025-09-30 09:15:40.510148 | controller | changed: "artifacts" 2025-09-30 09:15:40.736399 | controller | changed: "docs" 2025-09-30 09:15:40.781029 | 2025-09-30 09:15:40.781160 | PLAY RECAP 2025-09-30 09:15:40.781219 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 09:15:40.781252 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 09:15:40.781275 | 2025-09-30 09:15:40.913915 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 09:15:40.914759 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-09-30 09:15:41.547727 | 2025-09-30 09:15:41.547832 | PLAY [localhost] 2025-09-30 09:15:41.564183 | 2025-09-30 09:15:41.564255 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-09-30 09:15:41.925117 | localhost | ok 2025-09-30 09:15:41.930282 | 2025-09-30 09:15:41.930356 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-09-30 09:15:42.598474 | localhost | changed 2025-09-30 09:15:42.619952 | 2025-09-30 09:15:42.620062 | PLAY [all] 2025-09-30 09:15:42.635404 | 2025-09-30 09:15:42.635466 | TASK [include_role : prepare-workspace] 2025-09-30 09:15:42.663363 | controller | ok 2025-09-30 09:15:42.677305 | 2025-09-30 09:15:42.677367 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-09-30 09:15:43.097418 | controller | ok 2025-09-30 09:15:43.110194 | 2025-09-30 09:15:43.110330 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-09-30 09:15:44.991229 | controller | Output suppressed because no_log was given 2025-09-30 09:15:45.010293 | 2025-09-30 09:15:45.010389 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-09-30 09:15:45.317002 | controller | changed: "logs" 2025-09-30 09:15:45.568821 | controller | changed: "artifacts" 2025-09-30 09:15:45.803466 | controller | changed: "docs" 2025-09-30 09:15:45.826946 | 2025-09-30 09:15:45.827211 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-09-30 09:15:46.147101 | controller | changed: "logs" 2025-09-30 09:15:46.147345 | controller | changed: All items complete 2025-09-30 09:15:46.147371 | 2025-09-30 09:15:46.379082 | controller | changed: "artifacts" 2025-09-30 09:15:46.634187 | controller | changed: "docs" 2025-09-30 09:15:46.670128 | 2025-09-30 09:15:46.670392 | TASK [Check if worker can sudo] 2025-09-30 09:15:47.222174 | controller | ok: Runtime: 0:00:00.043651 2025-09-30 09:15:47.229998 | 2025-09-30 09:15:47.230087 | TASK [configure-mirrors : Gather needed facts] 2025-09-30 09:15:47.308162 | controller | skipping: Conditional result was False 2025-09-30 09:15:47.322193 | 2025-09-30 09:15:47.322334 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-09-30 09:15:47.401564 | controller | ok 2025-09-30 09:15:47.419857 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-09-30 09:15:47.469578 | 2025-09-30 09:15:47.469899 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-09-30 09:15:47.754067 | controller | ok 2025-09-30 09:15:47.760142 | 2025-09-30 09:15:47.760203 | LOOP [configure-mirrors : Include OS-specific variables] 2025-09-30 09:15:47.846548 | controller | ok: "/var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-09-30 09:15:47.871874 | 2025-09-30 09:15:47.872025 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-09-30 09:15:48.763463 | controller | changed 2025-09-30 09:15:48.770852 | 2025-09-30 09:15:48.770936 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-09-30 09:15:48.858777 | controller | ok: "/var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-09-30 09:15:48.859270 | controller | ok: All items complete 2025-09-30 09:15:48.859340 | 2025-09-30 09:15:48.939780 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-09-30 09:15:48.947255 | 2025-09-30 09:15:48.947321 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-09-30 09:15:49.948163 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-09-30 09:15:50.854522 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-09-30 09:15:50.878434 | 2025-09-30 09:15:50.878590 | TASK [configure-mirrors : Disable deltrarpm] 2025-09-30 09:15:51.376005 | controller | changed: section and option added 2025-09-30 09:15:51.416282 | 2025-09-30 09:15:51.416386 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-09-30 09:15:52.225491 | controller | 29 files removed 2025-09-30 09:15:52.225732 | controller | ok: Item: dnf clean all Runtime: 0:00:00.459591 2025-09-30 09:15:52.225773 | controller | changed: All items complete 2025-09-30 09:15:52.225795 | 2025-09-30 09:16:02.757292 | 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-09-30 09:16:02.757460 | controller | DNF version: 4.14.0 2025-09-30 09:16:02.757518 | controller | cachedir: /var/cache/dnf 2025-09-30 09:16:02.757564 | controller | Making cache files for all metadata files. 2025-09-30 09:16:02.757608 | controller | baseos: has expired and will be refreshed. 2025-09-30 09:16:02.757650 | controller | appstream: has expired and will be refreshed. 2025-09-30 09:16:02.757730 | controller | crb: has expired and will be refreshed. 2025-09-30 09:16:02.757791 | controller | extras-common: has expired and will be refreshed. 2025-09-30 09:16:02.757834 | controller | repo: downloading from remote: baseos 2025-09-30 09:16:02.757875 | controller | CentOS Stream 9 - BaseOS 74 MB/s | 8.8 MB 00:00 2025-09-30 09:16:02.757915 | controller | baseos: using metadata from Mon 22 Sep 2025 10:29:43 AM EDT. 2025-09-30 09:16:02.757954 | controller | repo: downloading from remote: appstream 2025-09-30 09:16:02.757993 | controller | CentOS Stream 9 - AppStream 100 MB/s | 25 MB 00:00 2025-09-30 09:16:02.758032 | controller | appstream: using metadata from Mon 22 Sep 2025 10:33:24 AM EDT. 2025-09-30 09:16:02.758071 | controller | repo: downloading from remote: crb 2025-09-30 09:16:02.758110 | controller | CentOS Stream 9 - CRB 76 MB/s | 7.1 MB 00:00 2025-09-30 09:16:02.758150 | controller | crb: using metadata from Mon 22 Sep 2025 10:37:51 AM EDT. 2025-09-30 09:16:02.758189 | controller | repo: downloading from remote: extras-common 2025-09-30 09:16:02.758228 | controller | CentOS Stream 9 - Extras packages 1.3 MB/s | 20 kB 00:00 2025-09-30 09:16:02.758267 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-09-30 09:16:02.758305 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-09-30 09:16:02.758344 | controller | Completion plugin: Generating completion cache... 2025-09-30 09:16:02.758382 | controller | Metadata cache created. 2025-09-30 09:16:02.758444 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.245142 2025-09-30 09:16:02.776078 | 2025-09-30 09:16:02.776162 | PLAY RECAP 2025-09-30 09:16:02.776204 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-09-30 09:16:02.776230 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 09:16:02.776247 | 2025-09-30 09:16:02.874750 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-09-30 09:16:02.875571 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-09-30 09:16:03.399709 | 2025-09-30 09:16:03.399813 | PLAY [all] 2025-09-30 09:16:03.421197 | 2025-09-30 09:16:03.421292 | TASK [Install binary dependencies] 2025-09-30 09:16:03.471801 | controller | ok 2025-09-30 09:16:03.490283 | 2025-09-30 09:16:03.490375 | TASK [bindep : Include find tasks] 2025-09-30 09:16:03.518660 | controller | ok 2025-09-30 09:16:03.525859 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-09-30 09:16:03.531764 | 2025-09-30 09:16:03.531824 | TASK [bindep : Look for bindep.txt] 2025-09-30 09:16:03.967361 | controller | ok 2025-09-30 09:16:03.973638 | 2025-09-30 09:16:03.973729 | TASK [bindep : Define bindep_file fact] 2025-09-30 09:16:04.002918 | controller | ok 2025-09-30 09:16:04.008002 | 2025-09-30 09:16:04.008070 | TASK [bindep : Look for other-requirements.txt] 2025-09-30 09:16:04.022235 | controller | skipping: Conditional result was False 2025-09-30 09:16:04.028813 | 2025-09-30 09:16:04.028894 | TASK [bindep : Define bindep_file fact] 2025-09-30 09:16:04.057418 | controller | skipping: Conditional result was False 2025-09-30 09:16:04.062816 | 2025-09-30 09:16:04.062883 | TASK [bindep : Look for bindep fallback file] 2025-09-30 09:16:04.086986 | controller | skipping: Conditional result was False 2025-09-30 09:16:04.092728 | 2025-09-30 09:16:04.092793 | TASK [bindep : Define bindep_file fact] 2025-09-30 09:16:04.116808 | controller | skipping: Conditional result was False 2025-09-30 09:16:04.122522 | 2025-09-30 09:16:04.122582 | TASK [bindep : Include bindep tasks] 2025-09-30 09:16:04.153158 | controller | ok 2025-09-30 09:16:04.159771 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-09-30 09:16:04.167419 | 2025-09-30 09:16:04.167478 | TASK [bindep : Look for bindep command] 2025-09-30 09:16:04.191390 | controller | skipping: Conditional result was False 2025-09-30 09:16:04.197406 | 2025-09-30 09:16:04.197467 | TASK [bindep : Check for system bindep] 2025-09-30 09:16:04.727608 | controller | ok: Runtime: 0:00:00.007082 2025-09-30 09:16:04.734660 | 2025-09-30 09:16:04.734992 | TASK [bindep : Define bindep_command fact] 2025-09-30 09:16:04.770779 | controller | skipping: Conditional result was False 2025-09-30 09:16:04.778147 | 2025-09-30 09:16:04.778213 | TASK [bindep : Include install tasks] 2025-09-30 09:16:04.819552 | controller | ok 2025-09-30 09:16:04.830236 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-09-30 09:16:04.840186 | 2025-09-30 09:16:04.840249 | TASK [bindep : Create temp dir for bindep] 2025-09-30 09:16:05.234488 | controller | changed 2025-09-30 09:16:05.239762 | 2025-09-30 09:16:05.239823 | TASK [Ensure we have pip dependencies] 2025-09-30 09:16:05.259665 | controller | ok 2025-09-30 09:16:05.283506 | 2025-09-30 09:16:05.283578 | TASK [ensure-pip : Check if pip is installed] 2025-09-30 05:16:05.590972 | controller | /usr/bin/pip3 2025-09-30 05:16:05.613997 | controller | /usr/bin/python3: No module named wheel 2025-09-30 09:16:05.816576 | controller | ok: Runtime: 0:00:00.036328 2025-09-30 09:16:05.822503 | 2025-09-30 09:16:05.822574 | LOOP [ensure-pip : Install pip from packages] 2025-09-30 09:16:05.863446 | controller | ok: "/var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-09-30 09:16:05.874148 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-09-30 09:16:05.884048 | 2025-09-30 09:16:05.884110 | TASK [ensure-pip : Install Python 3 pip] 2025-09-30 09:16:08.289549 | controller | changed 2025-09-30 09:16:08.301474 | 2025-09-30 09:16:08.301603 | TASK [ensure-pip : Check for EPEL repository] 2025-09-30 09:16:08.361437 | controller | skipping: Conditional result was False 2025-09-30 09:16:08.375980 | 2025-09-30 09:16:08.376135 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-09-30 09:16:08.434473 | controller | skipping: Conditional result was False 2025-09-30 09:16:08.447667 | 2025-09-30 09:16:08.447834 | TASK [ensure-pip : Install Python 2 pip] 2025-09-30 09:16:08.495184 | controller | skipping: Conditional result was False 2025-09-30 09:16:08.506559 | 2025-09-30 09:16:08.506730 | TASK [ensure-pip : Ensure setuptools] 2025-09-30 09:16:08.532100 | controller | skipping: Conditional result was False 2025-09-30 09:16:08.541519 | 2025-09-30 09:16:08.541622 | TASK [ensure-pip : Check for ensurepip module] 2025-09-30 09:16:09.082998 | controller | skipping: Conditional result was False 2025-09-30 09:16:09.097070 | 2025-09-30 09:16:09.097224 | TASK [ensure-pip : Ensure python3-venv] 2025-09-30 09:16:09.124412 | controller | skipping: Conditional result was False 2025-09-30 09:16:09.138534 | 2025-09-30 09:16:09.138671 | TASK [ensure-pip : Install pip from source] 2025-09-30 09:16:09.155351 | controller | skipping: Conditional result was False 2025-09-30 09:16:09.168082 | 2025-09-30 09:16:09.168218 | TASK [ensure-pip : Probe for venv python full path] 2025-09-30 05:16:09.476633 | controller | /usr/bin/python3 2025-09-30 09:16:09.711558 | controller | ok: Runtime: 0:00:00.007806 2025-09-30 09:16:09.717206 | 2025-09-30 09:16:09.717276 | TASK [ensure-pip : Set host default] 2025-09-30 09:16:09.756577 | controller | ok 2025-09-30 09:16:09.762376 | 2025-09-30 09:16:09.762440 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-09-30 09:16:09.813171 | controller | ok 2025-09-30 09:16:09.823860 | 2025-09-30 09:16:09.823926 | TASK [bindep : Install bindep into temporary venv] 2025-09-30 09:16:14.621632 | controller | changed 2025-09-30 09:16:14.633921 | 2025-09-30 09:16:14.634071 | TASK [bindep : Define bindep_command] 2025-09-30 09:16:14.674470 | controller | ok 2025-09-30 09:16:14.686133 | 2025-09-30 09:16:14.686263 | LOOP [bindep : Include package tasks] 2025-09-30 09:16:14.764917 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-09-30 09:16:14.765556 | controller | ok: All items complete 2025-09-30 09:16:14.765631 | 2025-09-30 09:16:14.794768 | controller | included: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-09-30 09:16:14.820622 | 2025-09-30 09:16:14.820741 | TASK [bindep : Define bindep_run fact] 2025-09-30 09:16:14.863809 | controller | ok 2025-09-30 09:16:14.871153 | 2025-09-30 09:16:14.871241 | TASK [bindep : Get list of packages to install from bindep] 2025-09-30 05:16:16.593726 | controller | podman 2025-09-30 05:16:16.646189 | controller | python3-jmespath 2025-09-30 05:16:16.646396 | controller | python3-libvirt 2025-09-30 05:16:16.646417 | controller | python3-lxml 2025-09-30 05:16:16.646436 | controller | python3-netaddr 2025-09-30 09:16:16.913134 | controller | ok: Runtime: 0:00:01.453370 2025-09-30 09:16:16.919559 | 2025-09-30 09:16:16.919624 | TASK [bindep : Install distro packages from bindep] 2025-09-30 09:17:22.214419 | controller | changed 2025-09-30 09:17:22.223178 | 2025-09-30 09:17:22.223270 | TASK [bindep : Check that packages are installed] 2025-09-30 09:17:23.787203 | controller | ok: Runtime: 0:00:01.231996 2025-09-30 09:17:23.798988 | 2025-09-30 09:17:23.799134 | TASK [bindep : Fail if we cannot install all packages] 2025-09-30 09:17:23.826374 | controller | skipping: Conditional result was False 2025-09-30 09:17:23.841824 | 2025-09-30 09:17:23.841923 | TASK [Run test-setup role] 2025-09-30 09:17:23.881619 | controller | ok 2025-09-30 09:17:23.909210 | 2025-09-30 09:17:23.909363 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-09-30 09:17:24.193183 | controller | ok 2025-09-30 09:17:24.204254 | 2025-09-30 09:17:24.204390 | TASK [test-setup : Run tools/test-setup.sh] 2025-09-30 09:17:24.744112 | controller | skipping: Conditional result was False 2025-09-30 09:17:24.782898 | 2025-09-30 09:17:24.783005 | TASK [bindep : Remove bindep temp dir] 2025-09-30 09:17:25.164788 | controller | ok 2025-09-30 09:17:25.187053 | 2025-09-30 09:17:25.187161 | PLAY RECAP 2025-09-30 09:17:25.187243 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-09-30 09:17:25.187286 | 2025-09-30 09:17:25.300387 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-09-30 09:17:25.302393 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-09-30 09:17:25.902365 | 2025-09-30 09:17:25.902477 | PLAY [all] 2025-09-30 09:17:25.921786 | 2025-09-30 09:17:25.921863 | TASK [Abort when test_command variable is undefined] 2025-09-30 09:17:25.966298 | controller | skipping: Conditional result was False 2025-09-30 09:17:25.972101 | 2025-09-30 09:17:25.972180 | TASK [Convert test_command to list] 2025-09-30 09:17:26.026603 | controller | skipping: Conditional result was False 2025-09-30 09:17:26.033312 | 2025-09-30 09:17:26.033380 | TASK [Use test_command list] 2025-09-30 09:17:26.092799 | controller | ok 2025-09-30 09:17:26.098124 | 2025-09-30 09:17:26.098184 | LOOP [Run test_command] 2025-09-30 09:17:26.516047 | controller | no check to run 2025-09-30 09:17:26.516333 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.009527 2025-09-30 09:17:26.565104 | 2025-09-30 09:17:26.565265 | PLAY RECAP 2025-09-30 09:17:26.565350 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 09:17:26.565391 | 2025-09-30 09:17:26.690993 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-09-30 09:17:26.691961 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-30 09:17:27.291074 | 2025-09-30 09:17:27.291185 | PLAY [all] 2025-09-30 09:17:27.311763 | 2025-09-30 09:17:27.311893 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-09-30 09:17:27.768887 | controller | changed: non-zero return code 2025-09-30 09:17:27.774196 | 2025-09-30 09:17:27.774269 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-09-30 09:17:27.798399 | controller | skipping: Conditional result was False 2025-09-30 09:17:27.803805 | 2025-09-30 09:17:27.803873 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-09-30 09:17:27.823799 | 2025-09-30 09:17:27.823917 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-09-30 09:17:27.853051 | 2025-09-30 09:17:27.853168 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-09-30 09:17:27.876866 | controller | skipping: Conditional result was False 2025-09-30 09:17:27.882483 | 2025-09-30 09:17:27.882549 | LOOP [fetch-subunit-output : Generate subunit file] 2025-09-30 09:17:27.932862 | 2025-09-30 09:17:27.933139 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-09-30 09:17:27.970828 | controller | skipping: Conditional result was False 2025-09-30 09:17:27.976851 | 2025-09-30 09:17:27.976921 | TASK [fetch-subunit-output : Remove the temporary file] 2025-09-30 09:17:27.991221 | controller | skipping: Conditional result was False 2025-09-30 09:17:27.997718 | 2025-09-30 09:17:27.997790 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-09-30 09:17:28.012047 | controller | skipping: Conditional result was False 2025-09-30 09:17:28.037666 | 2025-09-30 09:17:28.037760 | PLAY RECAP 2025-09-30 09:17:28.038242 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-09-30 09:17:28.038270 | 2025-09-30 09:17:28.137780 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-09-30 09:17:28.138615 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 09:17:28.709728 | 2025-09-30 09:17:28.709833 | PLAY [all] 2025-09-30 09:17:28.728858 | 2025-09-30 09:17:28.728934 | TASK [include_role : fetch-output] 2025-09-30 09:17:28.757754 | controller | ok 2025-09-30 09:17:28.775121 | 2025-09-30 09:17:28.775219 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 09:17:28.819364 | controller | skipping: Conditional result was False 2025-09-30 09:17:28.825073 | 2025-09-30 09:17:28.825139 | TASK [fetch-output : Set log path for single node] 2025-09-30 09:17:28.853621 | controller | ok 2025-09-30 09:17:28.858510 | 2025-09-30 09:17:28.858570 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 09:17:29.262717 | controller -> localhost | ok: "/var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/logs" 2025-09-30 09:17:29.483645 | controller -> localhost | changed: "/var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/artifacts" 2025-09-30 09:17:29.688616 | controller -> localhost | changed: "/var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/docs" 2025-09-30 09:17:29.697818 | 2025-09-30 09:17:29.697931 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 09:17:30.419441 | controller | changed: .d..t...... ./ 2025-09-30 09:17:30.419706 | controller | changed: All items complete 2025-09-30 09:17:30.419752 | 2025-09-30 09:17:30.860557 | controller | changed: .d..t...... ./ 2025-09-30 09:17:31.338000 | controller | changed: .d..t...... ./ 2025-09-30 09:17:31.355922 | 2025-09-30 09:17:31.356039 | TASK [include_role : fetch-output-openshift] 2025-09-30 09:17:31.382206 | controller | skipping: Conditional result was False 2025-09-30 09:17:31.395353 | 2025-09-30 09:17:31.395490 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-09-30 09:17:31.874755 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.011440 2025-09-30 09:17:32.139433 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007843 2025-09-30 09:17:32.173254 | 2025-09-30 09:17:32.173345 | PLAY [all] 2025-09-30 09:17:32.187587 | 2025-09-30 09:17:32.187651 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-30 09:17:32.625587 | controller | changed 2025-09-30 09:17:32.659493 | 2025-09-30 09:17:32.659595 | PLAY RECAP 2025-09-30 09:17:32.659655 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 09:17:32.659709 | 2025-09-30 09:17:32.797505 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 09:17:32.799178 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-09-30 09:17:33.458935 | 2025-09-30 09:17:33.459044 | PLAY [localhost] 2025-09-30 09:17:33.476607 | 2025-09-30 09:17:33.476707 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-30 09:17:33.927035 | localhost | changed 2025-09-30 09:17:33.937015 | 2025-09-30 09:17:33.937168 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-30 09:17:33.974001 | localhost | ok 2025-09-30 09:17:33.991196 | 2025-09-30 09:17:33.991338 | TASK [add-fileserver : Create SSH private key tempfile] 2025-09-30 09:17:34.408743 | localhost | changed 2025-09-30 09:17:34.414445 | 2025-09-30 09:17:34.414517 | TASK [add-fileserver : Create SSH private key from secret] 2025-09-30 09:17:35.183040 | localhost | changed 2025-09-30 09:17:35.194730 | 2025-09-30 09:17:35.194893 | TASK [add-fileserver : Add fileserver ssh key] 2025-09-30 09:17:35.649415 | localhost | Identity added: /var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/tmp/ansible.0_t2exaj (/var/lib/zuul/builds/acc3a4218efd487c8d4ebdecb2c96998/work/tmp/ansible.0_t2exaj) 2025-09-30 09:17:35.649769 | localhost | ok: Runtime: 0:00:00.014387 2025-09-30 09:17:35.659577 | 2025-09-30 09:17:35.659765 | TASK [add-fileserver : Remove SSH private key from disk] 2025-09-30 09:17:35.991662 | localhost | ok: Runtime: 0:00:00.008865 2025-09-30 09:17:36.001951 | 2025-09-30 09:17:36.002087 | TASK [add-fileserver : Add fileserver to inventory] 2025-09-30 09:17:36.091250 | localhost | changed 2025-09-30 09:17:36.101263 | 2025-09-30 09:17:36.101405 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-09-30 09:17:36.514420 | localhost | changed 2025-09-30 09:17:36.551882 | 2025-09-30 09:17:36.551964 | PLAY [localhost] 2025-09-30 09:17:36.568653 | 2025-09-30 09:17:36.568757 | TASK [Generate bulk log download script] 2025-09-30 09:17:36.591757 | localhost | ok 2025-09-30 09:17:36.607853 | 2025-09-30 09:17:36.607947 | TASK [local-log-download : Check API endpoint is defined] 2025-09-30 09:17:36.661730 | localhost | ok: All assertions passed 2025-09-30 09:17:36.671591 | 2025-09-30 09:17:36.671750 | TASK [local-log-download : Create download script] 2025-09-30 09:17:37.123480 | localhost -> localhost | changed 2025-09-30 09:17:37.132287 | 2025-09-30 09:17:37.132347 | TASK [Register quick-download link] 2025-09-30 09:17:37.160633 | localhost | ok 2025-09-30 09:17:37.202369 | 2025-09-30 09:17:37.202478 | PLAY [logserver.rdoproject.org] 2025-09-30 09:17:37.212300 | 2025-09-30 09:17:37.212360 | TASK [Set zuul-log-path fact] 2025-09-30 09:17:37.229311 | logserver.rdoproject.org | ok 2025-09-30 09:17:37.238662 | 2025-09-30 09:17:37.238836 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 09:17:37.276104 | logserver.rdoproject.org | ok 2025-09-30 09:17:37.284647 | 2025-09-30 09:17:37.284795 | TASK [upload-logs : Create log directories] 2025-09-30 09:17:38.175740 | logserver.rdoproject.org | changed 2025-09-30 09:17:38.182907 | 2025-09-30 09:17:38.183040 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-30 09:17:38.485969 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.008325 2025-09-30 09:17:38.495784 | 2025-09-30 09:17:38.495916 | TASK [upload-logs : Upload logs to log server] 2025-09-30 09:17:39.210732 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-09-30 09:17:39.216950 | 2025-09-30 09:17:39.217077 | LOOP [upload-logs : Compress console log and json output] 2025-09-30 09:17:39.274234 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 09:17:39.287159 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 09:17:39.302821 | 2025-09-30 09:17:39.302987 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-30 09:17:39.350421 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 09:17:39.350908 | 2025-09-30 09:17:39.353413 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 09:17:39.369927 | 2025-09-30 09:17:39.370110 | LOOP [upload-logs : Upload console log and json output]