2026-01-21 00:13:12.779743 | Job console starting... 2026-01-21 00:13:12.789366 | Updating repositories 2026-01-21 00:13:12.929077 | Preparing job workspace 2026-01-21 00:13:16.754183 | Running Ansible setup... 2026-01-21 00:13:21.778409 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-21 00:13:22.435580 | 2026-01-21 00:13:22.435757 | PLAY [localhost] 2026-01-21 00:13:22.444848 | 2026-01-21 00:13:22.444961 | TASK [Gathering Facts] 2026-01-21 00:13:23.462763 | localhost | ok 2026-01-21 00:13:23.476670 | 2026-01-21 00:13:23.476802 | TASK [Setup log path fact] 2026-01-21 00:13:23.511104 | localhost | ok 2026-01-21 00:13:23.524530 | 2026-01-21 00:13:23.524623 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-21 00:13:23.563357 | localhost | ok 2026-01-21 00:13:23.571373 | 2026-01-21 00:13:23.571465 | TASK [emit-job-header : Print job information] 2026-01-21 00:13:23.610458 | # Job Information 2026-01-21 00:13:23.610617 | Ansible Version: 2.15.12 2026-01-21 00:13:23.610649 | Job: ansible-test-sanity-docker-devel 2026-01-21 00:13:23.610671 | Pipeline: periodic 2026-01-21 00:13:23.610720 | Executor: ze04.softwarefactory-project.io 2026-01-21 00:13:23.610741 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-21 00:13:23.610768 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/88b/ansible/88b6fa2a45ac44438dc083f72f58d9d7/ 2026-01-21 00:13:23.610796 | Event ID: 08cfdb9560914df89453f509f8798614 2026-01-21 00:13:23.614872 | 2026-01-21 00:13:23.614957 | LOOP [emit-job-header : Print node information] 2026-01-21 00:13:23.741844 | localhost | ok: 2026-01-21 00:13:23.742127 | localhost | # Node Information 2026-01-21 00:13:23.742165 | localhost | Inventory Hostname: controller 2026-01-21 00:13:23.742194 | localhost | Hostname: np0005589746 2026-01-21 00:13:23.742221 | localhost | Username: zuul 2026-01-21 00:13:23.742255 | localhost | Distro: Fedora 37 2026-01-21 00:13:23.742282 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-01-21 00:13:23.742307 | localhost | Region: ca-ymq-1 2026-01-21 00:13:23.742332 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-21 00:13:23.742356 | localhost | Product Name: OpenStack Nova 2026-01-21 00:13:23.742380 | localhost | Interface IP: 162.253.55.227 2026-01-21 00:13:23.759781 | 2026-01-21 00:13:23.759928 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-21 00:13:24.199912 | localhost -> localhost | changed 2026-01-21 00:13:24.212626 | 2026-01-21 00:13:24.212828 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-21 00:13:25.066558 | localhost -> localhost | changed 2026-01-21 00:13:25.089065 | 2026-01-21 00:13:25.089147 | PLAY [all:!appliance*] 2026-01-21 00:13:25.108013 | 2026-01-21 00:13:25.108146 | TASK [include_role : start-zuul-console] 2026-01-21 00:13:25.127720 | controller | ok 2026-01-21 00:13:25.142713 | 2026-01-21 00:13:25.142795 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-21 00:13:25.501210 | controller | ok 2026-01-21 00:13:25.518528 | 2026-01-21 00:13:25.518737 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-21 00:13:26.520648 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-21 00:13:26.531538 | 2026-01-21 00:13:26.531712 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-21 00:13:27.082416 | controller | skipping: Conditional result was False 2026-01-21 00:13:27.089181 | 2026-01-21 00:13:27.089274 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-21 00:13:27.123736 | controller | skipping: Conditional result was False 2026-01-21 00:13:27.130371 | 2026-01-21 00:13:27.130445 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-21 00:13:27.155341 | controller | skipping: Conditional result was False 2026-01-21 00:13:27.164007 | 2026-01-21 00:13:27.164104 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-21 00:13:27.188512 | controller | skipping: Conditional result was False 2026-01-21 00:13:27.196253 | 2026-01-21 00:13:27.196388 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-21 00:13:27.221197 | controller | skipping: Conditional result was False 2026-01-21 00:13:27.230384 | 2026-01-21 00:13:27.230533 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-21 00:13:27.255758 | controller | skipping: Conditional result was False 2026-01-21 00:13:27.270005 | 2026-01-21 00:13:27.270133 | TASK [Disable Fedora Modular] 2026-01-21 00:13:27.513326 | controller | changed 2026-01-21 00:13:27.519910 | 2026-01-21 00:13:27.520236 | TASK [Enable EPEL] 2026-01-21 00:13:27.535941 | controller | skipping: Conditional result was False 2026-01-21 00:13:27.543559 | 2026-01-21 00:13:27.543647 | TASK [Register the RHEL node] 2026-01-21 00:13:28.084749 | 2026-01-21 00:13:28.084927 | TASK [Show the subscription-manager status] 2026-01-21 00:13:28.652456 | controller | skipping: Conditional result was False 2026-01-21 00:13:28.659322 | 2026-01-21 00:13:28.659415 | TASK [Enable EPEL on RHEL] 2026-01-21 00:13:29.195138 | controller | skipping: Conditional result was False 2026-01-21 00:13:29.210601 | 2026-01-21 00:13:29.210838 | TASK [Install git and tox] 2026-01-21 00:14:50.807414 | controller | changed 2026-01-21 00:14:50.815115 | 2026-01-21 00:14:50.815405 | TASK [include_role : prepare-workspace] 2026-01-21 00:14:50.836789 | controller | ok 2026-01-21 00:14:50.861019 | 2026-01-21 00:14:50.861143 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-21 00:14:51.085828 | controller | ok 2026-01-21 00:14:51.095392 | 2026-01-21 00:14:51.095493 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-21 00:15:03.911065 | controller | Output suppressed because no_log was given 2026-01-21 00:15:03.925400 | 2026-01-21 00:15:03.925484 | TASK [include_role : prepare-workspace-openshift] 2026-01-21 00:15:03.952993 | controller | skipping: Conditional result was False 2026-01-21 00:15:04.020454 | 2026-01-21 00:15:04.020605 | PLAY [all:!appliance] 2026-01-21 00:15:04.057699 | 2026-01-21 00:15:04.057850 | TASK [Run add-build-sshkey role (RSA)] 2026-01-21 00:15:04.082638 | controller | ok 2026-01-21 00:15:04.104022 | 2026-01-21 00:15:04.104132 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-21 00:15:04.342472 | controller -> localhost | ok 2026-01-21 00:15:04.349125 | 2026-01-21 00:15:04.349188 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-21 00:15:04.389722 | controller | ok 2026-01-21 00:15:04.404031 | controller | included: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-21 00:15:04.409968 | 2026-01-21 00:15:04.410031 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-21 00:15:04.976480 | controller -> localhost | Generating public/private rsa key pair. 2026-01-21 00:15:04.976673 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/88b6fa2a45ac44438dc083f72f58d9d7_id_rsa. 2026-01-21 00:15:04.976730 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/88b6fa2a45ac44438dc083f72f58d9d7_id_rsa.pub. 2026-01-21 00:15:04.976756 | controller -> localhost | The key fingerprint is: 2026-01-21 00:15:04.976778 | controller -> localhost | SHA256:SZza92Kw5wbgJsQgzEHdjFEp7tJmWdEeOx0vn3M+SNM zuul-build-sshkey 2026-01-21 00:15:04.976798 | controller -> localhost | The key's randomart image is: 2026-01-21 00:15:04.976818 | controller -> localhost | +---[RSA 2048]----+ 2026-01-21 00:15:04.976837 | controller -> localhost | |+oo.*.o | 2026-01-21 00:15:04.976856 | controller -> localhost | |.o.+ = + o | 2026-01-21 00:15:04.976875 | controller -> localhost | | ..o. o B o | 2026-01-21 00:15:04.976894 | controller -> localhost | | .o..B + . | 2026-01-21 00:15:04.976914 | controller -> localhost | | o.o...S + o | 2026-01-21 00:15:04.976942 | controller -> localhost | | . *. o .+ B E | 2026-01-21 00:15:04.976969 | controller -> localhost | | + o ..= B | 2026-01-21 00:15:04.976990 | controller -> localhost | | +.o o | 2026-01-21 00:15:04.977010 | controller -> localhost | | .. . | 2026-01-21 00:15:04.977032 | controller -> localhost | +----[SHA256]-----+ 2026-01-21 00:15:04.977080 | controller -> localhost | ok: Runtime: 0:00:00.168819 2026-01-21 00:15:04.984124 | 2026-01-21 00:15:04.984210 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-21 00:15:05.015346 | controller | ok 2026-01-21 00:15:05.027957 | controller | included: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-21 00:15:05.038327 | 2026-01-21 00:15:05.038431 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-21 00:15:05.063432 | controller | skipping: Conditional result was False 2026-01-21 00:15:05.071348 | 2026-01-21 00:15:05.071548 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-21 00:15:05.558451 | controller | changed 2026-01-21 00:15:05.572108 | 2026-01-21 00:15:05.572259 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-21 00:15:05.797158 | controller | ok 2026-01-21 00:15:05.810722 | 2026-01-21 00:15:05.810979 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-21 00:15:06.426299 | controller | changed 2026-01-21 00:15:06.434204 | 2026-01-21 00:15:06.434293 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-21 00:15:07.073456 | controller | changed 2026-01-21 00:15:07.085616 | 2026-01-21 00:15:07.085816 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-21 00:15:07.111671 | controller | skipping: Conditional result was False 2026-01-21 00:15:07.119009 | 2026-01-21 00:15:07.119094 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-21 00:15:07.552431 | controller -> localhost | changed 2026-01-21 00:15:07.577669 | 2026-01-21 00:15:07.577876 | TASK [add-build-sshkey : Add back temp key] 2026-01-21 00:15:07.911091 | controller -> localhost | Identity added: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/88b6fa2a45ac44438dc083f72f58d9d7_id_rsa (zuul-build-sshkey) 2026-01-21 00:15:07.911366 | controller -> localhost | ok: Runtime: 0:00:00.012312 2026-01-21 00:15:07.920843 | 2026-01-21 00:15:07.920955 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-21 00:15:08.262659 | controller | ok 2026-01-21 00:15:08.284117 | 2026-01-21 00:15:08.284328 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-21 00:15:08.311605 | controller | skipping: Conditional result was False 2026-01-21 00:15:08.328716 | 2026-01-21 00:15:08.328919 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-21 00:15:08.352421 | controller | ok 2026-01-21 00:15:08.378573 | 2026-01-21 00:15:08.378734 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-21 00:15:08.607970 | controller -> localhost | ok 2026-01-21 00:15:08.617780 | 2026-01-21 00:15:08.617909 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-21 00:15:08.650975 | controller | ok 2026-01-21 00:15:08.681265 | controller | included: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-21 00:15:08.692386 | 2026-01-21 00:15:08.692536 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-21 00:15:09.034866 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-21 00:15:09.035092 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/88b6fa2a45ac44438dc083f72f58d9d7_id_ecdsa. 2026-01-21 00:15:09.035124 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/88b6fa2a45ac44438dc083f72f58d9d7_id_ecdsa.pub. 2026-01-21 00:15:09.035157 | controller -> localhost | The key fingerprint is: 2026-01-21 00:15:09.035178 | controller -> localhost | SHA256:8S2VAwyhPY19Tm60T+YLt8DopBam3kAov/XJEJGOPl8 zuul-build-sshkey 2026-01-21 00:15:09.035198 | controller -> localhost | The key's randomart image is: 2026-01-21 00:15:09.035218 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-21 00:15:09.035242 | controller -> localhost | | o+. | 2026-01-21 00:15:09.035263 | controller -> localhost | | + +.. . | 2026-01-21 00:15:09.035282 | controller -> localhost | | + = o B | 2026-01-21 00:15:09.035301 | controller -> localhost | | + . + O o | 2026-01-21 00:15:09.035319 | controller -> localhost | | . o + S o * o | 2026-01-21 00:15:09.035338 | controller -> localhost | | + . .o = = | 2026-01-21 00:15:09.035357 | controller -> localhost | | + +oE.o + + | 2026-01-21 00:15:09.035376 | controller -> localhost | | =.B.= + o | 2026-01-21 00:15:09.035395 | controller -> localhost | | ..o.* . o | 2026-01-21 00:15:09.035415 | controller -> localhost | +----[SHA256]-----+ 2026-01-21 00:15:09.035464 | controller -> localhost | ok: Runtime: 0:00:00.011398 2026-01-21 00:15:09.052201 | 2026-01-21 00:15:09.064852 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-21 00:15:09.097671 | controller | ok 2026-01-21 00:15:09.108133 | controller | included: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-21 00:15:09.118239 | 2026-01-21 00:15:09.118324 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-21 00:15:09.132890 | controller | skipping: Conditional result was False 2026-01-21 00:15:09.143197 | 2026-01-21 00:15:09.143323 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-21 00:15:09.399185 | controller | changed 2026-01-21 00:15:09.413270 | 2026-01-21 00:15:09.413408 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-21 00:15:09.643485 | controller | ok 2026-01-21 00:15:09.654122 | 2026-01-21 00:15:09.654245 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-21 00:15:10.243344 | controller | changed 2026-01-21 00:15:10.256914 | 2026-01-21 00:15:10.257109 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-21 00:15:10.899667 | controller | changed 2026-01-21 00:15:10.911268 | 2026-01-21 00:15:10.911363 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-21 00:15:10.946768 | controller | skipping: Conditional result was False 2026-01-21 00:15:10.962896 | 2026-01-21 00:15:10.963041 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-21 00:15:11.255343 | controller -> localhost | changed 2026-01-21 00:15:11.309692 | 2026-01-21 00:15:11.309817 | TASK [add-build-sshkey : Add back temp key] 2026-01-21 00:15:11.569165 | controller -> localhost | Identity added: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/88b6fa2a45ac44438dc083f72f58d9d7_id_ecdsa (zuul-build-sshkey) 2026-01-21 00:15:11.569588 | controller -> localhost | ok: Runtime: 0:00:00.007021 2026-01-21 00:15:11.585557 | 2026-01-21 00:15:11.585779 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-21 00:15:11.791834 | controller | ok 2026-01-21 00:15:11.800303 | 2026-01-21 00:15:11.800462 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-21 00:15:11.836263 | controller | skipping: Conditional result was False 2026-01-21 00:15:11.856335 | 2026-01-21 00:15:11.856464 | TASK [include_role : remove-zuul-sshkey] 2026-01-21 00:15:11.871901 | controller | skipping: Conditional result was False 2026-01-21 00:15:11.879824 | 2026-01-21 00:15:11.879907 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-21 00:15:12.105952 | controller | ok: "logs" 2026-01-21 00:15:12.106334 | controller | ok: All items complete 2026-01-21 00:15:12.106365 | 2026-01-21 00:15:12.291227 | controller | ok: "artifacts" 2026-01-21 00:15:12.474816 | controller | ok: "docs" 2026-01-21 00:15:12.488344 | 2026-01-21 00:15:12.488531 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-21 00:15:12.723401 | controller | changed: "logs" 2026-01-21 00:15:12.931088 | controller | changed: "artifacts" 2026-01-21 00:15:13.133557 | controller | changed: "docs" 2026-01-21 00:15:13.200357 | 2026-01-21 00:15:13.200524 | PLAY RECAP 2026-01-21 00:15:13.200586 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-21 00:15:13.200622 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-21 00:15:13.200647 | 2026-01-21 00:15:13.344439 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-21 00:15:13.347207 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-21 00:15:14.062790 | 2026-01-21 00:15:14.062931 | PLAY [all] 2026-01-21 00:15:14.088986 | 2026-01-21 00:15:14.089134 | TASK [Install binary dependencies] 2026-01-21 00:15:14.161093 | controller | ok 2026-01-21 00:15:14.182407 | 2026-01-21 00:15:14.182515 | TASK [bindep : Include find tasks] 2026-01-21 00:15:14.225111 | controller | ok 2026-01-21 00:15:14.234666 | controller | included: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-21 00:15:14.241550 | 2026-01-21 00:15:14.241624 | TASK [bindep : Look for bindep.txt] 2026-01-21 00:15:14.630517 | controller | ok 2026-01-21 00:15:14.636905 | 2026-01-21 00:15:14.636992 | TASK [bindep : Define bindep_file fact] 2026-01-21 00:15:14.661052 | controller | skipping: Conditional result was False 2026-01-21 00:15:14.671246 | 2026-01-21 00:15:14.671383 | TASK [bindep : Look for other-requirements.txt] 2026-01-21 00:15:14.886252 | controller | ok 2026-01-21 00:15:14.895495 | 2026-01-21 00:15:14.895602 | TASK [bindep : Define bindep_file fact] 2026-01-21 00:15:14.933399 | controller | skipping: Conditional result was False 2026-01-21 00:15:14.943658 | 2026-01-21 00:15:14.943804 | TASK [bindep : Look for bindep fallback file] 2026-01-21 00:15:14.980162 | controller | skipping: Conditional result was False 2026-01-21 00:15:14.994317 | 2026-01-21 00:15:14.994436 | TASK [bindep : Define bindep_file fact] 2026-01-21 00:15:15.021165 | controller | skipping: Conditional result was False 2026-01-21 00:15:15.031862 | 2026-01-21 00:15:15.031972 | TASK [bindep : Include bindep tasks] 2026-01-21 00:15:15.058197 | controller | skipping: Conditional result was False 2026-01-21 00:15:15.067856 | 2026-01-21 00:15:15.067987 | TASK [bindep : Include install tasks] 2026-01-21 00:15:15.094313 | controller | skipping: Conditional result was False 2026-01-21 00:15:15.104039 | 2026-01-21 00:15:15.104137 | LOOP [bindep : Include package tasks] 2026-01-21 00:15:15.186140 | 2026-01-21 00:15:15.186430 | TASK [Run test-setup role] 2026-01-21 00:15:15.215854 | controller | ok 2026-01-21 00:15:15.243136 | 2026-01-21 00:15:15.243268 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-21 00:20:26.130482 | controller | ok 2026-01-21 00:20:26.146447 | 2026-01-21 00:20:26.146621 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-21 00:20:26.700088 | controller | skipping: Conditional result was False 2026-01-21 00:20:26.777190 | 2026-01-21 00:20:26.777494 | PLAY RECAP 2026-01-21 00:20:26.777566 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-21 00:20:26.777597 | 2026-01-21 00:20:26.962237 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-21 00:20:26.963194 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-21 00:20:27.595412 | 2026-01-21 00:20:27.595576 | PLAY [controller] 2026-01-21 00:20:27.618341 | 2026-01-21 00:20:27.618470 | TASK [Create the /root directory] 2026-01-21 00:20:28.169947 | controller | ok 2026-01-21 00:20:28.182491 | 2026-01-21 00:20:28.182673 | TASK [Install glibc-langpack-en] 2026-01-21 00:20:32.094938 | controller | ok: Nothing to do 2026-01-21 00:20:32.105635 | 2026-01-21 00:20:32.105853 | TASK [Ensure controller directory exists] 2026-01-21 00:20:32.331415 | controller | changed 2026-01-21 00:20:32.339248 | 2026-01-21 00:20:32.339346 | TASK [Install container runtime] 2026-01-21 00:20:32.414311 | controller | ok 2026-01-21 00:20:32.507388 | 2026-01-21 00:20:32.507510 | LOOP [ensure-podman : Find distribution installation] 2026-01-21 00:20:32.550758 | controller | ok: "/var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-21 00:20:32.561930 | controller | included: /var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-21 00:20:32.568325 | 2026-01-21 00:20:32.568390 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-21 00:21:37.217830 | controller | changed 2026-01-21 00:21:37.224840 | 2026-01-21 00:21:37.224957 | TASK [ensure-podman : Fetch podman version] 2026-01-21 00:21:37.762503 | controller | Client: Podman Engine 2026-01-21 00:21:37.789676 | controller | Version: 4.6.2 2026-01-21 00:21:37.789712 | controller | API Version: 4.6.2 2026-01-21 00:21:37.789720 | controller | Go Version: go1.19.12 2026-01-21 00:21:37.789740 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-21 00:21:37.789748 | controller | OS/Arch: linux/amd64 2026-01-21 00:21:38.264082 | controller | ok: Runtime: 0:00:00.200691 2026-01-21 00:21:38.273323 | 2026-01-21 00:21:38.273454 | TASK [ensure-podman : Print podman version installed] 2026-01-21 00:21:38.307939 | Podman version: Client: Podman Engine 2026-01-21 00:21:38.308121 | Version: 4.6.2 2026-01-21 00:21:38.308162 | API Version: 4.6.2 2026-01-21 00:21:38.308192 | Go Version: go1.19.12 2026-01-21 00:21:38.308219 | Built: Mon Aug 28 19:38:31 2023 2026-01-21 00:21:38.308246 | OS/Arch: linux/amd64 2026-01-21 00:21:38.316755 | 2026-01-21 00:21:38.316911 | TASK [ensure-podman : Validate podman engine] 2026-01-21 00:21:38.862102 | controller | skipping: Conditional result was False 2026-01-21 00:21:38.873423 | 2026-01-21 00:21:38.873557 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-21 00:21:38.890370 | controller | skipping: Conditional result was False 2026-01-21 00:21:38.908091 | 2026-01-21 00:21:38.908225 | TASK [Ensure python3.8 is present] 2026-01-21 00:21:38.923611 | controller | skipping: Conditional result was False 2026-01-21 00:21:38.936014 | 2026-01-21 00:21:38.936143 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-21 00:21:38.959800 | controller | ok 2026-01-21 00:21:38.986916 | 2026-01-21 00:21:38.987069 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-21 00:21:40.410619 | controller | ok: Nothing to do 2026-01-21 00:21:40.416409 | 2026-01-21 00:21:40.416473 | TASK [our-ensure-python : Also install python3-devel] 2026-01-21 00:21:49.132182 | controller | changed 2026-01-21 00:21:49.146321 | 2026-01-21 00:21:49.146477 | TASK [Run ensure-virtualenv role] 2026-01-21 00:21:49.177392 | controller | ok 2026-01-21 00:21:49.202854 | 2026-01-21 00:21:49.202989 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-21 00:21:49.413531 | controller | /usr/bin/virtualenv 2026-01-21 00:21:49.747446 | controller | ok: Runtime: 0:00:00.004796 2026-01-21 00:21:49.757474 | 2026-01-21 00:21:49.757617 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-21 00:21:49.783391 | controller | skipping: Conditional result was False 2026-01-21 00:21:49.783860 | controller | ok: All items complete 2026-01-21 00:21:49.783913 | 2026-01-21 00:21:49.811127 | 2026-01-21 00:21:49.811286 | TASK [Find the full path of the Python interpreter] 2026-01-21 00:21:50.071729 | controller | /usr/bin/python3 2026-01-21 00:21:50.389981 | controller | ok 2026-01-21 00:21:50.405119 | 2026-01-21 00:21:50.405312 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-21 00:21:51.351354 | controller | created virtual environment CPython3.11.0.final.0-64 in 513ms 2026-01-21 00:21:51.378877 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-21 00:21:51.378917 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2026-01-21 00:21:51.378926 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-21 00:21:51.378940 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-21 00:21:51.464401 | controller | changed 2026-01-21 00:21:51.473497 | 2026-01-21 00:21:51.473596 | TASK [Set selinux package] 2026-01-21 00:21:51.507001 | controller | ok 2026-01-21 00:21:51.514715 | 2026-01-21 00:21:51.514804 | TASK [Set selinux package (Fedora)] 2026-01-21 00:21:51.558334 | controller | ok 2026-01-21 00:21:51.565802 | 2026-01-21 00:21:51.565902 | TASK [Install selinux into virtualenv] 2026-01-21 00:21:52.864326 | controller | Collecting selinux-please-lie-to-me 2026-01-21 00:21:52.903466 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-21 00:21:53.199975 | controller | Collecting setuptools<50.0.0 2026-01-21 00:21:53.207746 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-21 00:21:53.244736 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 23.9 MB/s eta 0:00:00 2026-01-21 00:21:53.325378 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-21 00:21:53.325570 | controller | Attempting uninstall: setuptools 2026-01-21 00:21:53.328018 | controller | Found existing installation: setuptools 62.6.0 2026-01-21 00:21:53.387274 | controller | Uninstalling setuptools-62.6.0: 2026-01-21 00:21:53.395277 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-21 00:21:53.734540 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-21 00:21:53.873597 | controller | 2026-01-21 00:21:53.957290 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-21 00:21:53.957304 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-21 00:21:54.111410 | controller | ok: Runtime: 0:00:02.163700 2026-01-21 00:21:54.119366 | 2026-01-21 00:21:54.119442 | TASK [Install pytest-forked into virtualenv] 2026-01-21 00:21:54.701879 | controller | Collecting pytest-forked 2026-01-21 00:21:54.739951 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-21 00:21:54.805171 | controller | Collecting py 2026-01-21 00:21:54.811500 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-21 00:21:54.831474 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.1 MB/s eta 0:00:00 2026-01-21 00:21:54.930775 | controller | Collecting pytest>=3.10 2026-01-21 00:21:54.934945 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-21 00:21:54.950045 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 29.6 MB/s eta 0:00:00 2026-01-21 00:21:55.012580 | controller | Collecting iniconfig>=1.0.1 2026-01-21 00:21:55.016085 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-21 00:21:55.066067 | controller | Collecting packaging>=22 2026-01-21 00:21:55.072624 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-21 00:21:55.080846 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.6 MB/s eta 0:00:00 2026-01-21 00:21:55.113514 | controller | Collecting pluggy<2,>=1.5 2026-01-21 00:21:55.120006 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-21 00:21:55.169562 | controller | Collecting pygments>=2.7.2 2026-01-21 00:21:55.173812 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-21 00:21:55.209026 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 43.7 MB/s eta 0:00:00 2026-01-21 00:21:55.276752 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-21 00:21:56.405015 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-01-21 00:21:56.413596 | controller | 2026-01-21 00:21:56.482429 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-21 00:21:56.482471 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-21 00:21:56.678645 | controller | ok: Runtime: 0:00:02.146115 2026-01-21 00:21:56.686777 | 2026-01-21 00:21:56.686886 | TASK [Update pip] 2026-01-21 00:21:57.211047 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-21 00:21:57.343382 | controller | Collecting pip 2026-01-21 00:21:57.758056 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-21 00:21:57.805652 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 40.2 MB/s eta 0:00:00 2026-01-21 00:21:57.870951 | controller | Installing collected packages: pip 2026-01-21 00:21:57.871161 | controller | Attempting uninstall: pip 2026-01-21 00:21:57.873351 | controller | Found existing installation: pip 22.2.2 2026-01-21 00:21:58.006874 | controller | Uninstalling pip-22.2.2: 2026-01-21 00:21:58.021647 | controller | Successfully uninstalled pip-22.2.2 2026-01-21 00:21:58.823873 | controller | Successfully installed pip-25.3 2026-01-21 00:21:59.254845 | controller | ok: Runtime: 0:00:01.968045 2026-01-21 00:21:59.263553 | 2026-01-21 00:21:59.263721 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-21 00:21:59.479781 | controller | changed 2026-01-21 00:21:59.485549 | 2026-01-21 00:21:59.485627 | TASK [Install ansible into virtualenv] 2026-01-21 00:21:59.989111 | controller | Processing ./src/github.com/ansible/ansible 2026-01-21 00:21:59.992440 | controller | Installing build dependencies: started 2026-01-21 00:22:00.845520 | controller | Installing build dependencies: finished with status 'done' 2026-01-21 00:22:00.846223 | controller | Getting requirements to build wheel: started 2026-01-21 00:22:01.566998 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-21 00:22:01.567939 | controller | Preparing metadata (pyproject.toml): started 2026-01-21 00:22:02.016682 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-21 00:22:02.019255 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-01-21 00:22:02.021872 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-21 00:22:02.528345 | controller | ERROR 2026-01-21 00:22:02.528597 | controller | { 2026-01-21 00:22:02.528639 | controller | "delta": "0:00:02.376585", 2026-01-21 00:22:02.528669 | controller | "end": "2026-01-21 00:22:02.080041", 2026-01-21 00:22:02.528731 | controller | "msg": "non-zero return code", 2026-01-21 00:22:02.528772 | controller | "rc": 1, 2026-01-21 00:22:02.528798 | controller | "start": "2026-01-21 00:21:59.703456" 2026-01-21 00:22:02.528821 | controller | } failure 2026-01-21 00:22:02.531077 | 2026-01-21 00:22:02.531147 | PLAY RECAP 2026-01-21 00:22:02.531211 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-21 00:22:02.531248 | 2026-01-21 00:22:02.656995 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-21 00:22:02.657983 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-21 00:22:03.294049 | 2026-01-21 00:22:03.294178 | PLAY [all] 2026-01-21 00:22:03.317730 | 2026-01-21 00:22:03.317851 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-21 00:22:03.710570 | controller | changed: non-zero return code 2026-01-21 00:22:03.719873 | 2026-01-21 00:22:03.719997 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-21 00:22:03.735444 | controller | skipping: Conditional result was False 2026-01-21 00:22:03.749714 | 2026-01-21 00:22:03.749871 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-21 00:22:03.786744 | 2026-01-21 00:22:03.786936 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-21 00:22:03.821811 | 2026-01-21 00:22:03.822298 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-21 00:22:03.848488 | controller | skipping: Conditional result was False 2026-01-21 00:22:03.868461 | 2026-01-21 00:22:03.868806 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-21 00:22:03.904644 | 2026-01-21 00:22:03.904818 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-21 00:22:03.918525 | controller | skipping: Conditional result was False 2026-01-21 00:22:03.924965 | 2026-01-21 00:22:03.925035 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-21 00:22:03.938583 | controller | skipping: Conditional result was False 2026-01-21 00:22:03.945353 | 2026-01-21 00:22:03.945428 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-21 00:22:03.969310 | controller | skipping: Conditional result was False 2026-01-21 00:22:03.995751 | 2026-01-21 00:22:03.995810 | PLAY RECAP 2026-01-21 00:22:03.995846 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-21 00:22:03.995866 | 2026-01-21 00:22:04.093397 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-21 00:22:04.094265 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-21 00:22:04.681404 | 2026-01-21 00:22:04.681602 | PLAY [all:!appliance*] 2026-01-21 00:22:04.705045 | 2026-01-21 00:22:04.705184 | TASK [unregister the node] 2026-01-21 00:22:05.246878 | controller | skipping: Conditional result was False 2026-01-21 00:22:05.261103 | 2026-01-21 00:22:05.261295 | TASK [include_role : fetch-output] 2026-01-21 00:22:05.323195 | controller | ok 2026-01-21 00:22:05.374928 | 2026-01-21 00:22:05.375089 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-21 00:22:05.451614 | controller | skipping: Conditional result was False 2026-01-21 00:22:05.463019 | 2026-01-21 00:22:05.463199 | TASK [fetch-output : Set log path for single node] 2026-01-21 00:22:05.516609 | controller | ok 2026-01-21 00:22:05.531809 | 2026-01-21 00:22:05.531975 | LOOP [fetch-output : Ensure local output dirs] 2026-01-21 00:22:05.966663 | controller -> localhost | ok: "/var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/logs" 2026-01-21 00:22:06.223976 | controller -> localhost | changed: "/var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/artifacts" 2026-01-21 00:22:06.484578 | controller -> localhost | changed: "/var/lib/zuul/builds/88b6fa2a45ac44438dc083f72f58d9d7/work/docs" 2026-01-21 00:22:06.502493 | 2026-01-21 00:22:06.502658 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-21 00:22:07.159486 | controller | changed: 2026-01-21 00:22:07.159858 | controller | .d..t...... ./ 2026-01-21 00:22:07.159906 | controller | cd+++++++++ controller/ 2026-01-21 00:22:07.159952 | controller | changed: All items complete 2026-01-21 00:22:07.159981 | 2026-01-21 00:22:07.599670 | controller | changed: .d..t...... ./ 2026-01-21 00:22:08.146865 | controller | changed: .d..t...... ./ 2026-01-21 00:22:08.170126 | 2026-01-21 00:22:08.170278 | TASK [include_role : fetch-output-openshift] 2026-01-21 00:22:08.195800 | controller | skipping: Conditional result was False 2026-01-21 00:22:08.206187 | 2026-01-21 00:22:08.206352 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-21 00:22:08.245946 | controller | skipping: Conditional result was False 2026-01-21 00:22:08.258385 | controller | skipping: Conditional result was False 2026-01-21 00:22:08.310068 | 2026-01-21 00:22:08.310172 | PLAY [localhost] 2026-01-21 00:22:08.325089 | 2026-01-21 00:22:08.325200 | TASK [Run Zuul manifest role] 2026-01-21 00:22:08.343040 | localhost | ok 2026-01-21 00:22:08.359169 | 2026-01-21 00:22:08.359289 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-21 00:22:08.778343 | localhost | changed 2026-01-21 00:22:08.783372 | 2026-01-21 00:22:08.783921 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-21 00:22:08.812429 | localhost | ok 2026-01-21 00:22:08.821699 | 2026-01-21 00:22:08.821786 | TASK [Set zuul-log-path fact] 2026-01-21 00:22:08.841524 | localhost | ok 2026-01-21 00:22:08.861442 | 2026-01-21 00:22:08.861618 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-21 00:22:08.892567 | localhost | ok 2026-01-21 00:22:08.906106 | 2026-01-21 00:22:08.906304 | LOOP [Run upload-logs-swift role] 2026-01-21 00:22:08.942835 | localhost | Output suppressed because no_log was given 2026-01-21 00:22:08.977380 | 2026-01-21 00:22:08.977537 | TASK [Set zuul-log-path fact] 2026-01-21 00:22:09.003321 | localhost | skipping: Conditional result was False 2026-01-21 00:22:09.009886 | 2026-01-21 00:22:09.009970 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-21 00:22:09.426543 | localhost -> localhost | ok: Runtime: 0:00:00.006060 2026-01-21 00:22:09.474552 | 2026-01-21 00:22:09.474734 | TASK [upload-logs-swift : Upload logs to swift]