2026-02-04 00:20:57.965866 | Job console starting... 2026-02-04 00:20:57.974482 | Updating repositories 2026-02-04 00:20:58.092294 | Preparing job workspace 2026-02-04 00:21:01.810195 | Running Ansible setup... 2026-02-04 00:21:06.263468 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-04 00:21:07.012768 | 2026-02-04 00:21:07.013049 | PLAY [localhost] 2026-02-04 00:21:07.021649 | 2026-02-04 00:21:07.021748 | TASK [Gathering Facts] 2026-02-04 00:21:08.056389 | localhost | ok 2026-02-04 00:21:08.071729 | 2026-02-04 00:21:08.071842 | TASK [Setup log path fact] 2026-02-04 00:21:08.094453 | localhost | ok 2026-02-04 00:21:08.109335 | 2026-02-04 00:21:08.109419 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-04 00:21:08.137047 | localhost | ok 2026-02-04 00:21:08.144942 | 2026-02-04 00:21:08.145011 | TASK [emit-job-header : Print job information] 2026-02-04 00:21:08.183502 | # Job Information 2026-02-04 00:21:08.183632 | Ansible Version: 2.15.12 2026-02-04 00:21:08.183688 | Job: ansible-test-sanity-docker-milestone 2026-02-04 00:21:08.183715 | Pipeline: periodic 2026-02-04 00:21:08.183735 | Executor: ze02.softwarefactory-project.io 2026-02-04 00:21:08.183753 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-04 00:21:08.183774 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/d41/ansible/d413dbfe27b64f10a1a75ad4f408cd99/ 2026-02-04 00:21:08.183792 | Event ID: af23c61c78df4ae484f3d1e559ad4c41 2026-02-04 00:21:08.187713 | 2026-02-04 00:21:08.187777 | LOOP [emit-job-header : Print node information] 2026-02-04 00:21:08.296237 | localhost | ok: 2026-02-04 00:21:08.296605 | localhost | # Node Information 2026-02-04 00:21:08.296747 | localhost | Inventory Hostname: controller 2026-02-04 00:21:08.296819 | localhost | Hostname: np0005607592 2026-02-04 00:21:08.296885 | localhost | Username: zuul 2026-02-04 00:21:08.296960 | localhost | Distro: Fedora 37 2026-02-04 00:21:08.297026 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-04 00:21:08.297083 | localhost | Region: ca-ymq-1 2026-02-04 00:21:08.297141 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-04 00:21:08.297199 | localhost | Product Name: OpenStack Nova 2026-02-04 00:21:08.297255 | localhost | Interface IP: 162.253.55.212 2026-02-04 00:21:08.312753 | 2026-02-04 00:21:08.312921 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-04 00:21:08.795901 | localhost -> localhost | changed 2026-02-04 00:21:08.821218 | 2026-02-04 00:21:08.821441 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-04 00:21:09.862149 | localhost -> localhost | changed 2026-02-04 00:21:09.890798 | 2026-02-04 00:21:09.890924 | PLAY [all:!appliance*] 2026-02-04 00:21:09.907268 | 2026-02-04 00:21:09.907335 | TASK [include_role : start-zuul-console] 2026-02-04 00:21:09.928381 | controller | ok 2026-02-04 00:21:09.941631 | 2026-02-04 00:21:09.941712 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-04 00:21:10.327823 | controller | ok 2026-02-04 00:21:10.338858 | 2026-02-04 00:21:10.338924 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-04 00:21:11.338547 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-04 00:21:11.354407 | 2026-02-04 00:21:11.354553 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-04 00:21:11.904409 | controller | skipping: Conditional result was False 2026-02-04 00:21:11.922849 | 2026-02-04 00:21:11.923026 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-04 00:21:11.952252 | controller | skipping: Conditional result was False 2026-02-04 00:21:11.968988 | 2026-02-04 00:21:11.969143 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-04 00:21:11.998458 | controller | skipping: Conditional result was False 2026-02-04 00:21:12.014611 | 2026-02-04 00:21:12.014793 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-04 00:21:12.042835 | controller | skipping: Conditional result was False 2026-02-04 00:21:12.059502 | 2026-02-04 00:21:12.059715 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-04 00:21:12.079459 | controller | skipping: Conditional result was False 2026-02-04 00:21:12.095541 | 2026-02-04 00:21:12.095655 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-04 00:21:12.141641 | controller | skipping: Conditional result was False 2026-02-04 00:21:12.164575 | 2026-02-04 00:21:12.164807 | TASK [Disable Fedora Modular] 2026-02-04 00:21:12.427624 | controller | changed 2026-02-04 00:21:12.441291 | 2026-02-04 00:21:12.441443 | TASK [Enable EPEL] 2026-02-04 00:21:12.469091 | controller | skipping: Conditional result was False 2026-02-04 00:21:12.484586 | 2026-02-04 00:21:12.484774 | TASK [Register the RHEL node] 2026-02-04 00:21:13.051155 | 2026-02-04 00:21:13.051451 | TASK [Show the subscription-manager status] 2026-02-04 00:21:13.646144 | controller | skipping: Conditional result was False 2026-02-04 00:21:13.653208 | 2026-02-04 00:21:13.653276 | TASK [Enable EPEL on RHEL] 2026-02-04 00:21:14.195574 | controller | skipping: Conditional result was False 2026-02-04 00:21:14.202393 | 2026-02-04 00:21:14.202478 | TASK [Install git and tox] 2026-02-04 00:22:34.564708 | controller | changed 2026-02-04 00:22:34.578345 | 2026-02-04 00:22:34.578507 | TASK [include_role : prepare-workspace] 2026-02-04 00:22:34.619553 | controller | ok 2026-02-04 00:22:34.655509 | 2026-02-04 00:22:34.655598 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-04 00:22:34.928481 | controller | ok 2026-02-04 00:22:34.945907 | 2026-02-04 00:22:34.946121 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-04 00:22:47.401180 | controller | Output suppressed because no_log was given 2026-02-04 00:22:47.428335 | 2026-02-04 00:22:47.428494 | TASK [include_role : prepare-workspace-openshift] 2026-02-04 00:22:47.477322 | controller | skipping: Conditional result was False 2026-02-04 00:22:47.526073 | 2026-02-04 00:22:47.526218 | PLAY [all:!appliance] 2026-02-04 00:22:47.564337 | 2026-02-04 00:22:47.564609 | TASK [Run add-build-sshkey role (RSA)] 2026-02-04 00:22:47.601387 | controller | ok 2026-02-04 00:22:47.624296 | 2026-02-04 00:22:47.624460 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-04 00:22:47.937109 | controller -> localhost | ok 2026-02-04 00:22:47.953881 | 2026-02-04 00:22:47.954035 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-04 00:22:47.995536 | controller | ok 2026-02-04 00:22:48.022481 | controller | included: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-04 00:22:48.032410 | 2026-02-04 00:22:48.032499 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-04 00:22:48.576215 | controller -> localhost | Generating public/private rsa key pair. 2026-02-04 00:22:48.576550 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/d413dbfe27b64f10a1a75ad4f408cd99_id_rsa. 2026-02-04 00:22:48.576596 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/d413dbfe27b64f10a1a75ad4f408cd99_id_rsa.pub. 2026-02-04 00:22:48.576627 | controller -> localhost | The key fingerprint is: 2026-02-04 00:22:48.576656 | controller -> localhost | SHA256:jW9h+3Bv8TZSzQVI+E58BxCMIy9Mui1U4qW7RH9Yy1I zuul-build-sshkey 2026-02-04 00:22:48.576713 | controller -> localhost | The key's randomart image is: 2026-02-04 00:22:48.576742 | controller -> localhost | +---[RSA 2048]----+ 2026-02-04 00:22:48.576767 | controller -> localhost | | =++ | 2026-02-04 00:22:48.576794 | controller -> localhost | | . = + o o | 2026-02-04 00:22:48.576819 | controller -> localhost | | . O o + o | 2026-02-04 00:22:48.576844 | controller -> localhost | | * ooE + . o| 2026-02-04 00:22:48.576868 | controller -> localhost | | o =S*++ . oo| 2026-02-04 00:22:48.576909 | controller -> localhost | | = =o+o. ..o| 2026-02-04 00:22:48.576946 | controller -> localhost | | . o o= . .o | 2026-02-04 00:22:48.576973 | controller -> localhost | | . . + o..o| 2026-02-04 00:22:48.576999 | controller -> localhost | | ..o..| 2026-02-04 00:22:48.577028 | controller -> localhost | +----[SHA256]-----+ 2026-02-04 00:22:48.577108 | controller -> localhost | ok: Runtime: 0:00:00.089748 2026-02-04 00:22:48.587202 | 2026-02-04 00:22:48.587302 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-04 00:22:48.626575 | controller | ok 2026-02-04 00:22:48.647410 | controller | included: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-04 00:22:48.660320 | 2026-02-04 00:22:48.660503 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-04 00:22:48.686324 | controller | skipping: Conditional result was False 2026-02-04 00:22:48.698185 | 2026-02-04 00:22:48.698291 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-04 00:22:49.167788 | controller | changed 2026-02-04 00:22:49.182088 | 2026-02-04 00:22:49.182258 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-04 00:22:49.435724 | controller | ok 2026-02-04 00:22:49.448973 | 2026-02-04 00:22:49.449107 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-04 00:22:50.135903 | controller | changed 2026-02-04 00:22:50.149468 | 2026-02-04 00:22:50.149608 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-04 00:22:50.792755 | controller | changed 2026-02-04 00:22:50.805807 | 2026-02-04 00:22:50.805937 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-04 00:22:50.835532 | controller | skipping: Conditional result was False 2026-02-04 00:22:50.851842 | 2026-02-04 00:22:50.851986 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-04 00:22:51.287758 | controller -> localhost | changed 2026-02-04 00:22:51.300750 | 2026-02-04 00:22:51.300819 | TASK [add-build-sshkey : Add back temp key] 2026-02-04 00:22:51.644734 | controller -> localhost | Identity added: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/d413dbfe27b64f10a1a75ad4f408cd99_id_rsa (zuul-build-sshkey) 2026-02-04 00:22:51.645027 | controller -> localhost | ok: Runtime: 0:00:00.015122 2026-02-04 00:22:51.652846 | 2026-02-04 00:22:51.652913 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-04 00:22:52.041564 | controller | ok 2026-02-04 00:22:52.059295 | 2026-02-04 00:22:52.059645 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-04 00:22:52.099788 | controller | skipping: Conditional result was False 2026-02-04 00:22:52.127228 | 2026-02-04 00:22:52.127374 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-04 00:22:52.165079 | controller | ok 2026-02-04 00:22:52.191005 | 2026-02-04 00:22:52.191103 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-04 00:22:52.483558 | controller -> localhost | ok 2026-02-04 00:22:52.502147 | 2026-02-04 00:22:52.502305 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-04 00:22:52.545469 | controller | ok 2026-02-04 00:22:52.568839 | controller | included: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-04 00:22:52.577864 | 2026-02-04 00:22:52.577953 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-04 00:22:52.913583 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-04 00:22:52.913880 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/d413dbfe27b64f10a1a75ad4f408cd99_id_ecdsa. 2026-02-04 00:22:52.913910 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/d413dbfe27b64f10a1a75ad4f408cd99_id_ecdsa.pub. 2026-02-04 00:22:52.913942 | controller -> localhost | The key fingerprint is: 2026-02-04 00:22:52.913962 | controller -> localhost | SHA256:c1vzUmAYNf+7gcdu3SED+q5zso76jzJZUwcCwYqKnnQ zuul-build-sshkey 2026-02-04 00:22:52.913980 | controller -> localhost | The key's randomart image is: 2026-02-04 00:22:52.913999 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-04 00:22:52.914017 | controller -> localhost | | .oo ..o | 2026-02-04 00:22:52.914037 | controller -> localhost | | . . . o o | 2026-02-04 00:22:52.914056 | controller -> localhost | | . . . o o . | 2026-02-04 00:22:52.914078 | controller -> localhost | | . . . + . . | 2026-02-04 00:22:52.914095 | controller -> localhost | |o S + + . .| 2026-02-04 00:22:52.914112 | controller -> localhost | |o. E o + o *o..| 2026-02-04 00:22:52.914132 | controller -> localhost | |o o o . o ..+=+| 2026-02-04 00:22:52.914149 | controller -> localhost | | o + oo o .o.=| 2026-02-04 00:22:52.914166 | controller -> localhost | | .=+o=B. .o | 2026-02-04 00:22:52.914183 | controller -> localhost | +----[SHA256]-----+ 2026-02-04 00:22:52.914236 | controller -> localhost | ok: Runtime: 0:00:00.013706 2026-02-04 00:22:52.921842 | 2026-02-04 00:22:52.921953 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-04 00:22:52.957342 | controller | ok 2026-02-04 00:22:52.966043 | controller | included: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-04 00:22:52.975392 | 2026-02-04 00:22:52.975474 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-04 00:22:53.001151 | controller | skipping: Conditional result was False 2026-02-04 00:22:53.011267 | 2026-02-04 00:22:53.011358 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-04 00:22:53.292250 | controller | changed 2026-02-04 00:22:53.301536 | 2026-02-04 00:22:53.301624 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-04 00:22:53.538603 | controller | ok 2026-02-04 00:22:53.547451 | 2026-02-04 00:22:53.547591 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-04 00:22:54.216470 | controller | changed 2026-02-04 00:22:54.236747 | 2026-02-04 00:22:54.236979 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-04 00:22:54.983030 | controller | changed 2026-02-04 00:22:54.992246 | 2026-02-04 00:22:54.992340 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-04 00:22:55.029137 | controller | skipping: Conditional result was False 2026-02-04 00:22:55.043493 | 2026-02-04 00:22:55.043647 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-04 00:22:55.379655 | controller -> localhost | changed 2026-02-04 00:22:55.408458 | 2026-02-04 00:22:55.408646 | TASK [add-build-sshkey : Add back temp key] 2026-02-04 00:22:55.691860 | controller -> localhost | Identity added: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/d413dbfe27b64f10a1a75ad4f408cd99_id_ecdsa (zuul-build-sshkey) 2026-02-04 00:22:55.692300 | controller -> localhost | ok: Runtime: 0:00:00.010512 2026-02-04 00:22:55.709948 | 2026-02-04 00:22:55.710088 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-04 00:22:55.946776 | controller | ok 2026-02-04 00:22:55.959841 | 2026-02-04 00:22:55.960062 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-04 00:22:56.009710 | controller | skipping: Conditional result was False 2026-02-04 00:22:56.038748 | 2026-02-04 00:22:56.038913 | TASK [include_role : remove-zuul-sshkey] 2026-02-04 00:22:56.067642 | controller | skipping: Conditional result was False 2026-02-04 00:22:56.085160 | 2026-02-04 00:22:56.085426 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-04 00:22:56.341385 | controller | ok: "logs" 2026-02-04 00:22:56.343771 | controller | ok: All items complete 2026-02-04 00:22:56.343904 | 2026-02-04 00:22:56.565136 | controller | ok: "artifacts" 2026-02-04 00:22:56.765729 | controller | ok: "docs" 2026-02-04 00:22:56.787811 | 2026-02-04 00:22:56.788033 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-04 00:22:57.061654 | controller | changed: "logs" 2026-02-04 00:22:57.275309 | controller | changed: "artifacts" 2026-02-04 00:22:57.479775 | controller | changed: "docs" 2026-02-04 00:22:57.535138 | 2026-02-04 00:22:57.535219 | PLAY RECAP 2026-02-04 00:22:57.535276 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-04 00:22:57.535310 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-04 00:22:57.535335 | 2026-02-04 00:22:57.680578 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-04 00:22:57.682572 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-04 00:22:58.309534 | 2026-02-04 00:22:58.309701 | PLAY [all] 2026-02-04 00:22:58.333082 | 2026-02-04 00:22:58.333198 | TASK [Install binary dependencies] 2026-02-04 00:22:58.404754 | controller | ok 2026-02-04 00:22:58.425571 | 2026-02-04 00:22:58.425737 | TASK [bindep : Include find tasks] 2026-02-04 00:22:58.466818 | controller | ok 2026-02-04 00:22:58.475486 | controller | included: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-04 00:22:58.482185 | 2026-02-04 00:22:58.482251 | TASK [bindep : Look for bindep.txt] 2026-02-04 00:22:58.879971 | controller | ok 2026-02-04 00:22:58.886704 | 2026-02-04 00:22:58.886796 | TASK [bindep : Define bindep_file fact] 2026-02-04 00:22:58.911584 | controller | skipping: Conditional result was False 2026-02-04 00:22:58.918802 | 2026-02-04 00:22:58.918941 | TASK [bindep : Look for other-requirements.txt] 2026-02-04 00:22:59.141896 | controller | ok 2026-02-04 00:22:59.147878 | 2026-02-04 00:22:59.147951 | TASK [bindep : Define bindep_file fact] 2026-02-04 00:22:59.173565 | controller | skipping: Conditional result was False 2026-02-04 00:22:59.189992 | 2026-02-04 00:22:59.190175 | TASK [bindep : Look for bindep fallback file] 2026-02-04 00:22:59.229195 | controller | skipping: Conditional result was False 2026-02-04 00:22:59.245228 | 2026-02-04 00:22:59.245387 | TASK [bindep : Define bindep_file fact] 2026-02-04 00:22:59.273628 | controller | skipping: Conditional result was False 2026-02-04 00:22:59.288081 | 2026-02-04 00:22:59.288257 | TASK [bindep : Include bindep tasks] 2026-02-04 00:22:59.316809 | controller | skipping: Conditional result was False 2026-02-04 00:22:59.330097 | 2026-02-04 00:22:59.330232 | TASK [bindep : Include install tasks] 2026-02-04 00:22:59.369238 | controller | skipping: Conditional result was False 2026-02-04 00:22:59.384206 | 2026-02-04 00:22:59.384349 | LOOP [bindep : Include package tasks] 2026-02-04 00:22:59.458132 | 2026-02-04 00:22:59.458475 | TASK [Run test-setup role] 2026-02-04 00:22:59.492494 | controller | ok 2026-02-04 00:22:59.520723 | 2026-02-04 00:22:59.520868 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-04 00:22:59.737276 | controller | ok 2026-02-04 00:22:59.746137 | 2026-02-04 00:22:59.746253 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-04 00:23:00.292640 | controller | skipping: Conditional result was False 2026-02-04 00:23:00.348223 | 2026-02-04 00:23:00.348422 | PLAY RECAP 2026-02-04 00:23:00.348488 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-04 00:23:00.348517 | 2026-02-04 00:23:00.482595 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-04 00:23:00.485017 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-04 00:23:01.085780 | 2026-02-04 00:23:01.085937 | PLAY [controller] 2026-02-04 00:23:01.106466 | 2026-02-04 00:23:01.106567 | TASK [Create the /root directory] 2026-02-04 00:23:01.555303 | controller | ok 2026-02-04 00:23:01.568529 | 2026-02-04 00:23:01.568740 | TASK [Install glibc-langpack-en] 2026-02-04 00:23:05.531394 | controller | ok: Nothing to do 2026-02-04 00:23:05.549319 | 2026-02-04 00:23:05.549509 | TASK [Ensure controller directory exists] 2026-02-04 00:23:05.788863 | controller | changed 2026-02-04 00:23:05.794921 | 2026-02-04 00:23:05.795002 | TASK [Install container runtime] 2026-02-04 00:23:05.868886 | controller | ok 2026-02-04 00:23:05.906095 | 2026-02-04 00:23:05.906196 | LOOP [ensure-podman : Find distribution installation] 2026-02-04 00:23:05.939056 | controller | ok: "/var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-04 00:23:05.948417 | controller | included: /var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-04 00:23:05.954797 | 2026-02-04 00:23:05.954862 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-04 00:24:10.527459 | controller | changed 2026-02-04 00:24:10.536105 | 2026-02-04 00:24:10.536191 | TASK [ensure-podman : Fetch podman version] 2026-02-04 00:24:11.055040 | controller | Client: Podman Engine 2026-02-04 00:24:11.087692 | controller | Version: 4.6.2 2026-02-04 00:24:11.087808 | controller | API Version: 4.6.2 2026-02-04 00:24:11.087823 | controller | Go Version: go1.19.12 2026-02-04 00:24:11.087848 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-04 00:24:11.087861 | controller | OS/Arch: linux/amd64 2026-02-04 00:24:11.568615 | controller | ok: Runtime: 0:00:00.180873 2026-02-04 00:24:11.579303 | 2026-02-04 00:24:11.579422 | TASK [ensure-podman : Print podman version installed] 2026-02-04 00:24:11.616985 | Podman version: Client: Podman Engine 2026-02-04 00:24:11.617234 | Version: 4.6.2 2026-02-04 00:24:11.617279 | API Version: 4.6.2 2026-02-04 00:24:11.617310 | Go Version: go1.19.12 2026-02-04 00:24:11.617338 | Built: Mon Aug 28 19:38:31 2023 2026-02-04 00:24:11.617366 | OS/Arch: linux/amd64 2026-02-04 00:24:11.626139 | 2026-02-04 00:24:11.626237 | TASK [ensure-podman : Validate podman engine] 2026-02-04 00:24:12.169943 | controller | skipping: Conditional result was False 2026-02-04 00:24:12.177253 | 2026-02-04 00:24:12.177344 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-04 00:24:12.202040 | controller | skipping: Conditional result was False 2026-02-04 00:24:12.219628 | 2026-02-04 00:24:12.219830 | TASK [Ensure python3.8 is present] 2026-02-04 00:24:12.247392 | controller | skipping: Conditional result was False 2026-02-04 00:24:12.256772 | 2026-02-04 00:24:12.256871 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-04 00:24:12.284388 | controller | ok 2026-02-04 00:24:12.314457 | 2026-02-04 00:24:12.314626 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-04 00:24:14.000192 | controller | ok: Nothing to do 2026-02-04 00:24:14.013655 | 2026-02-04 00:24:14.013836 | TASK [our-ensure-python : Also install python3-devel] 2026-02-04 00:24:22.756449 | controller | changed 2026-02-04 00:24:22.768626 | 2026-02-04 00:24:22.768748 | TASK [Run ensure-virtualenv role] 2026-02-04 00:24:22.789922 | controller | ok 2026-02-04 00:24:22.814088 | 2026-02-04 00:24:22.814222 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-04 00:24:23.041239 | controller | /usr/bin/virtualenv 2026-02-04 00:24:23.349595 | controller | ok: Runtime: 0:00:00.005133 2026-02-04 00:24:23.365391 | 2026-02-04 00:24:23.365694 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-04 00:24:23.404287 | controller | skipping: Conditional result was False 2026-02-04 00:24:23.404864 | controller | ok: All items complete 2026-02-04 00:24:23.404931 | 2026-02-04 00:24:23.445268 | 2026-02-04 00:24:23.445475 | TASK [Find the full path of the Python interpreter] 2026-02-04 00:24:23.740308 | controller | /usr/bin/python3 2026-02-04 00:24:24.053901 | controller | ok 2026-02-04 00:24:24.069637 | 2026-02-04 00:24:24.069850 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-04 00:24:24.955891 | controller | created virtual environment CPython3.11.0.final.0-64 in 459ms 2026-02-04 00:24:24.979445 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-04 00:24:24.979899 | 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-02-04 00:24:24.980180 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-04 00:24:24.980455 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-04 00:24:25.131000 | controller | changed 2026-02-04 00:24:25.151222 | 2026-02-04 00:24:25.151413 | TASK [Set selinux package] 2026-02-04 00:24:25.186249 | controller | ok 2026-02-04 00:24:25.199435 | 2026-02-04 00:24:25.199583 | TASK [Set selinux package (Fedora)] 2026-02-04 00:24:25.245141 | controller | ok 2026-02-04 00:24:25.253357 | 2026-02-04 00:24:25.253444 | TASK [Install selinux into virtualenv] 2026-02-04 00:24:38.852947 | controller | Collecting selinux-please-lie-to-me 2026-02-04 00:24:51.265798 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-04 00:24:51.577187 | controller | Collecting setuptools<50.0.0 2026-02-04 00:24:51.699841 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-04 00:24:51.737103 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.9 MB/s eta 0:00:00 2026-02-04 00:24:51.817775 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-04 00:24:51.817949 | controller | Attempting uninstall: setuptools 2026-02-04 00:24:51.820384 | controller | Found existing installation: setuptools 62.6.0 2026-02-04 00:24:51.878317 | controller | Uninstalling setuptools-62.6.0: 2026-02-04 00:24:51.886175 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-04 00:24:52.220283 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-04 00:25:03.439648 | controller | 2026-02-04 00:25:03.520107 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-04 00:25:03.520155 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-04 00:25:03.811522 | controller | ok: Runtime: 0:00:38.049533 2026-02-04 00:25:03.820376 | 2026-02-04 00:25:03.820476 | TASK [Install pytest-forked into virtualenv] 2026-02-04 00:25:16.696379 | controller | Collecting pytest-forked 2026-02-04 00:25:28.948356 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-04 00:25:28.999178 | controller | Collecting py 2026-02-04 00:25:29.017472 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-04 00:25:29.039943 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.9 MB/s eta 0:00:00 2026-02-04 00:25:29.196461 | controller | Collecting pytest>=3.10 2026-02-04 00:25:29.213354 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-04 00:25:29.229184 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 30.6 MB/s eta 0:00:00 2026-02-04 00:25:29.278581 | controller | Collecting iniconfig>=1.0.1 2026-02-04 00:25:29.282194 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-04 00:25:29.326945 | controller | Collecting packaging>=22 2026-02-04 00:25:29.332211 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-04 00:25:29.339508 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 15.8 MB/s eta 0:00:00 2026-02-04 00:25:29.373758 | controller | Collecting pluggy<2,>=1.5 2026-02-04 00:25:29.377305 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-04 00:25:29.426014 | controller | Collecting pygments>=2.7.2 2026-02-04 00:25:29.432175 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-04 00:25:29.454552 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 65.8 MB/s eta 0:00:00 2026-02-04 00:25:29.526080 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-04 00:25:30.573482 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-02-04 00:25:30.582181 | controller | 2026-02-04 00:25:30.651552 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0 2026-02-04 00:25:30.651590 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-04 00:25:30.872360 | controller | ok: Runtime: 0:00:26.629709 2026-02-04 00:25:30.885145 | 2026-02-04 00:25:30.885271 | TASK [Update pip] 2026-02-04 00:25:31.426491 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-04 00:25:41.324238 | controller | Collecting pip 2026-02-04 00:25:53.646044 | controller | Downloading pip-26.0-py3-none-any.whl (1.8 MB) 2026-02-04 00:25:53.694202 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 39.9 MB/s eta 0:00:00 2026-02-04 00:25:53.757308 | controller | Installing collected packages: pip 2026-02-04 00:25:53.757423 | controller | Attempting uninstall: pip 2026-02-04 00:25:53.759518 | controller | Found existing installation: pip 22.2.2 2026-02-04 00:25:53.894923 | controller | Uninstalling pip-22.2.2: 2026-02-04 00:25:53.909959 | controller | Successfully uninstalled pip-22.2.2 2026-02-04 00:25:54.699192 | controller | Successfully installed pip-26.0 2026-02-04 00:25:54.951612 | controller | ok: Runtime: 0:00:23.645681 2026-02-04 00:25:54.965473 | 2026-02-04 00:25:54.965607 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-04 00:25:55.203931 | controller | changed 2026-02-04 00:25:55.209865 | 2026-02-04 00:25:55.209934 | TASK [Install ansible into virtualenv] 2026-02-04 00:25:55.708158 | controller | Processing ./src/github.com/ansible/ansible 2026-02-04 00:25:55.710598 | controller | Installing build dependencies: started 2026-02-04 00:26:18.679724 | controller | Installing build dependencies: finished with status 'done' 2026-02-04 00:26:18.681190 | controller | Getting requirements to build wheel: started 2026-02-04 00:26:19.424506 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-04 00:26:19.426791 | controller | Preparing metadata (pyproject.toml): started 2026-02-04 00:26:19.889215 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-04 00:26:19.894178 | 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-02-04 00:26:19.898029 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-04 00:26:20.259247 | controller | ERROR 2026-02-04 00:26:20.259775 | controller | { 2026-02-04 00:26:20.259867 | controller | "delta": "0:00:24.575721", 2026-02-04 00:26:20.259916 | controller | "end": "2026-02-04 00:26:20.001775", 2026-02-04 00:26:20.259965 | controller | "msg": "non-zero return code", 2026-02-04 00:26:20.260033 | controller | "rc": 1, 2026-02-04 00:26:20.260087 | controller | "start": "2026-02-04 00:25:55.426054" 2026-02-04 00:26:20.260128 | controller | } failure 2026-02-04 00:26:20.262644 | 2026-02-04 00:26:20.262768 | PLAY RECAP 2026-02-04 00:26:20.262848 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-04 00:26:20.262890 | 2026-02-04 00:26:20.388032 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-04 00:26:20.389613 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-04 00:26:20.978625 | 2026-02-04 00:26:20.978780 | PLAY [all] 2026-02-04 00:26:21.000424 | 2026-02-04 00:26:21.000501 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-04 00:26:21.283467 | controller | changed: non-zero return code 2026-02-04 00:26:21.296626 | 2026-02-04 00:26:21.296832 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-04 00:26:21.325534 | controller | skipping: Conditional result was False 2026-02-04 00:26:21.339418 | 2026-02-04 00:26:21.339572 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-04 00:26:21.383435 | 2026-02-04 00:26:21.383767 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-04 00:26:21.427480 | 2026-02-04 00:26:21.427819 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-04 00:26:21.456704 | controller | skipping: Conditional result was False 2026-02-04 00:26:21.474642 | 2026-02-04 00:26:21.474839 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-04 00:26:21.517637 | 2026-02-04 00:26:21.517931 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-04 00:26:21.545989 | controller | skipping: Conditional result was False 2026-02-04 00:26:21.560498 | 2026-02-04 00:26:21.560646 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-04 00:26:21.588612 | controller | skipping: Conditional result was False 2026-02-04 00:26:21.603762 | 2026-02-04 00:26:21.603914 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-04 00:26:21.632899 | controller | skipping: Conditional result was False 2026-02-04 00:26:21.683356 | 2026-02-04 00:26:21.683442 | PLAY RECAP 2026-02-04 00:26:21.683539 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-04 00:26:21.683569 | 2026-02-04 00:26:21.791697 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-04 00:26:21.792557 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-04 00:26:22.437328 | 2026-02-04 00:26:22.437465 | PLAY [all:!appliance*] 2026-02-04 00:26:22.459910 | 2026-02-04 00:26:22.460070 | TASK [unregister the node] 2026-02-04 00:26:22.994007 | controller | skipping: Conditional result was False 2026-02-04 00:26:23.009575 | 2026-02-04 00:26:23.009813 | TASK [include_role : fetch-output] 2026-02-04 00:26:23.069019 | controller | ok 2026-02-04 00:26:23.116601 | 2026-02-04 00:26:23.116781 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-04 00:26:23.195405 | controller | skipping: Conditional result was False 2026-02-04 00:26:23.204481 | 2026-02-04 00:26:23.204603 | TASK [fetch-output : Set log path for single node] 2026-02-04 00:26:23.248144 | controller | ok 2026-02-04 00:26:23.254647 | 2026-02-04 00:26:23.254742 | LOOP [fetch-output : Ensure local output dirs] 2026-02-04 00:26:23.717602 | controller -> localhost | ok: "/var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/logs" 2026-02-04 00:26:23.940509 | controller -> localhost | changed: "/var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/artifacts" 2026-02-04 00:26:24.183091 | controller -> localhost | changed: "/var/lib/zuul/builds/d413dbfe27b64f10a1a75ad4f408cd99/work/docs" 2026-02-04 00:26:24.194050 | 2026-02-04 00:26:24.194183 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-04 00:26:24.933241 | controller | changed: 2026-02-04 00:26:24.933626 | controller | .d..t...... ./ 2026-02-04 00:26:24.933760 | controller | cd+++++++++ controller/ 2026-02-04 00:26:24.933836 | controller | changed: All items complete 2026-02-04 00:26:24.933884 | 2026-02-04 00:26:25.484408 | controller | changed: .d..t...... ./ 2026-02-04 00:26:26.011633 | controller | changed: .d..t...... ./ 2026-02-04 00:26:26.046366 | 2026-02-04 00:26:26.046584 | TASK [include_role : fetch-output-openshift] 2026-02-04 00:26:26.074896 | controller | skipping: Conditional result was False 2026-02-04 00:26:26.088811 | 2026-02-04 00:26:26.089179 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-04 00:26:26.144470 | controller | skipping: Conditional result was False 2026-02-04 00:26:26.155118 | controller | skipping: Conditional result was False 2026-02-04 00:26:26.211485 | 2026-02-04 00:26:26.211622 | PLAY [localhost] 2026-02-04 00:26:26.228895 | 2026-02-04 00:26:26.228992 | TASK [Run Zuul manifest role] 2026-02-04 00:26:26.250982 | localhost | ok 2026-02-04 00:26:26.270229 | 2026-02-04 00:26:26.270328 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-04 00:26:26.712918 | localhost | changed 2026-02-04 00:26:26.722945 | 2026-02-04 00:26:26.723079 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-04 00:26:26.759375 | localhost | ok 2026-02-04 00:26:26.776945 | 2026-02-04 00:26:26.777076 | TASK [Set zuul-log-path fact] 2026-02-04 00:26:26.799464 | localhost | ok 2026-02-04 00:26:26.818784 | 2026-02-04 00:26:26.818944 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-04 00:26:26.849156 | localhost | ok 2026-02-04 00:26:26.860497 | 2026-02-04 00:26:26.860642 | LOOP [Run upload-logs-swift role] 2026-02-04 00:26:26.886240 | localhost | Output suppressed because no_log was given 2026-02-04 00:26:26.919629 | 2026-02-04 00:26:26.919771 | TASK [Set zuul-log-path fact] 2026-02-04 00:26:26.955768 | localhost | skipping: Conditional result was False 2026-02-04 00:26:26.963369 | 2026-02-04 00:26:26.963465 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-04 00:26:27.418677 | localhost -> localhost | ok: Runtime: 0:00:00.009652 2026-02-04 00:26:27.452982 | 2026-02-04 00:26:27.453127 | TASK [upload-logs-swift : Upload logs to swift]