2026-01-14 00:21:02.336353 | Job console starting...
2026-01-14 00:21:02.344623 | Updating repositories
2026-01-14 00:21:02.494945 | Preparing job workspace
2026-01-14 00:21:06.109267 | Running Ansible setup...
2026-01-14 00:21:14.125822 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-14 00:21:14.754335 | 
2026-01-14 00:21:14.754447 | PLAY [localhost]
2026-01-14 00:21:14.763372 | 
2026-01-14 00:21:14.763457 | TASK [Gathering Facts]
2026-01-14 00:21:15.834675 | localhost | ok
2026-01-14 00:21:15.863582 | 
2026-01-14 00:21:15.863826 | TASK [Setup log path fact]
2026-01-14 00:21:15.886265 | localhost | ok
2026-01-14 00:21:15.905143 | 
2026-01-14 00:21:15.905277 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-14 00:21:15.946942 | localhost | ok
2026-01-14 00:21:15.959330 | 
2026-01-14 00:21:15.959481 | TASK [emit-job-header : Print job information]
2026-01-14 00:21:16.011646 | # Job Information
2026-01-14 00:21:16.011878 | Ansible Version: 2.15.12
2026-01-14 00:21:16.011925 | Job: ansible-test-sanity-docker-devel
2026-01-14 00:21:16.011955 | Pipeline: periodic
2026-01-14 00:21:16.011982 | Executor: ze03.softwarefactory-project.io
2026-01-14 00:21:16.012011 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-14 00:21:16.012041 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/807/ansible/8073fb89911049449292942dd8e3eea1/
2026-01-14 00:21:16.012069 | Event ID: 6a8911388478401588366a6209bb2579
2026-01-14 00:21:16.017457 | 
2026-01-14 00:21:16.017549 | LOOP [emit-job-header : Print node information]
2026-01-14 00:21:16.148178 | localhost | ok:
2026-01-14 00:21:16.148375 | localhost | # Node Information
2026-01-14 00:21:16.148402 | localhost | Inventory Hostname: controller
2026-01-14 00:21:16.148421 | localhost | Hostname: np0005583430
2026-01-14 00:21:16.148457 | localhost | Username: zuul
2026-01-14 00:21:16.148483 | localhost | Distro: Fedora 37
2026-01-14 00:21:16.148502 | localhost | Provider: ansible-vexxhost-ams1
2026-01-14 00:21:16.148519 | localhost | Region: ams1
2026-01-14 00:21:16.148535 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-14 00:21:16.148552 | localhost | Product Name: OpenStack Nova
2026-01-14 00:21:16.148568 | localhost | Interface IP: 38.129.16.183
2026-01-14 00:21:16.174545 | 
2026-01-14 00:21:16.174691 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-14 00:21:16.619171 | localhost -> localhost | changed
2026-01-14 00:21:16.630137 | 
2026-01-14 00:21:16.630276 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-14 00:21:17.471658 | localhost -> localhost | changed
2026-01-14 00:21:17.497308 | 
2026-01-14 00:21:17.497415 | PLAY [all:!appliance*]
2026-01-14 00:21:17.518443 | 
2026-01-14 00:21:17.518525 | TASK [include_role : start-zuul-console]
2026-01-14 00:21:17.536847 | controller | ok
2026-01-14 00:21:17.550329 | 
2026-01-14 00:21:17.550438 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-14 00:21:18.619848 | controller | ok
2026-01-14 00:21:18.635270 | 
2026-01-14 00:21:18.635378 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-14 00:21:20.948629 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-14 00:21:20.955417 | 
2026-01-14 00:21:20.955486 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-14 00:21:21.340070 | controller | skipping: Conditional result was False
2026-01-14 00:21:21.348303 | 
2026-01-14 00:21:21.348430 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-14 00:21:21.375166 | controller | skipping: Conditional result was False
2026-01-14 00:21:21.392828 | 
2026-01-14 00:21:21.393025 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-14 00:21:21.430792 | controller | skipping: Conditional result was False
2026-01-14 00:21:21.446915 | 
2026-01-14 00:21:21.447098 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-14 00:21:21.472376 | controller | skipping: Conditional result was False
2026-01-14 00:21:21.481939 | 
2026-01-14 00:21:21.482047 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-14 00:21:21.507466 | controller | skipping: Conditional result was False
2026-01-14 00:21:21.517293 | 
2026-01-14 00:21:21.517414 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-14 00:21:21.542436 | controller | skipping: Conditional result was False
2026-01-14 00:21:21.560338 | 
2026-01-14 00:21:21.560481 | TASK [Disable Fedora Modular]
2026-01-14 00:21:22.619848 | controller | changed
2026-01-14 00:21:22.630128 | 
2026-01-14 00:21:22.630250 | TASK [Enable EPEL]
2026-01-14 00:21:22.655705 | controller | skipping: Conditional result was False
2026-01-14 00:21:22.665452 | 
2026-01-14 00:21:22.665552 | TASK [Register the RHEL node]
2026-01-14 00:21:23.062384 | 
2026-01-14 00:21:23.062532 | TASK [Show the subscription-manager status]
2026-01-14 00:21:23.422977 | controller | skipping: Conditional result was False
2026-01-14 00:21:23.432378 | 
2026-01-14 00:21:23.432471 | TASK [Enable EPEL on RHEL]
2026-01-14 00:21:23.829795 | controller | skipping: Conditional result was False
2026-01-14 00:21:23.842658 | 
2026-01-14 00:21:23.842851 | TASK [Install git and tox]
2026-01-14 00:23:29.335280 | controller | changed
2026-01-14 00:23:29.349515 | 
2026-01-14 00:23:29.349650 | TASK [include_role : prepare-workspace]
2026-01-14 00:23:29.389719 | controller | ok
2026-01-14 00:23:29.428261 | 
2026-01-14 00:23:29.428371 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-14 00:23:30.250157 | controller | ok
2026-01-14 00:23:30.265892 | 
2026-01-14 00:23:30.266036 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-14 00:23:45.872890 | controller | Output suppressed because no_log was given
2026-01-14 00:23:45.913679 | 
2026-01-14 00:23:45.913891 | TASK [include_role : prepare-workspace-openshift]
2026-01-14 00:23:45.931214 | controller | skipping: Conditional result was False
2026-01-14 00:23:45.953198 | 
2026-01-14 00:23:45.953279 | PLAY [all:!appliance]
2026-01-14 00:23:45.969483 | 
2026-01-14 00:23:45.969577 | TASK [Run add-build-sshkey role (RSA)]
2026-01-14 00:23:45.999598 | controller | ok
2026-01-14 00:23:46.014813 | 
2026-01-14 00:23:46.014938 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-14 00:23:46.284341 | controller -> localhost | ok
2026-01-14 00:23:46.300829 | 
2026-01-14 00:23:46.301007 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-14 00:23:46.334581 | controller | ok
2026-01-14 00:23:46.359018 | controller | included: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-14 00:23:46.368993 | 
2026-01-14 00:23:46.369159 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-14 00:23:46.916867 | controller -> localhost | Generating public/private rsa key pair.
2026-01-14 00:23:46.917051 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/8073fb89911049449292942dd8e3eea1_id_rsa.
2026-01-14 00:23:46.917081 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/8073fb89911049449292942dd8e3eea1_id_rsa.pub.
2026-01-14 00:23:46.917103 | controller -> localhost | The key fingerprint is:
2026-01-14 00:23:46.917124 | controller -> localhost | SHA256:Y8h9C00EJslR8rERl8i7Vl+Sw5qZqeo/wF7Khd7GyLE zuul-build-sshkey
2026-01-14 00:23:46.917147 | controller -> localhost | The key's randomart image is:
2026-01-14 00:23:46.917168 | controller -> localhost | +---[RSA 2048]----+
2026-01-14 00:23:46.917186 | controller -> localhost | |     .+=B+o.     |
2026-01-14 00:23:46.917205 | controller -> localhost | |      o=o*.      |
2026-01-14 00:23:46.917224 | controller -> localhost | |        o... .   |
2026-01-14 00:23:46.917243 | controller -> localhost | |     . o.o. = .  |
2026-01-14 00:23:46.917261 | controller -> localhost | |     .o.SooB +   |
2026-01-14 00:23:46.917288 | controller -> localhost | |      =.=+*..    |
2026-01-14 00:23:46.917308 | controller -> localhost | |     = % ..      |
2026-01-14 00:23:46.917331 | controller -> localhost | |      E *        |
2026-01-14 00:23:46.917350 | controller -> localhost | |     .o+..       |
2026-01-14 00:23:46.917371 | controller -> localhost | +----[SHA256]-----+
2026-01-14 00:23:46.917417 | controller -> localhost | ok: Runtime: 0:00:00.135471
2026-01-14 00:23:46.926775 | 
2026-01-14 00:23:46.926848 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-14 00:23:46.956917 | controller | ok
2026-01-14 00:23:46.966413 | controller | included: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-14 00:23:46.975221 | 
2026-01-14 00:23:46.975284 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-14 00:23:46.999986 | controller | skipping: Conditional result was False
2026-01-14 00:23:47.007038 | 
2026-01-14 00:23:47.007102 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-14 00:23:48.121947 | controller | changed
2026-01-14 00:23:48.137409 | 
2026-01-14 00:23:48.137594 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-14 00:23:48.801255 | controller | ok
2026-01-14 00:23:48.814507 | 
2026-01-14 00:23:48.814932 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-14 00:23:51.838699 | controller | changed
2026-01-14 00:23:51.852683 | 
2026-01-14 00:23:51.852888 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-14 00:23:54.875922 | controller | changed
2026-01-14 00:23:54.889562 | 
2026-01-14 00:23:54.889776 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-14 00:23:54.917005 | controller | skipping: Conditional result was False
2026-01-14 00:23:54.927268 | 
2026-01-14 00:23:54.927376 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-14 00:23:55.352550 | controller -> localhost | changed
2026-01-14 00:23:55.364497 | 
2026-01-14 00:23:55.364632 | TASK [add-build-sshkey : Add back temp key]
2026-01-14 00:23:55.704775 | controller -> localhost | Identity added: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/8073fb89911049449292942dd8e3eea1_id_rsa (zuul-build-sshkey)
2026-01-14 00:23:55.705061 | controller -> localhost | ok: Runtime: 0:00:00.011123
2026-01-14 00:23:55.711936 | 
2026-01-14 00:23:55.712018 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-14 00:23:56.641249 | controller | ok
2026-01-14 00:23:56.652142 | 
2026-01-14 00:23:56.652296 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-14 00:23:56.679067 | controller | skipping: Conditional result was False
2026-01-14 00:23:56.697561 | 
2026-01-14 00:23:56.697693 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-14 00:23:56.720512 | controller | ok
2026-01-14 00:23:56.738783 | 
2026-01-14 00:23:56.738916 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-14 00:23:56.959579 | controller -> localhost | ok
2026-01-14 00:23:56.970181 | 
2026-01-14 00:23:56.970326 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-14 00:23:57.004797 | controller | ok
2026-01-14 00:23:57.017607 | controller | included: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-14 00:23:57.023777 | 
2026-01-14 00:23:57.023863 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-14 00:23:57.286914 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-14 00:23:57.287306 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/8073fb89911049449292942dd8e3eea1_id_ecdsa.
2026-01-14 00:23:57.287370 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/8073fb89911049449292942dd8e3eea1_id_ecdsa.pub.
2026-01-14 00:23:57.287438 | controller -> localhost | The key fingerprint is:
2026-01-14 00:23:57.287484 | controller -> localhost | SHA256:bOhVZFITS/dX6WoErsdx0IT2MXmIjnJzohcfEqrJOXg zuul-build-sshkey
2026-01-14 00:23:57.287527 | controller -> localhost | The key's randomart image is:
2026-01-14 00:23:57.287569 | controller -> localhost | +---[ECDSA 521]---+
2026-01-14 00:23:57.287610 | controller -> localhost | |        ..B.*.o o|
2026-01-14 00:23:57.287650 | controller -> localhost | |         * X B o.|
2026-01-14 00:23:57.287690 | controller -> localhost | |        . O + * .|
2026-01-14 00:23:57.287760 | controller -> localhost | |       = O * + o |
2026-01-14 00:23:57.287811 | controller -> localhost | |    o = S X = .  |
2026-01-14 00:23:57.287853 | controller -> localhost | |   . E + o + o   |
2026-01-14 00:23:57.287894 | controller -> localhost | |    . o . . .    |
2026-01-14 00:23:57.287934 | controller -> localhost | |                 |
2026-01-14 00:23:57.287974 | controller -> localhost | |                 |
2026-01-14 00:23:57.288013 | controller -> localhost | +----[SHA256]-----+
2026-01-14 00:23:57.288126 | controller -> localhost | ok: Runtime: 0:00:00.008599
2026-01-14 00:23:57.304013 | 
2026-01-14 00:23:57.304197 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-14 00:23:57.346684 | controller | ok
2026-01-14 00:23:57.363304 | controller | included: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-14 00:23:57.377159 | 
2026-01-14 00:23:57.377299 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-14 00:23:57.403691 | controller | skipping: Conditional result was False
2026-01-14 00:23:57.411486 | 
2026-01-14 00:23:57.411598 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-14 00:23:58.343099 | controller | changed
2026-01-14 00:23:58.384570 | 
2026-01-14 00:23:58.384714 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-14 00:23:59.057172 | controller | ok
2026-01-14 00:23:59.073779 | 
2026-01-14 00:23:59.073973 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-14 00:24:02.129607 | controller | changed
2026-01-14 00:24:02.156070 | 
2026-01-14 00:24:02.156262 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-14 00:24:05.206092 | controller | changed
2026-01-14 00:24:05.221073 | 
2026-01-14 00:24:05.221193 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-14 00:24:05.247436 | controller | skipping: Conditional result was False
2026-01-14 00:24:05.257681 | 
2026-01-14 00:24:05.257834 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-14 00:24:05.498455 | controller -> localhost | changed
2026-01-14 00:24:05.510853 | 
2026-01-14 00:24:05.510961 | TASK [add-build-sshkey : Add back temp key]
2026-01-14 00:24:05.750546 | controller -> localhost | Identity added: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/8073fb89911049449292942dd8e3eea1_id_ecdsa (zuul-build-sshkey)
2026-01-14 00:24:05.750810 | controller -> localhost | ok: Runtime: 0:00:00.007908
2026-01-14 00:24:05.757877 | 
2026-01-14 00:24:05.757957 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-14 00:24:06.447430 | controller | ok
2026-01-14 00:24:06.454209 | 
2026-01-14 00:24:06.454279 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-14 00:24:06.488090 | controller | skipping: Conditional result was False
2026-01-14 00:24:06.499378 | 
2026-01-14 00:24:06.499461 | TASK [include_role : remove-zuul-sshkey]
2026-01-14 00:24:06.522628 | controller | skipping: Conditional result was False
2026-01-14 00:24:06.528748 | 
2026-01-14 00:24:06.528816 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-14 00:24:07.179409 | controller | ok: "logs"
2026-01-14 00:24:07.179645 | controller | ok: All items complete
2026-01-14 00:24:07.179682 | 
2026-01-14 00:24:07.807262 | controller | ok: "artifacts"
2026-01-14 00:24:08.412576 | controller | ok: "docs"
2026-01-14 00:24:08.429510 | 
2026-01-14 00:24:08.429634 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-14 00:24:09.071691 | controller | changed: "logs"
2026-01-14 00:24:09.708354 | controller | changed: "artifacts"
2026-01-14 00:24:10.340902 | controller | changed: "docs"
2026-01-14 00:24:10.401190 | 
2026-01-14 00:24:10.401301 | PLAY RECAP
2026-01-14 00:24:10.401357 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-14 00:24:10.401393 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-14 00:24:10.401419 | 
2026-01-14 00:24:10.543484 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-14 00:24:10.544674 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-14 00:24:11.123003 | 
2026-01-14 00:24:11.123177 | PLAY [all]
2026-01-14 00:24:11.146143 | 
2026-01-14 00:24:11.146463 | TASK [Install binary dependencies]
2026-01-14 00:24:11.216222 | controller | ok
2026-01-14 00:24:11.245854 | 
2026-01-14 00:24:11.246199 | TASK [bindep : Include find tasks]
2026-01-14 00:24:11.275598 | controller | ok
2026-01-14 00:24:11.293472 | controller | included: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-14 00:24:11.299752 | 
2026-01-14 00:24:11.299822 | TASK [bindep : Look for bindep.txt]
2026-01-14 00:24:12.211007 | controller | ok
2026-01-14 00:24:12.227428 | 
2026-01-14 00:24:12.227523 | TASK [bindep : Define bindep_file fact]
2026-01-14 00:24:12.241478 | controller | skipping: Conditional result was False
2026-01-14 00:24:12.247692 | 
2026-01-14 00:24:12.247781 | TASK [bindep : Look for other-requirements.txt]
2026-01-14 00:24:12.860661 | controller | ok
2026-01-14 00:24:12.870800 | 
2026-01-14 00:24:12.870881 | TASK [bindep : Define bindep_file fact]
2026-01-14 00:24:12.894444 | controller | skipping: Conditional result was False
2026-01-14 00:24:12.901265 | 
2026-01-14 00:24:12.901335 | TASK [bindep : Look for bindep fallback file]
2026-01-14 00:24:12.924666 | controller | skipping: Conditional result was False
2026-01-14 00:24:12.931021 | 
2026-01-14 00:24:12.931092 | TASK [bindep : Define bindep_file fact]
2026-01-14 00:24:12.954498 | controller | skipping: Conditional result was False
2026-01-14 00:24:12.961025 | 
2026-01-14 00:24:12.961089 | TASK [bindep : Include bindep tasks]
2026-01-14 00:24:12.984291 | controller | skipping: Conditional result was False
2026-01-14 00:24:12.990402 | 
2026-01-14 00:24:12.990466 | TASK [bindep : Include install tasks]
2026-01-14 00:24:13.013713 | controller | skipping: Conditional result was False
2026-01-14 00:24:13.022028 | 
2026-01-14 00:24:13.022111 | LOOP [bindep : Include package tasks]
2026-01-14 00:24:13.108293 | 
2026-01-14 00:24:13.108486 | TASK [Run test-setup role]
2026-01-14 00:24:13.143583 | controller | ok
2026-01-14 00:24:13.165741 | 
2026-01-14 00:24:13.165874 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-14 00:24:13.818628 | controller | ok
2026-01-14 00:24:13.824617 | 
2026-01-14 00:24:13.824681 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-14 00:24:14.180043 | controller | skipping: Conditional result was False
2026-01-14 00:24:14.206965 | 
2026-01-14 00:24:14.207030 | PLAY RECAP
2026-01-14 00:24:14.207070 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-14 00:24:14.207091 | 
2026-01-14 00:24:14.295188 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-14 00:24:14.296107 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-14 00:24:14.855499 | 
2026-01-14 00:24:14.855637 | PLAY [controller]
2026-01-14 00:24:14.881568 | 
2026-01-14 00:24:14.881696 | TASK [Create the /root directory]
2026-01-14 00:24:15.914562 | controller | ok
2026-01-14 00:24:15.923650 | 
2026-01-14 00:24:15.923801 | TASK [Install glibc-langpack-en]
2026-01-14 00:24:24.072921 | controller | ok: Nothing to do
2026-01-14 00:24:24.083229 | 
2026-01-14 00:24:24.083317 | TASK [Ensure controller directory exists]
2026-01-14 00:24:24.915293 | controller | changed
2026-01-14 00:24:24.928477 | 
2026-01-14 00:24:24.928643 | TASK [Install container runtime]
2026-01-14 00:24:25.009420 | controller | ok
2026-01-14 00:24:25.061267 | 
2026-01-14 00:24:25.061434 | LOOP [ensure-podman : Find distribution installation]
2026-01-14 00:24:25.103678 | controller | ok: "/var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-14 00:24:25.113041 | controller | included: /var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-14 00:24:25.119774 | 
2026-01-14 00:24:25.119878 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-14 00:26:21.434024 | controller | changed
2026-01-14 00:26:21.442539 | 
2026-01-14 00:26:21.442684 | TASK [ensure-podman : Fetch podman version]
2026-01-14 00:26:22.565650 | controller | Client:       Podman Engine
2026-01-14 00:26:22.596581 | controller | Version:      4.6.2
2026-01-14 00:26:22.596635 | controller | API Version:  4.6.2
2026-01-14 00:26:22.596644 | controller | Go Version:   go1.19.12
2026-01-14 00:26:22.596663 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-14 00:26:22.596671 | controller | OS/Arch:      linux/amd64
2026-01-14 00:26:22.811413 | controller | ok: Runtime: 0:00:00.269981
2026-01-14 00:26:22.822483 | 
2026-01-14 00:26:22.822608 | TASK [ensure-podman : Print podman version installed]
2026-01-14 00:26:22.857586 | Podman version: Client:       Podman Engine
2026-01-14 00:26:22.857895 | Version:      4.6.2
2026-01-14 00:26:22.857940 | API Version:  4.6.2
2026-01-14 00:26:22.857970 | Go Version:   go1.19.12
2026-01-14 00:26:22.857996 | Built:        Mon Aug 28 19:38:31 2023
2026-01-14 00:26:22.858025 | OS/Arch:      linux/amd64
2026-01-14 00:26:22.871600 | 
2026-01-14 00:26:22.871715 | TASK [ensure-podman : Validate podman engine]
2026-01-14 00:26:23.232829 | controller | skipping: Conditional result was False
2026-01-14 00:26:23.249081 | 
2026-01-14 00:26:23.249318 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-14 00:26:23.278120 | controller | skipping: Conditional result was False
2026-01-14 00:26:23.320098 | 
2026-01-14 00:26:23.320240 | TASK [Ensure python3.8 is present]
2026-01-14 00:26:23.347926 | controller | skipping: Conditional result was False
2026-01-14 00:26:23.356877 | 
2026-01-14 00:26:23.357016 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-14 00:26:23.380248 | controller | ok
2026-01-14 00:26:23.403870 | 
2026-01-14 00:26:23.403991 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-14 00:26:26.701639 | controller | ok: Nothing to do
2026-01-14 00:26:26.714392 | 
2026-01-14 00:26:26.714537 | TASK [our-ensure-python : Also install python3-devel]
2026-01-14 00:26:42.520881 | controller | changed
2026-01-14 00:26:42.537412 | 
2026-01-14 00:26:42.537506 | TASK [Run ensure-virtualenv role]
2026-01-14 00:26:42.559775 | controller | ok
2026-01-14 00:26:42.590351 | 
2026-01-14 00:26:42.590496 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-14 00:26:43.361630 | controller | /usr/bin/virtualenv
2026-01-14 00:26:43.972314 | controller | ok: Runtime: 0:00:00.004455
2026-01-14 00:26:43.988394 | 
2026-01-14 00:26:43.988588 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-14 00:26:44.023608 | controller | skipping: Conditional result was False
2026-01-14 00:26:44.024067 | controller | ok: All items complete
2026-01-14 00:26:44.024130 | 
2026-01-14 00:26:44.052441 | 
2026-01-14 00:26:44.052626 | TASK [Find the full path of the Python interpreter]
2026-01-14 00:26:44.832881 | controller | /usr/bin/python3
2026-01-14 00:26:45.418496 | controller | ok
2026-01-14 00:26:45.430662 | 
2026-01-14 00:26:45.430865 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-14 00:26:47.441284 | controller | created virtual environment CPython3.11.0.final.0-64 in 981ms
2026-01-14 00:26:47.526743 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-14 00:26:47.526798 | 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-14 00:26:47.526815 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-14 00:26:47.526837 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-14 00:26:47.815134 | controller | changed
2026-01-14 00:26:47.828491 | 
2026-01-14 00:26:47.828652 | TASK [Set selinux package]
2026-01-14 00:26:47.867176 | controller | ok
2026-01-14 00:26:47.878314 | 
2026-01-14 00:26:47.878455 | TASK [Set selinux package (Fedora)]
2026-01-14 00:26:47.928821 | controller | ok
2026-01-14 00:26:47.940959 | 
2026-01-14 00:26:47.941112 | TASK [Install selinux into virtualenv]
2026-01-14 00:26:51.180539 | controller | Collecting selinux-please-lie-to-me
2026-01-14 00:26:51.253048 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-14 00:26:51.823212 | controller | Collecting setuptools<50.0.0
2026-01-14 00:26:51.829685 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-14 00:26:51.886985 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.4 MB/s eta 0:00:00
2026-01-14 00:26:52.035981 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-14 00:26:52.036296 | controller |   Attempting uninstall: setuptools
2026-01-14 00:26:52.039907 | controller |     Found existing installation: setuptools 62.6.0
2026-01-14 00:26:52.147066 | controller |     Uninstalling setuptools-62.6.0:
2026-01-14 00:26:52.162780 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-14 00:26:52.926430 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-14 00:26:53.162652 | controller |
2026-01-14 00:26:53.434607 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-14 00:26:53.434659 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-14 00:26:53.846244 | controller | ok: Runtime: 0:00:04.684142
2026-01-14 00:26:53.852319 | 
2026-01-14 00:26:53.852385 | TASK [Install pytest-forked into virtualenv]
2026-01-14 00:26:55.353968 | controller | Collecting pytest-forked
2026-01-14 00:26:55.416448 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-14 00:26:55.473324 | controller | Collecting py
2026-01-14 00:26:55.479951 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-14 00:26:55.514399 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.9 MB/s eta 0:00:00
2026-01-14 00:26:55.726000 | controller | Collecting pytest>=3.10
2026-01-14 00:26:55.735568 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-14 00:26:55.760544 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 18.1 MB/s eta 0:00:00
2026-01-14 00:26:55.833503 | controller | Collecting iniconfig>=1.0.1
2026-01-14 00:26:55.837802 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-14 00:26:55.907261 | controller | Collecting packaging>=22
2026-01-14 00:26:55.911776 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-14 00:26:55.930651 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 4.4 MB/s eta 0:00:00
2026-01-14 00:26:55.992555 | controller | Collecting pluggy<2,>=1.5
2026-01-14 00:26:55.999417 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-14 00:26:56.107648 | controller | Collecting pygments>=2.7.2
2026-01-14 00:26:56.112750 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-14 00:26:56.150677 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 38.8 MB/s eta 0:00:00
2026-01-14 00:26:56.322457 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-14 00:26:58.811138 | 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-14 00:26:58.826966 | controller |
2026-01-14 00:26:59.079908 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-14 00:26:59.080002 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-14 00:26:59.235173 | controller | ok: Runtime: 0:00:04.419194
2026-01-14 00:26:59.247860 | 
2026-01-14 00:26:59.247996 | TASK [Update pip]
2026-01-14 00:27:00.572252 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-14 00:27:00.907680 | controller | Collecting pip
2026-01-14 00:27:00.972101 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-14 00:27:01.053577 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 22.9 MB/s eta 0:00:00
2026-01-14 00:27:01.179924 | controller | Installing collected packages: pip
2026-01-14 00:27:01.180086 | controller |   Attempting uninstall: pip
2026-01-14 00:27:01.185407 | controller |     Found existing installation: pip 22.2.2
2026-01-14 00:27:01.408794 | controller |     Uninstalling pip-22.2.2:
2026-01-14 00:27:01.435058 | controller |       Successfully uninstalled pip-22.2.2
2026-01-14 00:27:03.298253 | controller | Successfully installed pip-25.3
2026-01-14 00:27:04.139485 | controller | ok: Runtime: 0:00:03.494280
2026-01-14 00:27:04.152026 | 
2026-01-14 00:27:04.152161 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-14 00:27:05.120225 | controller | changed
2026-01-14 00:27:05.132567 | 
2026-01-14 00:27:05.132713 | TASK [Install ansible into virtualenv]
2026-01-14 00:27:06.304976 | controller | Processing ./src/github.com/ansible/ansible
2026-01-14 00:27:06.309915 | controller |   Installing build dependencies: started
2026-01-14 00:27:08.101773 | controller |   Installing build dependencies: finished with status 'done'
2026-01-14 00:27:09.552405 | controller |   Getting requirements to build wheel: started
2026-01-14 00:27:09.552465 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-14 00:27:10.455037 | controller |   Preparing metadata (pyproject.toml): started
2026-01-14 00:27:10.455088 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-14 00:27:10.456578 | 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-14 00:27:10.461213 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-14 00:27:11.018013 | controller | ERROR
2026-01-14 00:27:11.018438 | controller | {
2026-01-14 00:27:11.018516 | controller |   "delta": "0:00:04.854789",
2026-01-14 00:27:11.018565 | controller |   "end": "2026-01-14 00:27:10.624757",
2026-01-14 00:27:11.018606 | controller |   "msg": "non-zero return code",
2026-01-14 00:27:11.018662 | controller |   "rc": 1,
2026-01-14 00:27:11.018703 | controller |   "start": "2026-01-14 00:27:05.769968"
2026-01-14 00:27:11.018782 | controller | }
failure
2026-01-14 00:27:11.026158 | 
2026-01-14 00:27:11.026270 | PLAY RECAP
2026-01-14 00:27:11.026356 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-14 00:27:11.026401 | 
2026-01-14 00:27:11.144599 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-14 00:27:11.145584 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-14 00:27:11.708077 | 
2026-01-14 00:27:11.708198 | PLAY [all]
2026-01-14 00:27:11.729641 | 
2026-01-14 00:27:11.729767 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-14 00:27:13.585167 | controller | changed: non-zero return code
2026-01-14 00:27:13.599711 | 
2026-01-14 00:27:13.599958 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-14 00:27:13.629144 | controller | skipping: Conditional result was False
2026-01-14 00:27:13.639186 | 
2026-01-14 00:27:13.639298 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-14 00:27:13.677398 | 
2026-01-14 00:27:13.677623 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-14 00:27:13.719469 | 
2026-01-14 00:27:13.719787 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-14 00:27:13.736750 | controller | skipping: Conditional result was False
2026-01-14 00:27:13.747754 | 
2026-01-14 00:27:13.747886 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-14 00:27:13.781435 | 
2026-01-14 00:27:13.781655 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-14 00:27:13.806505 | controller | skipping: Conditional result was False
2026-01-14 00:27:13.815674 | 
2026-01-14 00:27:13.815805 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-14 00:27:13.831705 | controller | skipping: Conditional result was False
2026-01-14 00:27:13.842325 | 
2026-01-14 00:27:13.842439 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-14 00:27:13.867156 | controller | skipping: Conditional result was False
2026-01-14 00:27:13.906171 | 
2026-01-14 00:27:13.906303 | PLAY RECAP
2026-01-14 00:27:13.906366 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-14 00:27:13.906401 | 
2026-01-14 00:27:14.005646 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-14 00:27:14.006775 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-14 00:27:14.619858 | 
2026-01-14 00:27:14.619973 | PLAY [all:!appliance*]
2026-01-14 00:27:14.641537 | 
2026-01-14 00:27:14.641625 | TASK [unregister the node]
2026-01-14 00:27:14.991671 | controller | skipping: Conditional result was False
2026-01-14 00:27:14.999657 | 
2026-01-14 00:27:14.999781 | TASK [include_role : fetch-output]
2026-01-14 00:27:15.031991 | controller | ok
2026-01-14 00:27:15.058229 | 
2026-01-14 00:27:15.058344 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-14 00:27:15.113425 | controller | skipping: Conditional result was False
2026-01-14 00:27:15.119362 | 
2026-01-14 00:27:15.119432 | TASK [fetch-output : Set log path for single node]
2026-01-14 00:27:15.160490 | controller | ok
2026-01-14 00:27:15.167956 | 
2026-01-14 00:27:15.168137 | LOOP [fetch-output : Ensure local output dirs]
2026-01-14 00:27:15.589236 | controller -> localhost | ok: "/var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/logs"
2026-01-14 00:27:15.815834 | controller -> localhost | changed: "/var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/artifacts"
2026-01-14 00:27:16.022826 | controller -> localhost | changed: "/var/lib/zuul/builds/8073fb89911049449292942dd8e3eea1/work/docs"
2026-01-14 00:27:16.037800 | 
2026-01-14 00:27:16.037911 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-14 00:27:18.285766 | controller | changed:
2026-01-14 00:27:18.285961 | controller | .d..t...... ./
2026-01-14 00:27:18.285989 | controller | cd+++++++++ controller/
2026-01-14 00:27:18.286020 | controller | changed: All items complete
2026-01-14 00:27:18.286039 | 
2026-01-14 00:27:20.334220 | controller | changed: .d..t...... ./
2026-01-14 00:27:22.421448 | controller | changed: .d..t...... ./
2026-01-14 00:27:22.455991 | 
2026-01-14 00:27:22.456213 | TASK [include_role : fetch-output-openshift]
2026-01-14 00:27:22.483228 | controller | skipping: Conditional result was False
2026-01-14 00:27:22.499022 | 
2026-01-14 00:27:22.499211 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-14 00:27:22.551496 | controller | skipping: Conditional result was False
2026-01-14 00:27:22.565153 | controller | skipping: Conditional result was False
2026-01-14 00:27:22.623687 | 
2026-01-14 00:27:22.623839 | PLAY [localhost]
2026-01-14 00:27:22.641589 | 
2026-01-14 00:27:22.641716 | TASK [Run Zuul manifest role]
2026-01-14 00:27:22.661881 | localhost | ok
2026-01-14 00:27:22.680197 | 
2026-01-14 00:27:22.680306 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-14 00:27:23.025079 | localhost | changed
2026-01-14 00:27:23.029865 | 
2026-01-14 00:27:23.029936 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-14 00:27:23.057898 | localhost | ok
2026-01-14 00:27:23.066149 | 
2026-01-14 00:27:23.066216 | TASK [Set zuul-log-path fact]
2026-01-14 00:27:23.084053 | localhost | ok
2026-01-14 00:27:23.120712 | 
2026-01-14 00:27:23.120838 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-14 00:27:23.148932 | localhost | ok
2026-01-14 00:27:23.157010 | 
2026-01-14 00:27:23.157077 | LOOP [Run upload-logs-swift role]
2026-01-14 00:27:23.182106 | localhost | Output suppressed because no_log was given
2026-01-14 00:27:23.206498 | 
2026-01-14 00:27:23.206591 | TASK [Set zuul-log-path fact]
2026-01-14 00:27:23.240754 | localhost | skipping: Conditional result was False
2026-01-14 00:27:23.247066 | 
2026-01-14 00:27:23.247149 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-14 00:27:23.628499 | localhost -> localhost | ok: Runtime: 0:00:00.008531
2026-01-14 00:27:23.640493 | 
2026-01-14 00:27:23.640653 | TASK [upload-logs-swift : Upload logs to swift]