2025-10-13 07:00:15.971947 | Job console starting... 2025-10-13 07:00:15.982241 | Updating repositories 2025-10-13 07:00:16.006591 | Preparing job workspace 2025-10-13 07:00:19.186260 | Running Ansible setup... 2025-10-13 07:00:24.005573 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 07:00:24.628861 | 2025-10-13 07:00:24.628995 | PLAY [localhost] 2025-10-13 07:00:24.638150 | 2025-10-13 07:00:24.638254 | TASK [Gathering Facts] 2025-10-13 07:00:25.642253 | localhost | ok 2025-10-13 07:00:25.656212 | 2025-10-13 07:00:25.656351 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 07:00:26.037062 | localhost -> localhost | changed 2025-10-13 07:00:26.043562 | 2025-10-13 07:00:26.043662 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 07:00:26.823030 | localhost -> localhost | changed 2025-10-13 07:00:26.835005 | 2025-10-13 07:00:26.835153 | TASK [Setup log path fact] 2025-10-13 07:00:26.854334 | localhost | ok 2025-10-13 07:00:26.870514 | 2025-10-13 07:00:26.870634 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 07:00:26.900107 | localhost | ok 2025-10-13 07:00:26.907922 | 2025-10-13 07:00:26.908064 | TASK [emit-job-header : Print job information] 2025-10-13 07:00:26.935797 | # Job Information 2025-10-13 07:00:26.935945 | Ansible Version: 2.15.12 2025-10-13 07:00:26.935987 | Job: cifmw-molecule-switch_config 2025-10-13 07:00:26.936009 | Pipeline: github-check 2025-10-13 07:00:26.936029 | Executor: ze03.softwarefactory-project.io 2025-10-13 07:00:26.936047 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237 2025-10-13 07:00:26.936067 | Log URL (when completed): https://logserver.rdoproject.org/3f9/rdoproject.org/3f9637b4261149168d8c5c92950b874b/ 2025-10-13 07:00:26.936087 | Event ID: 07b5c7c0-a802-11f0-8dbe-38d1533757a8 2025-10-13 07:00:26.939563 | 2025-10-13 07:00:26.939629 | LOOP [emit-job-header : Print node information] 2025-10-13 07:00:27.054070 | localhost | ok: 2025-10-13 07:00:27.054345 | localhost | # Node Information 2025-10-13 07:00:27.054401 | localhost | Inventory Hostname: controller 2025-10-13 07:00:27.054450 | localhost | Hostname: np0005482744 2025-10-13 07:00:27.054492 | localhost | Username: zuul 2025-10-13 07:00:27.054536 | localhost | Distro: CentOS 9 2025-10-13 07:00:27.054576 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-13 07:00:27.054614 | localhost | Region: RegionOne 2025-10-13 07:00:27.054649 | localhost | Label: cloud-centos-9-stream-tripleo 2025-10-13 07:00:27.054686 | localhost | Product Name: OpenStack Nova 2025-10-13 07:00:27.054722 | localhost | Interface IP: 38.129.56.245 2025-10-13 07:00:27.102447 | 2025-10-13 07:00:27.102563 | PLAY [all] 2025-10-13 07:00:27.111895 | 2025-10-13 07:00:27.112000 | TASK [Gather network facts] 2025-10-13 07:00:27.639390 | controller | ok 2025-10-13 07:00:27.669612 | 2025-10-13 07:00:27.669752 | TASK [include_role : start-zuul-console] 2025-10-13 07:00:27.687910 | controller | ok 2025-10-13 07:00:27.700322 | 2025-10-13 07:00:27.700393 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 07:00:28.083879 | controller | ok 2025-10-13 07:00:28.099191 | 2025-10-13 07:00:28.099324 | TASK [include_role : add-build-sshkey] 2025-10-13 07:00:28.142294 | controller | ok 2025-10-13 07:00:28.161437 | 2025-10-13 07:00:28.161568 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 07:00:28.400189 | controller -> localhost | ok 2025-10-13 07:00:28.405855 | 2025-10-13 07:00:28.405929 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 07:00:28.434514 | controller | ok 2025-10-13 07:00:28.448185 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 07:00:28.453753 | 2025-10-13 07:00:28.453817 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 07:00:29.269453 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 07:00:29.269659 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/3f9637b4261149168d8c5c92950b874b_id_rsa. 2025-10-13 07:00:29.269692 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/3f9637b4261149168d8c5c92950b874b_id_rsa.pub. 2025-10-13 07:00:29.269716 | controller -> localhost | The key fingerprint is: 2025-10-13 07:00:29.269794 | controller -> localhost | SHA256:MOEzmKzOGCmP+7C3MCxl3+OAVn1VbFmT33zB4+xLYPA zuul-build-sshkey 2025-10-13 07:00:29.269828 | controller -> localhost | The key's randomart image is: 2025-10-13 07:00:29.269857 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 07:00:29.269884 | controller -> localhost | | . ..o+. | 2025-10-13 07:00:29.269911 | controller -> localhost | | . + . o+ .= | 2025-10-13 07:00:29.269936 | controller -> localhost | | + * ..o oo+| 2025-10-13 07:00:29.269961 | controller -> localhost | | . . . = . E o=| 2025-10-13 07:00:29.269987 | controller -> localhost | |+ + . . S . o .| 2025-10-13 07:00:29.270008 | controller -> localhost | |oX + . . o | 2025-10-13 07:00:29.270025 | controller -> localhost | |B.* o o . .| 2025-10-13 07:00:29.270047 | controller -> localhost | |.B. o . . | 2025-10-13 07:00:29.270069 | controller -> localhost | |ooo. . | 2025-10-13 07:00:29.270093 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 07:00:29.270147 | controller -> localhost | ok: Runtime: 0:00:00.443538 2025-10-13 07:00:29.276883 | 2025-10-13 07:00:29.276960 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 07:00:29.298807 | controller | ok 2025-10-13 07:00:29.311104 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 07:00:29.320641 | 2025-10-13 07:00:29.320759 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 07:00:29.335126 | controller | skipping: Conditional result was False 2025-10-13 07:00:29.340821 | 2025-10-13 07:00:29.340905 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 07:00:29.810266 | controller | changed 2025-10-13 07:00:29.816101 | 2025-10-13 07:00:29.816164 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 07:00:30.119991 | controller | ok 2025-10-13 07:00:30.125229 | 2025-10-13 07:00:30.125408 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 07:00:30.996824 | controller | changed 2025-10-13 07:00:31.005134 | 2025-10-13 07:00:31.005205 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 07:00:31.888651 | controller | changed 2025-10-13 07:00:31.894430 | 2025-10-13 07:00:31.894493 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 07:00:31.943635 | controller | skipping: Conditional result was False 2025-10-13 07:00:31.949211 | 2025-10-13 07:00:31.949278 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 07:00:32.431640 | controller -> localhost | changed 2025-10-13 07:00:32.442093 | 2025-10-13 07:00:32.442164 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 07:00:32.860825 | controller -> localhost | Identity added: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/3f9637b4261149168d8c5c92950b874b_id_rsa (zuul-build-sshkey) 2025-10-13 07:00:32.861010 | controller -> localhost | ok: Runtime: 0:00:00.015312 2025-10-13 07:00:32.866694 | 2025-10-13 07:00:32.866766 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 07:00:33.263523 | controller | ok 2025-10-13 07:00:33.268822 | 2025-10-13 07:00:33.269073 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 07:00:33.305290 | controller | skipping: Conditional result was False 2025-10-13 07:00:33.319227 | 2025-10-13 07:00:33.319340 | TASK [include_role : validate-host] 2025-10-13 07:00:33.348471 | controller | ok 2025-10-13 07:00:33.370666 | 2025-10-13 07:00:33.370858 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 07:00:33.398841 | controller | ok 2025-10-13 07:00:33.403958 | 2025-10-13 07:00:33.404024 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 07:00:33.658978 | controller -> localhost | ok 2025-10-13 07:00:33.664771 | 2025-10-13 07:00:33.664832 | TASK [validate-host : Collect information about the host] 2025-10-13 07:00:34.438556 | controller | ok 2025-10-13 07:00:34.447693 | 2025-10-13 07:00:34.447905 | TASK [validate-host : Sanitize hostname] 2025-10-13 07:00:34.508533 | controller | ok 2025-10-13 07:00:34.513876 | 2025-10-13 07:00:34.513942 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 07:00:35.108773 | controller -> localhost | changed 2025-10-13 07:00:35.114289 | 2025-10-13 07:00:35.114368 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 07:00:35.600094 | controller | ok 2025-10-13 07:00:35.613096 | 2025-10-13 07:00:35.613267 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 07:00:36.105826 | controller -> localhost | changed 2025-10-13 07:00:36.117591 | 2025-10-13 07:00:36.117696 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 07:00:36.153801 | controller | skipping: Conditional result was False 2025-10-13 07:00:36.160126 | 2025-10-13 07:00:36.160205 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 07:00:36.188802 | controller | skipping: Conditional result was False 2025-10-13 07:00:36.194995 | 2025-10-13 07:00:36.195093 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 07:00:36.438538 | controller | ok: "logs" 2025-10-13 07:00:36.438930 | controller | ok: All items complete 2025-10-13 07:00:36.438968 | 2025-10-13 07:00:36.704004 | controller | ok: "artifacts" 2025-10-13 07:00:36.920312 | controller | ok: "docs" 2025-10-13 07:00:36.929963 | 2025-10-13 07:00:36.930076 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 07:00:37.187951 | controller | changed: "logs" 2025-10-13 07:00:37.464711 | controller | changed: "artifacts" 2025-10-13 07:00:37.738132 | controller | changed: "docs" 2025-10-13 07:00:37.769049 | 2025-10-13 07:00:37.769131 | PLAY RECAP 2025-10-13 07:00:37.769174 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 07:00:37.769206 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 07:00:37.769231 | 2025-10-13 07:00:37.889977 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 07:00:37.891263 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 07:00:38.554061 | 2025-10-13 07:00:38.554167 | PLAY [localhost] 2025-10-13 07:00:38.571026 | 2025-10-13 07:00:38.571104 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-10-13 07:00:38.966609 | localhost | ok 2025-10-13 07:00:38.971665 | 2025-10-13 07:00:38.971769 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-10-13 07:00:39.595396 | localhost | changed 2025-10-13 07:00:39.622012 | 2025-10-13 07:00:39.622151 | PLAY [all] 2025-10-13 07:00:39.638405 | 2025-10-13 07:00:39.638525 | TASK [include_role : prepare-workspace] 2025-10-13 07:00:39.657676 | controller | ok 2025-10-13 07:00:39.673292 | 2025-10-13 07:00:39.673395 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 07:00:40.096870 | controller | ok 2025-10-13 07:00:40.103053 | 2025-10-13 07:00:40.103118 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 07:00:41.856517 | controller | Output suppressed because no_log was given 2025-10-13 07:00:41.879474 | 2025-10-13 07:00:41.879692 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 07:00:42.150794 | controller | changed: "logs" 2025-10-13 07:00:42.373865 | controller | changed: "artifacts" 2025-10-13 07:00:42.587819 | controller | changed: "docs" 2025-10-13 07:00:42.597019 | 2025-10-13 07:00:42.597105 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 07:00:42.856422 | controller | changed: "logs" 2025-10-13 07:00:42.856852 | controller | changed: All items complete 2025-10-13 07:00:42.856913 | 2025-10-13 07:00:43.101503 | controller | changed: "artifacts" 2025-10-13 07:00:43.345089 | controller | changed: "docs" 2025-10-13 07:00:43.366991 | 2025-10-13 07:00:43.367102 | TASK [Check if worker can sudo] 2025-10-13 07:00:43.944374 | controller | ok: Runtime: 0:00:00.058456 2025-10-13 07:00:43.951049 | 2025-10-13 07:00:43.951138 | TASK [configure-mirrors : Gather needed facts] 2025-10-13 07:00:44.058384 | controller | skipping: Conditional result was False 2025-10-13 07:00:44.078869 | 2025-10-13 07:00:44.079019 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-10-13 07:00:44.199164 | controller | ok 2025-10-13 07:00:44.211163 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-10-13 07:00:44.229592 | 2025-10-13 07:00:44.229707 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-10-13 07:00:44.638360 | controller | ok 2025-10-13 07:00:44.647032 | 2025-10-13 07:00:44.647145 | LOOP [configure-mirrors : Include OS-specific variables] 2025-10-13 07:00:44.707822 | controller | ok: "/var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-10-13 07:00:44.719205 | 2025-10-13 07:00:44.719288 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-10-13 07:00:45.609192 | controller | changed 2025-10-13 07:00:45.615053 | 2025-10-13 07:00:45.615116 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-10-13 07:00:45.677381 | controller | ok: "/var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-10-13 07:00:45.677575 | controller | ok: All items complete 2025-10-13 07:00:45.677603 | 2025-10-13 07:00:45.720279 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-10-13 07:00:45.726989 | 2025-10-13 07:00:45.727054 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-10-13 07:00:46.645189 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-10-13 07:00:47.475428 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-10-13 07:00:47.484449 | 2025-10-13 07:00:47.484575 | TASK [configure-mirrors : Disable deltrarpm] 2025-10-13 07:00:47.899694 | controller | changed: section and option added 2025-10-13 07:00:47.930978 | 2025-10-13 07:00:47.931125 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-10-13 07:00:48.764824 | controller | 29 files removed 2025-10-13 07:00:48.765038 | controller | ok: Item: dnf clean all Runtime: 0:00:00.494775 2025-10-13 07:00:48.765079 | controller | changed: All items complete 2025-10-13 07:00:48.765099 | 2025-10-13 07:01:00.010126 | 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 07:01:00.010230 | controller | DNF version: 4.14.0 2025-10-13 07:01:00.010254 | controller | cachedir: /var/cache/dnf 2025-10-13 07:01:00.010274 | controller | Making cache files for all metadata files. 2025-10-13 07:01:00.010294 | controller | baseos: has expired and will be refreshed. 2025-10-13 07:01:00.010312 | controller | appstream: has expired and will be refreshed. 2025-10-13 07:01:00.010329 | controller | crb: has expired and will be refreshed. 2025-10-13 07:01:00.010356 | controller | extras-common: has expired and will be refreshed. 2025-10-13 07:01:00.010374 | controller | repo: downloading from remote: baseos 2025-10-13 07:01:00.010391 | controller | CentOS Stream 9 - BaseOS 71 MB/s | 8.8 MB 00:00 2025-10-13 07:01:00.010408 | controller | baseos: using metadata from Wed 08 Oct 2025 09:42:12 AM EDT. 2025-10-13 07:01:00.010424 | controller | repo: downloading from remote: appstream 2025-10-13 07:01:00.010441 | controller | CentOS Stream 9 - AppStream 80 MB/s | 25 MB 00:00 2025-10-13 07:01:00.010458 | controller | appstream: using metadata from Wed 08 Oct 2025 09:45:45 AM EDT. 2025-10-13 07:01:00.010474 | controller | repo: downloading from remote: crb 2025-10-13 07:01:00.010491 | controller | CentOS Stream 9 - CRB 65 MB/s | 7.2 MB 00:00 2025-10-13 07:01:00.010508 | controller | crb: using metadata from Wed 08 Oct 2025 09:50:07 AM EDT. 2025-10-13 07:01:00.010525 | controller | repo: downloading from remote: extras-common 2025-10-13 07:01:00.010542 | controller | CentOS Stream 9 - Extras packages 1.2 MB/s | 20 kB 00:00 2025-10-13 07:01:00.010559 | controller | extras-common: using metadata from Mon 15 Sep 2025 02:32:43 PM EDT. 2025-10-13 07:01:00.010576 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-10-13 07:01:00.010593 | controller | Completion plugin: Generating completion cache... 2025-10-13 07:01:00.010610 | controller | Metadata cache created. 2025-10-13 07:01:00.010636 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.941970 2025-10-13 07:01:00.056472 | 2025-10-13 07:01:00.056568 | PLAY RECAP 2025-10-13 07:01:00.056622 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 07:01:00.056653 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 07:01:00.056677 | 2025-10-13 07:01:00.200517 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-10-13 07:01:00.201327 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 07:01:00.775493 | 2025-10-13 07:01:00.775607 | PLAY [all] 2025-10-13 07:01:00.803792 | 2025-10-13 07:01:00.803880 | TASK [Install binary dependencies] 2025-10-13 07:01:00.857439 | controller | ok 2025-10-13 07:01:00.875719 | 2025-10-13 07:01:00.885893 | TASK [bindep : Include find tasks] 2025-10-13 07:01:00.945210 | controller | ok 2025-10-13 07:01:00.954314 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-10-13 07:01:00.961948 | 2025-10-13 07:01:00.962021 | TASK [bindep : Look for bindep.txt] 2025-10-13 07:01:01.420160 | controller | ok 2025-10-13 07:01:01.426589 | 2025-10-13 07:01:01.426651 | TASK [bindep : Define bindep_file fact] 2025-10-13 07:01:01.467482 | controller | ok 2025-10-13 07:01:01.482950 | 2025-10-13 07:01:01.483123 | TASK [bindep : Look for other-requirements.txt] 2025-10-13 07:01:01.510188 | controller | skipping: Conditional result was False 2025-10-13 07:01:01.519843 | 2025-10-13 07:01:01.519973 | TASK [bindep : Define bindep_file fact] 2025-10-13 07:01:01.559792 | controller | skipping: Conditional result was False 2025-10-13 07:01:01.566062 | 2025-10-13 07:01:01.566151 | TASK [bindep : Look for bindep fallback file] 2025-10-13 07:01:01.597778 | controller | skipping: Conditional result was False 2025-10-13 07:01:01.603848 | 2025-10-13 07:01:01.603960 | TASK [bindep : Define bindep_file fact] 2025-10-13 07:01:01.629175 | controller | skipping: Conditional result was False 2025-10-13 07:01:01.634914 | 2025-10-13 07:01:01.635000 | TASK [bindep : Include bindep tasks] 2025-10-13 07:01:01.669429 | controller | ok 2025-10-13 07:01:01.676036 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-10-13 07:01:01.683967 | 2025-10-13 07:01:01.684077 | TASK [bindep : Look for bindep command] 2025-10-13 07:01:01.714078 | controller | skipping: Conditional result was False 2025-10-13 07:01:01.721011 | 2025-10-13 07:01:01.721132 | TASK [bindep : Check for system bindep] 2025-10-13 07:01:02.256588 | controller | ok: Runtime: 0:00:00.007001 2025-10-13 07:01:02.262230 | 2025-10-13 07:01:02.262313 | TASK [bindep : Define bindep_command fact] 2025-10-13 07:01:02.286433 | controller | skipping: Conditional result was False 2025-10-13 07:01:02.292667 | 2025-10-13 07:01:02.292781 | TASK [bindep : Include install tasks] 2025-10-13 07:01:02.322710 | controller | ok 2025-10-13 07:01:02.334686 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-10-13 07:01:02.346061 | 2025-10-13 07:01:02.346141 | TASK [bindep : Create temp dir for bindep] 2025-10-13 07:01:02.754284 | controller | changed 2025-10-13 07:01:02.759514 | 2025-10-13 07:01:02.759570 | TASK [Ensure we have pip dependencies] 2025-10-13 07:01:02.780770 | controller | ok 2025-10-13 07:01:02.815858 | 2025-10-13 07:01:02.815937 | TASK [ensure-pip : Check if pip is installed] 2025-10-13 03:01:03.086794 | controller | /usr/bin/pip3 2025-10-13 03:01:03.110629 | controller | /usr/bin/python3: No module named wheel 2025-10-13 07:01:03.343635 | controller | ok: Runtime: 0:00:00.035936 2025-10-13 07:01:03.351892 | 2025-10-13 07:01:03.352110 | LOOP [ensure-pip : Install pip from packages] 2025-10-13 07:01:03.384388 | controller | ok: "/var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-10-13 07:01:03.399923 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-10-13 07:01:03.414325 | 2025-10-13 07:01:03.414537 | TASK [ensure-pip : Install Python 3 pip] 2025-10-13 07:01:05.657880 | controller | changed 2025-10-13 07:01:05.663301 | 2025-10-13 07:01:05.663361 | TASK [ensure-pip : Check for EPEL repository] 2025-10-13 07:01:05.718966 | controller | skipping: Conditional result was False 2025-10-13 07:01:05.726835 | 2025-10-13 07:01:05.726908 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-10-13 07:01:05.782211 | controller | skipping: Conditional result was False 2025-10-13 07:01:05.789132 | 2025-10-13 07:01:05.789197 | TASK [ensure-pip : Install Python 2 pip] 2025-10-13 07:01:05.823792 | controller | skipping: Conditional result was False 2025-10-13 07:01:05.831070 | 2025-10-13 07:01:05.831147 | TASK [ensure-pip : Ensure setuptools] 2025-10-13 07:01:05.858250 | controller | skipping: Conditional result was False 2025-10-13 07:01:05.864958 | 2025-10-13 07:01:05.865024 | TASK [ensure-pip : Check for ensurepip module] 2025-10-13 07:01:06.401799 | controller | skipping: Conditional result was False 2025-10-13 07:01:06.408639 | 2025-10-13 07:01:06.408716 | TASK [ensure-pip : Ensure python3-venv] 2025-10-13 07:01:06.433694 | controller | skipping: Conditional result was False 2025-10-13 07:01:06.439838 | 2025-10-13 07:01:06.439908 | TASK [ensure-pip : Install pip from source] 2025-10-13 07:01:06.454971 | controller | skipping: Conditional result was False 2025-10-13 07:01:06.461490 | 2025-10-13 07:01:06.461565 | TASK [ensure-pip : Probe for venv python full path] 2025-10-13 03:01:06.786765 | controller | /usr/bin/python3 2025-10-13 07:01:06.991796 | controller | ok: Runtime: 0:00:00.006341 2025-10-13 07:01:07.001345 | 2025-10-13 07:01:07.001638 | TASK [ensure-pip : Set host default] 2025-10-13 07:01:07.063288 | controller | ok 2025-10-13 07:01:07.068488 | 2025-10-13 07:01:07.068556 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-10-13 07:01:07.121844 | controller | ok 2025-10-13 07:01:07.136319 | 2025-10-13 07:01:07.136402 | TASK [bindep : Install bindep into temporary venv] 2025-10-13 07:01:12.131559 | controller | changed 2025-10-13 07:01:12.141786 | 2025-10-13 07:01:12.142068 | TASK [bindep : Define bindep_command] 2025-10-13 07:01:12.179876 | controller | ok 2025-10-13 07:01:12.187202 | 2025-10-13 07:01:12.187348 | LOOP [bindep : Include package tasks] 2025-10-13 07:01:12.255833 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-10-13 07:01:12.256136 | controller | ok: All items complete 2025-10-13 07:01:12.256175 | 2025-10-13 07:01:12.273498 | controller | included: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-10-13 07:01:12.285775 | 2025-10-13 07:01:12.285897 | TASK [bindep : Define bindep_run fact] 2025-10-13 07:01:12.316628 | controller | ok 2025-10-13 07:01:12.322430 | 2025-10-13 07:01:12.322550 | TASK [bindep : Get list of packages to install from bindep] 2025-10-13 03:01:13.786011 | controller | podman 2025-10-13 03:01:13.834609 | controller | python3-jmespath 2025-10-13 03:01:13.834826 | controller | python3-libvirt 2025-10-13 03:01:13.834841 | controller | python3-lxml 2025-10-13 03:01:13.834855 | controller | python3-netaddr 2025-10-13 07:01:13.880066 | controller | ok: Runtime: 0:00:01.240812 2025-10-13 07:01:13.896575 | 2025-10-13 07:01:13.896848 | TASK [bindep : Install distro packages from bindep] 2025-10-13 07:02:21.874427 | controller | changed 2025-10-13 07:02:21.880093 | 2025-10-13 07:02:21.880166 | TASK [bindep : Check that packages are installed] 2025-10-13 07:02:23.412607 | controller | ok: Runtime: 0:00:01.204028 2025-10-13 07:02:23.419655 | 2025-10-13 07:02:23.419752 | TASK [bindep : Fail if we cannot install all packages] 2025-10-13 07:02:23.455675 | controller | skipping: Conditional result was False 2025-10-13 07:02:23.469522 | 2025-10-13 07:02:23.469645 | TASK [Run test-setup role] 2025-10-13 07:02:23.493255 | controller | ok 2025-10-13 07:02:23.514410 | 2025-10-13 07:02:23.514520 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-10-13 07:02:23.737971 | controller | ok 2025-10-13 07:02:23.747870 | 2025-10-13 07:02:23.747970 | TASK [test-setup : Run tools/test-setup.sh] 2025-10-13 07:02:24.290443 | controller | skipping: Conditional result was False 2025-10-13 07:02:24.337883 | 2025-10-13 07:02:24.338103 | TASK [bindep : Remove bindep temp dir] 2025-10-13 07:02:24.730195 | controller | ok 2025-10-13 07:02:24.749709 | 2025-10-13 07:02:24.749876 | PLAY RECAP 2025-10-13 07:02:24.749939 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-10-13 07:02:24.749967 | 2025-10-13 07:02:24.861979 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-10-13 07:02:24.862834 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 07:02:25.427265 | 2025-10-13 07:02:25.427369 | PLAY [all] 2025-10-13 07:02:25.463926 | 2025-10-13 07:02:25.464004 | TASK [Abort when test_command variable is undefined] 2025-10-13 07:02:25.488355 | controller | skipping: Conditional result was False 2025-10-13 07:02:25.494993 | 2025-10-13 07:02:25.495086 | TASK [Convert test_command to list] 2025-10-13 07:02:25.545117 | controller | skipping: Conditional result was False 2025-10-13 07:02:25.554430 | 2025-10-13 07:02:25.554506 | TASK [Use test_command list] 2025-10-13 07:02:25.603184 | controller | ok 2025-10-13 07:02:25.608586 | 2025-10-13 07:02:25.608648 | LOOP [Run test_command] 2025-10-13 07:02:26.010715 | controller | no check to run 2025-10-13 07:02:26.010956 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.010483 2025-10-13 07:02:26.046801 | 2025-10-13 07:02:26.046914 | PLAY RECAP 2025-10-13 07:02:26.046979 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 07:02:26.047004 | 2025-10-13 07:02:26.139964 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-10-13 07:02:26.140824 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 07:02:27.042873 | 2025-10-13 07:02:27.043089 | PLAY [all] 2025-10-13 07:02:27.068629 | 2025-10-13 07:02:27.069006 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-10-13 07:02:27.518421 | controller | changed: non-zero return code 2025-10-13 07:02:27.524216 | 2025-10-13 07:02:27.524335 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-10-13 07:02:27.538408 | controller | skipping: Conditional result was False 2025-10-13 07:02:27.544575 | 2025-10-13 07:02:27.544668 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-10-13 07:02:27.565209 | 2025-10-13 07:02:27.565370 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-10-13 07:02:27.585380 | 2025-10-13 07:02:27.585545 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-10-13 07:02:27.599344 | controller | skipping: Conditional result was False 2025-10-13 07:02:27.605540 | 2025-10-13 07:02:27.605638 | LOOP [fetch-subunit-output : Generate subunit file] 2025-10-13 07:02:27.627238 | 2025-10-13 07:02:27.627477 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-10-13 07:02:27.641812 | controller | skipping: Conditional result was False 2025-10-13 07:02:27.648333 | 2025-10-13 07:02:27.648439 | TASK [fetch-subunit-output : Remove the temporary file] 2025-10-13 07:02:27.662366 | controller | skipping: Conditional result was False 2025-10-13 07:02:27.669580 | 2025-10-13 07:02:27.669700 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-10-13 07:02:27.684491 | controller | skipping: Conditional result was False 2025-10-13 07:02:27.709072 | 2025-10-13 07:02:27.709145 | PLAY RECAP 2025-10-13 07:02:27.709188 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-10-13 07:02:27.709210 | 2025-10-13 07:02:27.807695 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-10-13 07:02:27.808533 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 07:02:28.421031 | 2025-10-13 07:02:28.421124 | PLAY [all] 2025-10-13 07:02:28.439977 | 2025-10-13 07:02:28.440083 | TASK [include_role : fetch-output] 2025-10-13 07:02:28.489664 | controller | ok 2025-10-13 07:02:28.507865 | 2025-10-13 07:02:28.508019 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 07:02:28.554507 | controller | skipping: Conditional result was False 2025-10-13 07:02:28.560681 | 2025-10-13 07:02:28.560775 | TASK [fetch-output : Set log path for single node] 2025-10-13 07:02:28.589814 | controller | ok 2025-10-13 07:02:28.597398 | 2025-10-13 07:02:28.597521 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 07:02:28.962108 | controller -> localhost | ok: "/var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/logs" 2025-10-13 07:02:29.179983 | controller -> localhost | changed: "/var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/artifacts" 2025-10-13 07:02:29.409715 | controller -> localhost | changed: "/var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/docs" 2025-10-13 07:02:29.427356 | 2025-10-13 07:02:29.427474 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 07:02:30.035411 | controller | changed: .d..t...... ./ 2025-10-13 07:02:30.035603 | controller | changed: All items complete 2025-10-13 07:02:30.035631 | 2025-10-13 07:02:30.494660 | controller | changed: .d..t...... ./ 2025-10-13 07:02:30.963557 | controller | changed: .d..t...... ./ 2025-10-13 07:02:30.978556 | 2025-10-13 07:02:30.978685 | TASK [include_role : fetch-output-openshift] 2025-10-13 07:02:31.029544 | controller | skipping: Conditional result was False 2025-10-13 07:02:31.035947 | 2025-10-13 07:02:31.036035 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 07:02:31.474992 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.020918 2025-10-13 07:02:31.780566 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.016117 2025-10-13 07:02:31.818461 | 2025-10-13 07:02:31.818573 | PLAY [all] 2025-10-13 07:02:31.854494 | 2025-10-13 07:02:31.854609 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 07:02:32.412547 | controller | changed 2025-10-13 07:02:32.456478 | 2025-10-13 07:02:32.456566 | PLAY RECAP 2025-10-13 07:02:32.456605 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 07:02:32.456627 | 2025-10-13 07:02:32.657310 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 07:02:32.658329 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 07:02:33.308244 | 2025-10-13 07:02:33.308354 | PLAY [localhost] 2025-10-13 07:02:33.340641 | 2025-10-13 07:02:33.340773 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 07:02:33.730824 | localhost | changed 2025-10-13 07:02:33.744180 | 2025-10-13 07:02:33.744292 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 07:02:33.783999 | localhost | ok 2025-10-13 07:02:33.792530 | 2025-10-13 07:02:33.792604 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 07:02:34.167038 | localhost | changed 2025-10-13 07:02:34.173226 | 2025-10-13 07:02:34.173313 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 07:02:34.794948 | localhost | changed 2025-10-13 07:02:34.800207 | 2025-10-13 07:02:34.800270 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 07:02:35.248172 | localhost | Identity added: /var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/tmp/ansible.5vv9lbwo (/var/lib/zuul/builds/3f9637b4261149168d8c5c92950b874b/work/tmp/ansible.5vv9lbwo) 2025-10-13 07:02:35.248349 | localhost | ok: Runtime: 0:00:00.042514 2025-10-13 07:02:35.252786 | 2025-10-13 07:02:35.252852 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 07:02:35.528074 | localhost | ok: Runtime: 0:00:00.012628 2025-10-13 07:02:35.533288 | 2025-10-13 07:02:35.533357 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 07:02:35.583583 | localhost | changed 2025-10-13 07:02:35.588414 | 2025-10-13 07:02:35.588484 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 07:02:36.001932 | localhost | changed 2025-10-13 07:02:36.025653 | 2025-10-13 07:02:36.025756 | PLAY [localhost] 2025-10-13 07:02:36.045010 | 2025-10-13 07:02:36.045136 | TASK [Generate bulk log download script] 2025-10-13 07:02:36.079933 | localhost | ok 2025-10-13 07:02:36.092424 | 2025-10-13 07:02:36.092528 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 07:02:36.141082 | localhost | ok: All assertions passed 2025-10-13 07:02:36.145816 | 2025-10-13 07:02:36.145899 | TASK [local-log-download : Create download script] 2025-10-13 07:02:36.561050 | localhost -> localhost | changed 2025-10-13 07:02:36.572722 | 2025-10-13 07:02:36.572848 | TASK [Register quick-download link] 2025-10-13 07:02:36.599705 | localhost | ok 2025-10-13 07:02:36.661454 | 2025-10-13 07:02:36.661555 | PLAY [logserver.rdoproject.org] 2025-10-13 07:02:36.671404 | 2025-10-13 07:02:36.671547 | TASK [Set zuul-log-path fact] 2025-10-13 07:02:36.700921 | logserver.rdoproject.org | ok 2025-10-13 07:02:36.714970 | 2025-10-13 07:02:36.715126 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 07:02:36.755669 | logserver.rdoproject.org | ok 2025-10-13 07:02:36.762421 | 2025-10-13 07:02:36.762501 | TASK [upload-logs : Create log directories] 2025-10-13 07:02:37.450374 | logserver.rdoproject.org | changed 2025-10-13 07:02:37.453777 | 2025-10-13 07:02:37.453847 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 07:02:37.713567 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005156 2025-10-13 07:02:37.718172 | 2025-10-13 07:02:37.718527 | TASK [upload-logs : Upload logs to log server] 2025-10-13 07:02:38.376265 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 07:02:38.379205 | 2025-10-13 07:02:38.379269 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 07:02:38.439399 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:38.447899 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:38.462228 | 2025-10-13 07:02:38.462422 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 07:02:38.503613 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:38.503877 | 2025-10-13 07:02:38.512691 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 07:02:38.526789 | 2025-10-13 07:02:38.526971 | LOOP [upload-logs : Upload console log and json output]