2025-12-05 15:33:25.939466 | Job console starting... 2025-12-05 15:33:25.950153 | Updating repositories 2025-12-05 15:33:25.983478 | Preparing job workspace 2025-12-05 15:33:30.046798 | Running Ansible setup... 2025-12-05 15:33:33.935253 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:33:34.569200 | 2025-12-05 15:33:34.569299 | PLAY [localhost] 2025-12-05 15:33:34.578035 | 2025-12-05 15:33:34.578116 | TASK [Gathering Facts] 2025-12-05 15:33:35.546789 | localhost | ok 2025-12-05 15:33:35.572311 | 2025-12-05 15:33:35.572462 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 15:33:35.953462 | localhost -> localhost | changed 2025-12-05 15:33:35.961876 | 2025-12-05 15:33:35.961995 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 15:33:36.906935 | localhost -> localhost | changed 2025-12-05 15:33:36.915866 | 2025-12-05 15:33:36.915935 | TASK [Setup log path fact] 2025-12-05 15:33:36.934079 | localhost | ok 2025-12-05 15:33:36.945650 | 2025-12-05 15:33:36.945721 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:33:36.972718 | localhost | ok 2025-12-05 15:33:36.980484 | 2025-12-05 15:33:36.980548 | TASK [emit-job-header : Print job information] 2025-12-05 15:33:37.010521 | # Job Information 2025-12-05 15:33:37.010712 | Ansible Version: 2.15.12 2025-12-05 15:33:37.010759 | Job: cifmw-molecule-ci_dcn_site 2025-12-05 15:33:37.010780 | Pipeline: github-check 2025-12-05 15:33:37.010798 | Executor: ze03.softwarefactory-project.io 2025-12-05 15:33:37.010815 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3539 2025-12-05 15:33:37.010833 | Log URL (when completed): https://logserver.rdoproject.org/05a/rdoproject.org/05a438ab0ccc44589a2a77bec7ffab0f/ 2025-12-05 15:33:37.010851 | Event ID: 757b9e30-d1ef-11f0-97eb-f505e6ea5a00 2025-12-05 15:33:37.014569 | 2025-12-05 15:33:37.014638 | LOOP [emit-job-header : Print node information] 2025-12-05 15:33:37.120447 | localhost | ok: 2025-12-05 15:33:37.120653 | localhost | # Node Information 2025-12-05 15:33:37.120680 | localhost | Inventory Hostname: controller 2025-12-05 15:33:37.120705 | localhost | Hostname: np0005547414 2025-12-05 15:33:37.120747 | localhost | Username: zuul 2025-12-05 15:33:37.120773 | localhost | Distro: CentOS 9 2025-12-05 15:33:37.120791 | localhost | Provider: vexxhost-nodepool-tripleo 2025-12-05 15:33:37.120808 | localhost | Region: RegionOne 2025-12-05 15:33:37.120825 | localhost | Label: cloud-centos-9-stream-tripleo 2025-12-05 15:33:37.120841 | localhost | Product Name: OpenStack Nova 2025-12-05 15:33:37.120857 | localhost | Interface IP: 38.102.83.176 2025-12-05 15:33:37.143158 | 2025-12-05 15:33:37.143275 | PLAY [all] 2025-12-05 15:33:37.149595 | 2025-12-05 15:33:37.149660 | TASK [Gather network facts] 2025-12-05 15:33:37.629157 | controller | ok 2025-12-05 15:33:37.647439 | 2025-12-05 15:33:37.647562 | TASK [include_role : start-zuul-console] 2025-12-05 15:33:37.670760 | controller | ok 2025-12-05 15:33:37.687240 | 2025-12-05 15:33:37.687356 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 15:33:38.130292 | controller | ok 2025-12-05 15:33:38.143124 | 2025-12-05 15:33:38.143271 | TASK [include_role : add-build-sshkey] 2025-12-05 15:33:38.165230 | controller | ok 2025-12-05 15:33:38.186986 | 2025-12-05 15:33:38.187138 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 15:33:38.494386 | controller -> localhost | ok 2025-12-05 15:33:38.505111 | 2025-12-05 15:33:38.505206 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 15:33:38.535902 | controller | ok 2025-12-05 15:33:38.549187 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 15:33:38.561450 | 2025-12-05 15:33:38.561531 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 15:33:39.552937 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 15:33:39.553118 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/05a438ab0ccc44589a2a77bec7ffab0f_id_rsa. 2025-12-05 15:33:39.553147 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/05a438ab0ccc44589a2a77bec7ffab0f_id_rsa.pub. 2025-12-05 15:33:39.553169 | controller -> localhost | The key fingerprint is: 2025-12-05 15:33:39.553188 | controller -> localhost | SHA256:ursPZ8NrJTZ8Ec4YP5wB7x9BUnmSmMnD4y0dCqL81XI zuul-build-sshkey 2025-12-05 15:33:39.553209 | controller -> localhost | The key's randomart image is: 2025-12-05 15:33:39.553227 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 15:33:39.553244 | controller -> localhost | | .+.=oo | 2025-12-05 15:33:39.553263 | controller -> localhost | | . o.@o= . | 2025-12-05 15:33:39.553280 | controller -> localhost | | . . . @.X.+ | 2025-12-05 15:33:39.553297 | controller -> localhost | | o +.E o. | 2025-12-05 15:33:39.553314 | controller -> localhost | | . oSo.+. | 2025-12-05 15:33:39.553331 | controller -> localhost | | .o= o. . | 2025-12-05 15:33:39.553348 | controller -> localhost | | o.== . | 2025-12-05 15:33:39.553366 | controller -> localhost | | =.o | 2025-12-05 15:33:39.553383 | controller -> localhost | | +=o | 2025-12-05 15:33:39.553400 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 15:33:39.553467 | controller -> localhost | ok: Runtime: 0:00:00.430862 2025-12-05 15:33:39.559184 | 2025-12-05 15:33:39.559242 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 15:33:39.588473 | controller | ok 2025-12-05 15:33:39.599160 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 15:33:39.610204 | 2025-12-05 15:33:39.610285 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 15:33:39.634688 | controller | skipping: Conditional result was False 2025-12-05 15:33:39.645828 | 2025-12-05 15:33:39.645939 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 15:33:40.276470 | controller | changed 2025-12-05 15:33:40.290015 | 2025-12-05 15:33:40.290132 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 15:33:40.589361 | controller | ok 2025-12-05 15:33:40.594389 | 2025-12-05 15:33:40.594449 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 15:33:41.691556 | controller | changed 2025-12-05 15:33:41.696514 | 2025-12-05 15:33:41.696583 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 15:33:42.697994 | controller | changed 2025-12-05 15:33:42.707134 | 2025-12-05 15:33:42.707221 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 15:33:42.768582 | controller | skipping: Conditional result was False 2025-12-05 15:33:42.775453 | 2025-12-05 15:33:42.775534 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 15:33:43.673138 | controller -> localhost | changed 2025-12-05 15:33:43.684685 | 2025-12-05 15:33:43.684792 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 15:33:44.243954 | controller -> localhost | Identity added: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/05a438ab0ccc44589a2a77bec7ffab0f_id_rsa (zuul-build-sshkey) 2025-12-05 15:33:44.244161 | controller -> localhost | ok: Runtime: 0:00:00.015791 2025-12-05 15:33:44.251475 | 2025-12-05 15:33:44.251540 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 15:33:44.783749 | controller | ok 2025-12-05 15:33:44.788828 | 2025-12-05 15:33:44.788889 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 15:33:44.833233 | controller | skipping: Conditional result was False 2025-12-05 15:33:44.847312 | 2025-12-05 15:33:44.857750 | TASK [include_role : validate-host] 2025-12-05 15:33:44.876471 | controller | ok 2025-12-05 15:33:44.896782 | 2025-12-05 15:33:44.896848 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 15:33:44.984684 | controller | ok 2025-12-05 15:33:44.989277 | 2025-12-05 15:33:44.989334 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 15:33:45.284322 | controller -> localhost | ok 2025-12-05 15:33:45.290277 | 2025-12-05 15:33:45.290339 | TASK [validate-host : Collect information about the host] 2025-12-05 15:33:46.187567 | controller | ok 2025-12-05 15:33:46.205362 | 2025-12-05 15:33:46.205451 | TASK [validate-host : Sanitize hostname] 2025-12-05 15:33:46.309973 | controller | ok 2025-12-05 15:33:46.323552 | 2025-12-05 15:33:46.323672 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 15:33:47.053611 | controller -> localhost | changed 2025-12-05 15:33:47.059665 | 2025-12-05 15:33:47.059770 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 15:33:47.490186 | controller | ok 2025-12-05 15:33:47.495278 | 2025-12-05 15:33:47.495339 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 15:33:48.512273 | controller -> localhost | changed 2025-12-05 15:33:48.534553 | 2025-12-05 15:33:48.534648 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 15:33:48.573929 | controller | skipping: Conditional result was False 2025-12-05 15:33:48.578983 | 2025-12-05 15:33:48.579045 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 15:33:48.592669 | controller | skipping: Conditional result was False 2025-12-05 15:33:48.599227 | 2025-12-05 15:33:48.599304 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:33:48.881861 | controller | ok: "logs" 2025-12-05 15:33:48.882064 | controller | ok: All items complete 2025-12-05 15:33:48.882091 | 2025-12-05 15:33:49.107920 | controller | ok: "artifacts" 2025-12-05 15:33:49.385255 | controller | ok: "docs" 2025-12-05 15:33:49.392699 | 2025-12-05 15:33:49.392822 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:33:49.740671 | controller | changed: "logs" 2025-12-05 15:33:50.003516 | controller | changed: "artifacts" 2025-12-05 15:33:50.278241 | controller | changed: "docs" 2025-12-05 15:33:50.308976 | 2025-12-05 15:33:50.309057 | PLAY RECAP 2025-12-05 15:33:50.309099 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 15:33:50.309125 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:33:50.309142 | 2025-12-05 15:33:50.410805 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 15:33:50.411622 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:33:51.023835 | 2025-12-05 15:33:51.023950 | PLAY [localhost] 2025-12-05 15:33:51.039519 | 2025-12-05 15:33:51.039589 | TASK [configure-ssh-config-fips : Ensure ssh config directory] 2025-12-05 15:33:51.461173 | localhost | ok 2025-12-05 15:33:51.468424 | 2025-12-05 15:33:51.468540 | TASK [configure-ssh-config-fips : Setup ssh config] 2025-12-05 15:33:52.188252 | localhost | changed 2025-12-05 15:33:52.217786 | 2025-12-05 15:33:52.217862 | PLAY [all] 2025-12-05 15:33:52.236559 | 2025-12-05 15:33:52.236619 | TASK [include_role : prepare-workspace] 2025-12-05 15:33:52.265772 | controller | ok 2025-12-05 15:33:52.282605 | 2025-12-05 15:33:52.282674 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 15:33:53.293073 | controller | ok 2025-12-05 15:33:53.313011 | 2025-12-05 15:33:53.313253 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 15:33:55.563512 | controller | Output suppressed because no_log was given 2025-12-05 15:33:55.578444 | 2025-12-05 15:33:55.578534 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 15:33:55.899612 | controller | changed: "logs" 2025-12-05 15:33:56.158812 | controller | changed: "artifacts" 2025-12-05 15:33:56.407591 | controller | changed: "docs" 2025-12-05 15:33:56.422696 | 2025-12-05 15:33:56.422813 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 15:33:56.719925 | controller | changed: "logs" 2025-12-05 15:33:56.720607 | controller | changed: All items complete 2025-12-05 15:33:56.720658 | 2025-12-05 15:33:56.997397 | controller | changed: "artifacts" 2025-12-05 15:33:57.231236 | controller | changed: "docs" 2025-12-05 15:33:57.251247 | 2025-12-05 15:33:57.251319 | TASK [Check if worker can sudo] 2025-12-05 15:33:57.781629 | controller | ok: Runtime: 0:00:00.033505 2025-12-05 15:33:57.787178 | 2025-12-05 15:33:57.787242 | TASK [configure-mirrors : Gather needed facts] 2025-12-05 15:33:57.892444 | controller | skipping: Conditional result was False 2025-12-05 15:33:57.898438 | 2025-12-05 15:33:57.898504 | TASK [configure-mirrors : Set up infrastructure mirrors] 2025-12-05 15:33:58.031314 | controller | ok 2025-12-05 15:33:58.040127 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml 2025-12-05 15:33:58.045828 | 2025-12-05 15:33:58.045888 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir] 2025-12-05 15:33:58.350437 | controller | ok 2025-12-05 15:33:58.355922 | 2025-12-05 15:33:58.355982 | LOOP [configure-mirrors : Include OS-specific variables] 2025-12-05 15:33:58.426773 | controller | ok: "/var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml" 2025-12-05 15:33:58.436434 | 2025-12-05 15:33:58.436550 | TASK [configure-mirrors : Install /etc/pip.conf configuration] 2025-12-05 15:33:59.410258 | controller | changed 2025-12-05 15:33:59.417635 | 2025-12-05 15:33:59.417762 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors] 2025-12-05 15:33:59.471879 | controller | ok: "/var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml" 2025-12-05 15:33:59.472162 | controller | ok: All items complete 2025-12-05 15:33:59.472193 | 2025-12-05 15:33:59.526192 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml 2025-12-05 15:33:59.535953 | 2025-12-05 15:33:59.536019 | LOOP [configure-mirrors : Install CentOS 9 repository files] 2025-12-05 15:34:00.492490 | controller | changed: "etc/yum.repos.d/centos.repo" 2025-12-05 15:34:01.510207 | controller | changed: "etc/yum.repos.d/centos-addons.repo" 2025-12-05 15:34:01.530520 | 2025-12-05 15:34:01.530718 | TASK [configure-mirrors : Disable deltrarpm] 2025-12-05 15:34:02.057439 | controller | changed: section and option added 2025-12-05 15:34:02.090087 | 2025-12-05 15:34:02.090316 | LOOP [configure-mirrors : Update yum/dnf cache] 2025-12-05 15:34:02.813147 | controller | 29 files removed 2025-12-05 15:34:02.813373 | controller | ok: Item: dnf clean all Runtime: 0:00:00.316755 2025-12-05 15:34:02.813412 | controller | changed: All items complete 2025-12-05 15:34:02.813433 | 2025-12-05 15:34:13.354401 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade 2025-12-05 15:34:13.354602 | controller | DNF version: 4.14.0 2025-12-05 15:34:13.354644 | controller | cachedir: /var/cache/dnf 2025-12-05 15:34:13.354673 | controller | Making cache files for all metadata files. 2025-12-05 15:34:13.354699 | controller | baseos: has expired and will be refreshed. 2025-12-05 15:34:13.354745 | controller | appstream: has expired and will be refreshed. 2025-12-05 15:34:13.354778 | controller | crb: has expired and will be refreshed. 2025-12-05 15:34:13.354811 | controller | extras-common: has expired and will be refreshed. 2025-12-05 15:34:13.354835 | controller | repo: downloading from remote: baseos 2025-12-05 15:34:13.354859 | controller | CentOS Stream 9 - BaseOS 53 MB/s | 8.8 MB 00:00 2025-12-05 15:34:13.354881 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST. 2025-12-05 15:34:13.354904 | controller | repo: downloading from remote: appstream 2025-12-05 15:34:13.354926 | controller | CentOS Stream 9 - AppStream 79 MB/s | 25 MB 00:00 2025-12-05 15:34:13.354948 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST. 2025-12-05 15:34:13.354970 | controller | repo: downloading from remote: crb 2025-12-05 15:34:13.354992 | controller | CentOS Stream 9 - CRB 75 MB/s | 7.3 MB 00:00 2025-12-05 15:34:13.355015 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST. 2025-12-05 15:34:13.355038 | controller | repo: downloading from remote: extras-common 2025-12-05 15:34:13.355060 | controller | CentOS Stream 9 - Extras packages 1.5 MB/s | 20 kB 00:00 2025-12-05 15:34:13.355082 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT. 2025-12-05 15:34:13.355104 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)' 2025-12-05 15:34:13.355126 | controller | Completion plugin: Generating completion cache... 2025-12-05 15:34:13.355149 | controller | Metadata cache created. 2025-12-05 15:34:13.355183 | controller | ok: Item: dnf makecache -v Runtime: 0:00:10.257076 2025-12-05 15:34:13.378521 | 2025-12-05 15:34:13.378642 | PLAY RECAP 2025-12-05 15:34:13.378698 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 15:34:13.378756 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 15:34:13.378787 | 2025-12-05 15:34:13.477278 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master] 2025-12-05 15:34:13.478878 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:34:14.130034 | 2025-12-05 15:34:14.130152 | PLAY [all] 2025-12-05 15:34:14.157010 | 2025-12-05 15:34:14.157296 | TASK [Install binary dependencies] 2025-12-05 15:34:14.218884 | controller | ok 2025-12-05 15:34:14.252830 | 2025-12-05 15:34:14.252966 | TASK [bindep : Include find tasks] 2025-12-05 15:34:14.285497 | controller | ok 2025-12-05 15:34:14.306688 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-05 15:34:14.318926 | 2025-12-05 15:34:14.319040 | TASK [bindep : Look for bindep.txt] 2025-12-05 15:34:14.863248 | controller | ok 2025-12-05 15:34:14.876124 | 2025-12-05 15:34:14.876225 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:14.907846 | controller | ok 2025-12-05 15:34:14.915317 | 2025-12-05 15:34:14.915405 | TASK [bindep : Look for other-requirements.txt] 2025-12-05 15:34:14.940458 | controller | skipping: Conditional result was False 2025-12-05 15:34:14.948116 | 2025-12-05 15:34:14.948206 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:14.973406 | controller | skipping: Conditional result was False 2025-12-05 15:34:14.981104 | 2025-12-05 15:34:14.981190 | TASK [bindep : Look for bindep fallback file] 2025-12-05 15:34:15.015989 | controller | skipping: Conditional result was False 2025-12-05 15:34:15.023511 | 2025-12-05 15:34:15.023600 | TASK [bindep : Define bindep_file fact] 2025-12-05 15:34:15.058503 | controller | skipping: Conditional result was False 2025-12-05 15:34:15.066635 | 2025-12-05 15:34:15.066722 | TASK [bindep : Include bindep tasks] 2025-12-05 15:34:15.099179 | controller | ok 2025-12-05 15:34:15.111426 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml 2025-12-05 15:34:15.118993 | 2025-12-05 15:34:15.119075 | TASK [bindep : Look for bindep command] 2025-12-05 15:34:15.144213 | controller | skipping: Conditional result was False 2025-12-05 15:34:15.150651 | 2025-12-05 15:34:15.150713 | TASK [bindep : Check for system bindep] 2025-12-05 15:34:15.708479 | controller | ok: Runtime: 0:00:00.007769 2025-12-05 15:34:15.714120 | 2025-12-05 15:34:15.714183 | TASK [bindep : Define bindep_command fact] 2025-12-05 15:34:15.748211 | controller | skipping: Conditional result was False 2025-12-05 15:34:15.754055 | 2025-12-05 15:34:15.754116 | TASK [bindep : Include install tasks] 2025-12-05 15:34:15.793361 | controller | ok 2025-12-05 15:34:15.802230 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml 2025-12-05 15:34:15.813403 | 2025-12-05 15:34:15.813465 | TASK [bindep : Create temp dir for bindep] 2025-12-05 15:34:16.280208 | controller | changed 2025-12-05 15:34:16.293292 | 2025-12-05 15:34:16.293422 | TASK [Ensure we have pip dependencies] 2025-12-05 15:34:16.320547 | controller | ok 2025-12-05 15:34:16.345792 | 2025-12-05 15:34:16.345884 | TASK [ensure-pip : Check if pip is installed] 2025-12-05 10:34:16.679718 | controller | /usr/bin/pip3 2025-12-05 10:34:16.724212 | controller | /usr/bin/python3: No module named wheel 2025-12-05 15:34:16.876528 | controller | ok: Runtime: 0:00:00.062475 2025-12-05 15:34:16.882574 | 2025-12-05 15:34:16.882639 | LOOP [ensure-pip : Install pip from packages] 2025-12-05 15:34:16.925045 | controller | ok: "/var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml" 2025-12-05 15:34:16.935852 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml 2025-12-05 15:34:16.947414 | 2025-12-05 15:34:16.947482 | TASK [ensure-pip : Install Python 3 pip] 2025-12-05 15:34:18.809365 | controller | changed 2025-12-05 15:34:18.821349 | 2025-12-05 15:34:18.821475 | TASK [ensure-pip : Check for EPEL repository] 2025-12-05 15:34:18.879766 | controller | skipping: Conditional result was False 2025-12-05 15:34:18.894329 | 2025-12-05 15:34:18.894544 | TASK [ensure-pip : Fail with instructions when EPEL is not installed] 2025-12-05 15:34:18.953607 | controller | skipping: Conditional result was False 2025-12-05 15:34:18.968492 | 2025-12-05 15:34:18.968901 | TASK [ensure-pip : Install Python 2 pip] 2025-12-05 15:34:19.017019 | controller | skipping: Conditional result was False 2025-12-05 15:34:19.032197 | 2025-12-05 15:34:19.032494 | TASK [ensure-pip : Ensure setuptools] 2025-12-05 15:34:19.060105 | controller | skipping: Conditional result was False 2025-12-05 15:34:19.076139 | 2025-12-05 15:34:19.076283 | TASK [ensure-pip : Check for ensurepip module] 2025-12-05 15:34:19.623870 | controller | skipping: Conditional result was False 2025-12-05 15:34:19.637060 | 2025-12-05 15:34:19.637203 | TASK [ensure-pip : Ensure python3-venv] 2025-12-05 15:34:19.664398 | controller | skipping: Conditional result was False 2025-12-05 15:34:19.687442 | 2025-12-05 15:34:19.687603 | TASK [ensure-pip : Install pip from source] 2025-12-05 15:34:19.713235 | controller | skipping: Conditional result was False 2025-12-05 15:34:19.724214 | 2025-12-05 15:34:19.724351 | TASK [ensure-pip : Probe for venv python full path] 2025-12-05 10:34:20.022350 | controller | /usr/bin/python3 2025-12-05 15:34:20.266351 | controller | ok: Runtime: 0:00:00.005638 2025-12-05 15:34:20.274683 | 2025-12-05 15:34:20.274795 | TASK [ensure-pip : Set host default] 2025-12-05 15:34:20.358299 | controller | ok 2025-12-05 15:34:20.366105 | 2025-12-05 15:34:20.366279 | TASK [ensure-pip : Set ensure_pip_virtualenv_command] 2025-12-05 15:34:20.418690 | controller | ok 2025-12-05 15:34:20.432862 | 2025-12-05 15:34:20.432951 | TASK [bindep : Install bindep into temporary venv] 2025-12-05 15:34:24.906300 | controller | changed 2025-12-05 15:34:24.918607 | 2025-12-05 15:34:24.918703 | TASK [bindep : Define bindep_command] 2025-12-05 15:34:24.963037 | controller | ok 2025-12-05 15:34:24.970544 | 2025-12-05 15:34:24.970632 | LOOP [bindep : Include package tasks] 2025-12-05 15:34:25.056224 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt" 2025-12-05 15:34:25.056443 | controller | ok: All items complete 2025-12-05 15:34:25.056480 | 2025-12-05 15:34:25.077031 | controller | included: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml 2025-12-05 15:34:25.092215 | 2025-12-05 15:34:25.092301 | TASK [bindep : Define bindep_run fact] 2025-12-05 15:34:25.117166 | controller | ok 2025-12-05 15:34:25.124766 | 2025-12-05 15:34:25.124852 | TASK [bindep : Get list of packages to install from bindep] 2025-12-05 10:34:26.666719 | controller | podman 2025-12-05 10:34:26.713908 | controller | python3-jmespath 2025-12-05 10:34:26.714060 | controller | python3-libvirt 2025-12-05 10:34:26.714076 | controller | python3-lxml 2025-12-05 10:34:26.714088 | controller | python3-netaddr 2025-12-05 15:34:27.165202 | controller | ok: Runtime: 0:00:01.311704 2025-12-05 15:34:27.178807 | 2025-12-05 15:34:27.178968 | TASK [bindep : Install distro packages from bindep] 2025-12-05 15:35:30.592151 | controller | changed 2025-12-05 15:35:30.598260 | 2025-12-05 15:35:30.598342 | TASK [bindep : Check that packages are installed] 2025-12-05 15:35:32.667527 | controller | ok: Runtime: 0:00:01.484788 2025-12-05 15:35:32.687496 | 2025-12-05 15:35:32.687608 | TASK [bindep : Fail if we cannot install all packages] 2025-12-05 15:35:32.738612 | controller | skipping: Conditional result was False 2025-12-05 15:35:32.751717 | 2025-12-05 15:35:32.751856 | TASK [Run test-setup role] 2025-12-05 15:35:32.772637 | controller | ok 2025-12-05 15:35:32.818875 | 2025-12-05 15:35:32.818990 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-05 15:35:33.053551 | controller | ok 2025-12-05 15:35:33.060658 | 2025-12-05 15:35:33.060775 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-05 15:35:33.634414 | controller | skipping: Conditional result was False 2025-12-05 15:35:33.655313 | 2025-12-05 15:35:33.655429 | TASK [bindep : Remove bindep temp dir] 2025-12-05 15:35:34.006041 | controller | ok 2025-12-05 15:35:34.024662 | 2025-12-05 15:35:34.024771 | PLAY RECAP 2025-12-05 15:35:34.024816 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-12-05 15:35:34.024837 | 2025-12-05 15:35:34.173872 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-05 15:35:34.174701 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:35:34.838413 | 2025-12-05 15:35:34.838516 | PLAY [all] 2025-12-05 15:35:34.857867 | 2025-12-05 15:35:34.857943 | TASK [Abort when test_command variable is undefined] 2025-12-05 15:35:34.892337 | controller | skipping: Conditional result was False 2025-12-05 15:35:34.897871 | 2025-12-05 15:35:34.897947 | TASK [Convert test_command to list] 2025-12-05 15:35:34.949218 | controller | skipping: Conditional result was False 2025-12-05 15:35:34.955359 | 2025-12-05 15:35:34.955425 | TASK [Use test_command list] 2025-12-05 15:35:35.014495 | controller | ok 2025-12-05 15:35:35.019914 | 2025-12-05 15:35:35.019974 | LOOP [Run test_command] 2025-12-05 15:35:35.461689 | controller | no check to run 2025-12-05 15:35:35.461874 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.006235 2025-12-05 15:35:35.526603 | 2025-12-05 15:35:35.526706 | PLAY RECAP 2025-12-05 15:35:35.526773 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:35:35.526797 | 2025-12-05 15:35:39.069092 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master] 2025-12-05 15:35:39.070027 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:35:39.803282 | 2025-12-05 15:35:39.803457 | PLAY [all] 2025-12-05 15:35:39.833305 | 2025-12-05 15:35:39.833450 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-05 15:35:40.247418 | controller | changed: non-zero return code 2025-12-05 15:35:40.253425 | 2025-12-05 15:35:40.253498 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-05 15:35:40.267081 | controller | skipping: Conditional result was False 2025-12-05 15:35:40.273589 | 2025-12-05 15:35:40.273671 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-05 15:35:40.304667 | 2025-12-05 15:35:40.304923 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-05 15:35:40.326614 | 2025-12-05 15:35:40.326840 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-05 15:35:40.354214 | controller | skipping: Conditional result was False 2025-12-05 15:35:40.365839 | 2025-12-05 15:35:40.365970 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-05 15:35:40.400415 | 2025-12-05 15:35:40.400658 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-05 15:35:40.431899 | controller | skipping: Conditional result was False 2025-12-05 15:35:40.438393 | 2025-12-05 15:35:40.438523 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-05 15:35:40.484398 | controller | skipping: Conditional result was False 2025-12-05 15:35:40.491152 | 2025-12-05 15:35:40.491278 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-05 15:35:40.531873 | controller | skipping: Conditional result was False 2025-12-05 15:35:40.593336 | 2025-12-05 15:35:40.593439 | PLAY RECAP 2025-12-05 15:35:40.593482 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-05 15:35:40.593502 | 2025-12-05 15:35:40.723554 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-05 15:35:40.724518 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:35:41.614139 | 2025-12-05 15:35:41.614346 | PLAY [all] 2025-12-05 15:35:41.659187 | 2025-12-05 15:35:41.659330 | TASK [include_role : fetch-output] 2025-12-05 15:35:41.746382 | controller | ok 2025-12-05 15:35:41.801398 | 2025-12-05 15:35:41.801541 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 15:35:41.907772 | controller | skipping: Conditional result was False 2025-12-05 15:35:41.913912 | 2025-12-05 15:35:41.913996 | TASK [fetch-output : Set log path for single node] 2025-12-05 15:35:41.971625 | controller | ok 2025-12-05 15:35:41.980152 | 2025-12-05 15:35:41.980266 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 15:35:42.453794 | controller -> localhost | ok: "/var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/logs" 2025-12-05 15:35:42.691825 | controller -> localhost | changed: "/var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/artifacts" 2025-12-05 15:35:42.934227 | controller -> localhost | changed: "/var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/docs" 2025-12-05 15:35:42.951504 | 2025-12-05 15:35:42.951633 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 15:35:43.717119 | controller | changed: .d..t...... ./ 2025-12-05 15:35:43.717349 | controller | changed: All items complete 2025-12-05 15:35:43.717377 | 2025-12-05 15:35:44.369937 | controller | changed: .d..t...... ./ 2025-12-05 15:35:45.006880 | controller | changed: .d..t...... ./ 2025-12-05 15:35:45.026856 | 2025-12-05 15:35:45.026978 | TASK [include_role : fetch-output-openshift] 2025-12-05 15:35:45.063334 | controller | skipping: Conditional result was False 2025-12-05 15:35:45.069504 | 2025-12-05 15:35:45.069600 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 15:35:45.532774 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009571 2025-12-05 15:35:45.905696 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.025829 2025-12-05 15:35:45.943398 | 2025-12-05 15:35:45.943559 | PLAY [all] 2025-12-05 15:35:45.967671 | 2025-12-05 15:35:45.968499 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 15:35:46.458585 | controller | changed 2025-12-05 15:35:46.530744 | 2025-12-05 15:35:46.530865 | PLAY RECAP 2025-12-05 15:35:46.530918 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 15:35:46.530940 | 2025-12-05 15:35:46.728063 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 15:35:46.728926 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 15:35:47.583514 | 2025-12-05 15:35:47.583650 | PLAY [localhost] 2025-12-05 15:35:47.602996 | 2025-12-05 15:35:47.603128 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 15:35:48.113922 | localhost | changed 2025-12-05 15:35:48.118890 | 2025-12-05 15:35:48.118966 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 15:35:48.173259 | localhost | ok 2025-12-05 15:35:48.181296 | 2025-12-05 15:35:48.181366 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 15:35:48.936576 | localhost | changed 2025-12-05 15:35:48.941582 | 2025-12-05 15:35:48.941649 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 15:35:50.243331 | localhost | changed 2025-12-05 15:35:50.248790 | 2025-12-05 15:35:50.248898 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 15:35:50.815103 | localhost | Identity added: /var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/tmp/ansible.c9ib_x4f (/var/lib/zuul/builds/05a438ab0ccc44589a2a77bec7ffab0f/work/tmp/ansible.c9ib_x4f) 2025-12-05 15:35:50.815331 | localhost | ok: Runtime: 0:00:00.028214 2025-12-05 15:35:50.821478 | 2025-12-05 15:35:50.821569 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 15:35:51.216289 | localhost | ok: Runtime: 0:00:00.007203 2025-12-05 15:35:51.221966 | 2025-12-05 15:35:51.222028 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 15:35:51.301066 | localhost | changed 2025-12-05 15:35:51.305867 | 2025-12-05 15:35:51.305930 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 15:35:51.694952 | localhost | changed 2025-12-05 15:35:51.715571 | 2025-12-05 15:35:51.715630 | PLAY [localhost] 2025-12-05 15:35:51.727429 | 2025-12-05 15:35:51.727487 | TASK [Generate bulk log download script] 2025-12-05 15:35:51.744908 | localhost | ok 2025-12-05 15:35:51.756917 | 2025-12-05 15:35:51.756985 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 15:35:51.794334 | localhost | ok: All assertions passed 2025-12-05 15:35:51.798911 | 2025-12-05 15:35:51.798969 | TASK [local-log-download : Create download script] 2025-12-05 15:35:52.354204 | localhost -> localhost | changed 2025-12-05 15:35:52.405906 | 2025-12-05 15:35:52.406393 | TASK [Register quick-download link] 2025-12-05 15:35:52.434893 | localhost | ok 2025-12-05 15:35:52.452762 | 2025-12-05 15:35:52.452877 | PLAY [logserver.rdoproject.org] 2025-12-05 15:35:52.464592 | 2025-12-05 15:35:52.464722 | TASK [Set zuul-log-path fact] 2025-12-05 15:35:52.482697 | logserver.rdoproject.org | ok 2025-12-05 15:35:52.496890 | 2025-12-05 15:35:52.497384 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 15:35:52.524558 | logserver.rdoproject.org | ok 2025-12-05 15:35:52.531455 | 2025-12-05 15:35:52.531565 | TASK [upload-logs : Create log directories] 2025-12-05 15:35:53.163027 | logserver.rdoproject.org | changed 2025-12-05 15:35:53.166543 | 2025-12-05 15:35:53.166629 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 15:35:53.595606 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.007872 2025-12-05 15:35:53.600430 | 2025-12-05 15:35:53.600498 | TASK [upload-logs : Upload logs to log server] 2025-12-05 15:35:54.427062 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 15:35:54.430313 | 2025-12-05 15:35:54.430375 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 15:35:54.493562 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.494355 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.503758 | 2025-12-05 15:35:54.503869 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 15:35:54.580345 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.580595 | 2025-12-05 15:35:54.581124 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 15:35:54.586512 | 2025-12-05 15:35:54.586625 | LOOP [upload-logs : Upload console log and json output]