2026-01-07 00:06:39.516633 | Job console starting...
2026-01-07 00:06:39.525760 | Updating repositories
2026-01-07 00:06:40.687332 | Preparing job workspace
2026-01-07 00:06:44.608549 | Running Ansible setup...
2026-01-07 00:06:49.241092 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-07 00:06:49.920433 | 
2026-01-07 00:06:49.920624 | PLAY [localhost]
2026-01-07 00:06:49.930858 | 
2026-01-07 00:06:49.930983 | TASK [Gathering Facts]
2026-01-07 00:06:50.951200 | localhost | ok
2026-01-07 00:06:50.969606 | 
2026-01-07 00:06:50.969733 | TASK [Setup log path fact]
2026-01-07 00:06:51.000265 | localhost | ok
2026-01-07 00:06:51.012746 | 
2026-01-07 00:06:51.012983 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-07 00:06:51.040335 | localhost | ok
2026-01-07 00:06:51.048635 | 
2026-01-07 00:06:51.048703 | TASK [emit-job-header : Print job information]
2026-01-07 00:06:51.077380 | # Job Information
2026-01-07 00:06:51.077596 | Ansible Version: 2.15.12
2026-01-07 00:06:51.077634 | Job: ansible-test-sanity-docker-milestone
2026-01-07 00:06:51.077656 | Pipeline: periodic
2026-01-07 00:06:51.077676 | Executor: ze01.softwarefactory-project.io
2026-01-07 00:06:51.077695 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-07 00:06:51.077717 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/662/ansible/662e025151ea4b8cbc84dd2c3b7a8978/
2026-01-07 00:06:51.077738 | Event ID: 087827c9b28a45b7af9092d2d6250d5f
2026-01-07 00:06:51.081521 | 
2026-01-07 00:06:51.081591 | LOOP [emit-job-header : Print node information]
2026-01-07 00:06:51.189367 | localhost | ok:
2026-01-07 00:06:51.189525 | localhost | # Node Information
2026-01-07 00:06:51.189553 | localhost | Inventory Hostname: controller
2026-01-07 00:06:51.189573 | localhost | Hostname: np0005576211
2026-01-07 00:06:51.189593 | localhost | Username: zuul
2026-01-07 00:06:51.189615 | localhost | Distro: Fedora 37
2026-01-07 00:06:51.189634 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-07 00:06:51.189658 | localhost | Region: ca-ymq-1
2026-01-07 00:06:51.189684 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-07 00:06:51.189707 | localhost | Product Name: OpenStack Nova
2026-01-07 00:06:51.189729 | localhost | Interface IP: 162.253.55.213
2026-01-07 00:06:51.201863 | 
2026-01-07 00:06:51.201989 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-07 00:06:51.703088 | localhost -> localhost | changed
2026-01-07 00:06:51.720640 | 
2026-01-07 00:06:51.720759 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-07 00:06:52.771460 | localhost -> localhost | changed
2026-01-07 00:06:52.791366 | 
2026-01-07 00:06:52.791443 | PLAY [all:!appliance*]
2026-01-07 00:06:52.807816 | 
2026-01-07 00:06:52.807933 | TASK [include_role : start-zuul-console]
2026-01-07 00:06:52.831840 | controller | ok
2026-01-07 00:06:52.846101 | 
2026-01-07 00:06:52.846208 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-07 00:06:53.212510 | controller | ok
2026-01-07 00:06:53.223809 | 
2026-01-07 00:06:53.223913 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-07 00:06:53.986797 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-07 00:06:53.994191 | 
2026-01-07 00:06:53.994269 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-07 00:06:54.530230 | controller | skipping: Conditional result was False
2026-01-07 00:06:54.536413 | 
2026-01-07 00:06:54.536492 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-07 00:06:54.570375 | controller | skipping: Conditional result was False
2026-01-07 00:06:54.576742 | 
2026-01-07 00:06:54.576832 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-07 00:06:54.600674 | controller | skipping: Conditional result was False
2026-01-07 00:06:54.606743 | 
2026-01-07 00:06:54.606836 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-07 00:06:54.632125 | controller | skipping: Conditional result was False
2026-01-07 00:06:54.639268 | 
2026-01-07 00:06:54.639387 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-07 00:06:54.664315 | controller | skipping: Conditional result was False
2026-01-07 00:06:54.672200 | 
2026-01-07 00:06:54.672353 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-07 00:06:54.709055 | controller | skipping: Conditional result was False
2026-01-07 00:06:54.722721 | 
2026-01-07 00:06:54.722878 | TASK [Disable Fedora Modular]
2026-01-07 00:06:54.977614 | controller | changed
2026-01-07 00:06:54.983631 | 
2026-01-07 00:06:54.983729 | TASK [Enable EPEL]
2026-01-07 00:06:55.008459 | controller | skipping: Conditional result was False
2026-01-07 00:06:55.014656 | 
2026-01-07 00:06:55.014755 | TASK [Register the RHEL node]
2026-01-07 00:06:55.557810 | 
2026-01-07 00:06:55.558114 | TASK [Show the subscription-manager status]
2026-01-07 00:06:56.122807 | controller | skipping: Conditional result was False
2026-01-07 00:06:56.140983 | 
2026-01-07 00:06:56.141198 | TASK [Enable EPEL on RHEL]
2026-01-07 00:06:56.689752 | controller | skipping: Conditional result was False
2026-01-07 00:06:56.699726 | 
2026-01-07 00:06:56.699844 | TASK [Install git and tox]
2026-01-07 00:08:20.807609 | controller | changed
2026-01-07 00:08:20.822975 | 
2026-01-07 00:08:20.823195 | TASK [include_role : prepare-workspace]
2026-01-07 00:08:20.862263 | controller | ok
2026-01-07 00:08:20.896606 | 
2026-01-07 00:08:20.896717 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-07 00:08:21.142225 | controller | ok
2026-01-07 00:08:21.150471 | 
2026-01-07 00:08:21.150557 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-07 00:08:34.968066 | controller | Output suppressed because no_log was given
2026-01-07 00:08:34.985003 | 
2026-01-07 00:08:34.985281 | TASK [include_role : prepare-workspace-openshift]
2026-01-07 00:08:35.001360 | controller | skipping: Conditional result was False
2026-01-07 00:08:35.070398 | 
2026-01-07 00:08:35.070496 | PLAY [all:!appliance]
2026-01-07 00:08:35.087986 | 
2026-01-07 00:08:35.088093 | TASK [Run add-build-sshkey role (RSA)]
2026-01-07 00:08:35.107842 | controller | ok
2026-01-07 00:08:35.124870 | 
2026-01-07 00:08:35.124959 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-07 00:08:35.373970 | controller -> localhost | ok
2026-01-07 00:08:35.380976 | 
2026-01-07 00:08:35.381062 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-07 00:08:35.415860 | controller | ok
2026-01-07 00:08:35.456352 | controller | included: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-07 00:08:35.463962 | 
2026-01-07 00:08:35.464063 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-07 00:08:35.975843 | controller -> localhost | Generating public/private rsa key pair.
2026-01-07 00:08:35.976079 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/662e025151ea4b8cbc84dd2c3b7a8978_id_rsa.
2026-01-07 00:08:35.976111 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/662e025151ea4b8cbc84dd2c3b7a8978_id_rsa.pub.
2026-01-07 00:08:35.976132 | controller -> localhost | The key fingerprint is:
2026-01-07 00:08:35.976150 | controller -> localhost | SHA256:mYdN5DOkKY7mQxIRkMbEWasaI3DcUVLoYWsYOjTVgEI zuul-build-sshkey
2026-01-07 00:08:35.976169 | controller -> localhost | The key's randomart image is:
2026-01-07 00:08:35.976192 | controller -> localhost | +---[RSA 2048]----+
2026-01-07 00:08:35.976216 | controller -> localhost | |*EB==+o   o      |
2026-01-07 00:08:35.976240 | controller -> localhost | |oX.o=+   *       |
2026-01-07 00:08:35.976264 | controller -> localhost | |=.=*.o. o =      |
2026-01-07 00:08:35.976288 | controller -> localhost | |+.o.+o . * o     |
2026-01-07 00:08:35.976311 | controller -> localhost | |+o..+ . S o      |
2026-01-07 00:08:35.976345 | controller -> localhost | |oo =     .       |
2026-01-07 00:08:35.976374 | controller -> localhost | |.   o            |
2026-01-07 00:08:35.976398 | controller -> localhost | |     .           |
2026-01-07 00:08:35.976421 | controller -> localhost | |                 |
2026-01-07 00:08:35.976447 | controller -> localhost | +----[SHA256]-----+
2026-01-07 00:08:35.976504 | controller -> localhost | ok: Runtime: 0:00:00.147268
2026-01-07 00:08:35.983919 | 
2026-01-07 00:08:35.984002 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-07 00:08:36.005539 | controller | ok
2026-01-07 00:08:36.015696 | controller | included: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-07 00:08:36.025033 | 
2026-01-07 00:08:36.025103 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-07 00:08:36.049125 | controller | skipping: Conditional result was False
2026-01-07 00:08:36.057084 | 
2026-01-07 00:08:36.057172 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-07 00:08:36.522302 | controller | changed
2026-01-07 00:08:36.536392 | 
2026-01-07 00:08:36.536593 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-07 00:08:36.771799 | controller | ok
2026-01-07 00:08:36.785221 | 
2026-01-07 00:08:36.785396 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-07 00:08:37.429930 | controller | changed
2026-01-07 00:08:37.443532 | 
2026-01-07 00:08:37.443694 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-07 00:08:38.091586 | controller | changed
2026-01-07 00:08:38.100141 | 
2026-01-07 00:08:38.100231 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-07 00:08:38.138228 | controller | skipping: Conditional result was False
2026-01-07 00:08:38.149703 | 
2026-01-07 00:08:38.149883 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-07 00:08:38.597567 | controller -> localhost | changed
2026-01-07 00:08:38.611096 | 
2026-01-07 00:08:38.611220 | TASK [add-build-sshkey : Add back temp key]
2026-01-07 00:08:38.879483 | controller -> localhost | Identity added: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/662e025151ea4b8cbc84dd2c3b7a8978_id_rsa (zuul-build-sshkey)
2026-01-07 00:08:38.879682 | controller -> localhost | ok: Runtime: 0:00:00.007092
2026-01-07 00:08:38.886593 | 
2026-01-07 00:08:38.886658 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-07 00:08:39.211578 | controller | ok
2026-01-07 00:08:39.216907 | 
2026-01-07 00:08:39.216971 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-07 00:08:39.252759 | controller | skipping: Conditional result was False
2026-01-07 00:08:39.265346 | 
2026-01-07 00:08:39.265439 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-07 00:08:39.289212 | controller | ok
2026-01-07 00:08:39.306098 | 
2026-01-07 00:08:39.306200 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-07 00:08:39.535164 | controller -> localhost | ok
2026-01-07 00:08:39.542139 | 
2026-01-07 00:08:39.542237 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-07 00:08:39.572856 | controller | ok
2026-01-07 00:08:39.583756 | controller | included: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-07 00:08:39.589629 | 
2026-01-07 00:08:39.589722 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-07 00:08:39.848033 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-07 00:08:39.848225 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/662e025151ea4b8cbc84dd2c3b7a8978_id_ecdsa.
2026-01-07 00:08:39.848254 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/662e025151ea4b8cbc84dd2c3b7a8978_id_ecdsa.pub.
2026-01-07 00:08:39.848287 | controller -> localhost | The key fingerprint is:
2026-01-07 00:08:39.848308 | controller -> localhost | SHA256:KWtIS1bnKbZ06R9Yh95qQiAE5CtFnSiZ4i7vhU15b2Y zuul-build-sshkey
2026-01-07 00:08:39.848327 | controller -> localhost | The key's randomart image is:
2026-01-07 00:08:39.848346 | controller -> localhost | +---[ECDSA 521]---+
2026-01-07 00:08:39.848364 | controller -> localhost | | +++ .           |
2026-01-07 00:08:39.848382 | controller -> localhost | |=o. +            |
2026-01-07 00:08:39.848400 | controller -> localhost | |o.o.  . .        |
2026-01-07 00:08:39.848418 | controller -> localhost | | o ..o.o + .     |
2026-01-07 00:08:39.848435 | controller -> localhost | |o . *.*.S o .    |
2026-01-07 00:08:39.848452 | controller -> localhost | |.o B * O.+ o     |
2026-01-07 00:08:39.848469 | controller -> localhost | |... = +.E o .    |
2026-01-07 00:08:39.848487 | controller -> localhost | |  .. . +...o     |
2026-01-07 00:08:39.848504 | controller -> localhost | | ..      oo      |
2026-01-07 00:08:39.848521 | controller -> localhost | +----[SHA256]-----+
2026-01-07 00:08:39.848566 | controller -> localhost | ok: Runtime: 0:00:00.009540
2026-01-07 00:08:39.855537 | 
2026-01-07 00:08:39.855621 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-07 00:08:39.887625 | controller | ok
2026-01-07 00:08:39.895489 | controller | included: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-07 00:08:39.904806 | 
2026-01-07 00:08:39.904873 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-07 00:08:39.930649 | controller | skipping: Conditional result was False
2026-01-07 00:08:39.937604 | 
2026-01-07 00:08:39.937675 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-07 00:08:40.193641 | controller | changed
2026-01-07 00:08:40.202391 | 
2026-01-07 00:08:40.202699 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-07 00:08:40.429659 | controller | ok
2026-01-07 00:08:40.435752 | 
2026-01-07 00:08:40.435831 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-07 00:08:41.057752 | controller | changed
2026-01-07 00:08:41.072478 | 
2026-01-07 00:08:41.072614 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-07 00:08:41.680648 | controller | changed
2026-01-07 00:08:41.689953 | 
2026-01-07 00:08:41.690094 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-07 00:08:41.705387 | controller | skipping: Conditional result was False
2026-01-07 00:08:41.715330 | 
2026-01-07 00:08:41.715430 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-07 00:08:41.955477 | controller -> localhost | changed
2026-01-07 00:08:41.986057 | 
2026-01-07 00:08:41.986197 | TASK [add-build-sshkey : Add back temp key]
2026-01-07 00:08:42.316979 | controller -> localhost | Identity added: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/662e025151ea4b8cbc84dd2c3b7a8978_id_ecdsa (zuul-build-sshkey)
2026-01-07 00:08:42.317212 | controller -> localhost | ok: Runtime: 0:00:00.007565
2026-01-07 00:08:42.370390 | 
2026-01-07 00:08:42.370509 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-07 00:08:42.586679 | controller | ok
2026-01-07 00:08:42.593382 | 
2026-01-07 00:08:42.593519 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-07 00:08:42.619506 | controller | skipping: Conditional result was False
2026-01-07 00:08:42.646255 | 
2026-01-07 00:08:42.646441 | TASK [include_role : remove-zuul-sshkey]
2026-01-07 00:08:42.681936 | controller | skipping: Conditional result was False
2026-01-07 00:08:42.692913 | 
2026-01-07 00:08:42.693079 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-07 00:08:42.919208 | controller | ok: "logs"
2026-01-07 00:08:42.919518 | controller | ok: All items complete
2026-01-07 00:08:42.919905 | 
2026-01-07 00:08:43.101487 | controller | ok: "artifacts"
2026-01-07 00:08:43.305109 | controller | ok: "docs"
2026-01-07 00:08:43.327303 | 
2026-01-07 00:08:43.327500 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-07 00:08:43.563160 | controller | changed: "logs"
2026-01-07 00:08:43.746203 | controller | changed: "artifacts"
2026-01-07 00:08:43.941618 | controller | changed: "docs"
2026-01-07 00:08:43.990936 | 
2026-01-07 00:08:43.991079 | PLAY RECAP
2026-01-07 00:08:43.991143 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-07 00:08:43.991185 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-07 00:08:43.991212 | 
2026-01-07 00:08:44.117292 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-07 00:08:44.118219 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-07 00:08:44.753274 | 
2026-01-07 00:08:44.753402 | PLAY [all]
2026-01-07 00:08:44.778316 | 
2026-01-07 00:08:44.778453 | TASK [Install binary dependencies]
2026-01-07 00:08:44.832937 | controller | ok
2026-01-07 00:08:44.854130 | 
2026-01-07 00:08:44.854270 | TASK [bindep : Include find tasks]
2026-01-07 00:08:44.895508 | controller | ok
2026-01-07 00:08:44.905101 | controller | included: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-07 00:08:44.912053 | 
2026-01-07 00:08:44.912157 | TASK [bindep : Look for bindep.txt]
2026-01-07 00:08:45.272618 | controller | ok
2026-01-07 00:08:45.283887 | 
2026-01-07 00:08:45.284048 | TASK [bindep : Define bindep_file fact]
2026-01-07 00:08:45.309628 | controller | skipping: Conditional result was False
2026-01-07 00:08:45.315840 | 
2026-01-07 00:08:45.315934 | TASK [bindep : Look for other-requirements.txt]
2026-01-07 00:08:45.540264 | controller | ok
2026-01-07 00:08:45.546873 | 
2026-01-07 00:08:45.546995 | TASK [bindep : Define bindep_file fact]
2026-01-07 00:08:45.581680 | controller | skipping: Conditional result was False
2026-01-07 00:08:45.590196 | 
2026-01-07 00:08:45.590310 | TASK [bindep : Look for bindep fallback file]
2026-01-07 00:08:45.615286 | controller | skipping: Conditional result was False
2026-01-07 00:08:45.623085 | 
2026-01-07 00:08:45.623172 | TASK [bindep : Define bindep_file fact]
2026-01-07 00:08:45.656985 | controller | skipping: Conditional result was False
2026-01-07 00:08:45.665230 | 
2026-01-07 00:08:45.665320 | TASK [bindep : Include bindep tasks]
2026-01-07 00:08:45.700153 | controller | skipping: Conditional result was False
2026-01-07 00:08:45.714664 | 
2026-01-07 00:08:45.714811 | TASK [bindep : Include install tasks]
2026-01-07 00:08:45.739923 | controller | skipping: Conditional result was False
2026-01-07 00:08:45.746650 | 
2026-01-07 00:08:45.746753 | LOOP [bindep : Include package tasks]
2026-01-07 00:08:45.815845 | 
2026-01-07 00:08:45.816030 | TASK [Run test-setup role]
2026-01-07 00:08:45.839793 | controller | ok
2026-01-07 00:08:45.865621 | 
2026-01-07 00:08:45.865761 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-07 00:08:46.095303 | controller | ok
2026-01-07 00:08:46.104239 | 
2026-01-07 00:08:46.104338 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-07 00:08:46.644279 | controller | skipping: Conditional result was False
2026-01-07 00:08:46.694129 | 
2026-01-07 00:08:46.694304 | PLAY RECAP
2026-01-07 00:08:46.694387 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-07 00:08:46.694432 | 
2026-01-07 00:08:46.817784 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-07 00:08:46.818695 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-07 00:08:47.428294 | 
2026-01-07 00:08:47.428440 | PLAY [controller]
2026-01-07 00:08:47.449461 | 
2026-01-07 00:08:47.449588 | TASK [Create the /root directory]
2026-01-07 00:08:47.874299 | controller | ok
2026-01-07 00:08:47.882837 | 
2026-01-07 00:08:47.882971 | TASK [Install glibc-langpack-en]
2026-01-07 00:08:51.829660 | controller | ok: Nothing to do
2026-01-07 00:08:51.841963 | 
2026-01-07 00:08:51.842168 | TASK [Ensure controller directory exists]
2026-01-07 00:08:52.064841 | controller | changed
2026-01-07 00:08:52.078759 | 
2026-01-07 00:08:52.078925 | TASK [Install container runtime]
2026-01-07 00:08:52.146381 | controller | ok
2026-01-07 00:08:52.196159 | 
2026-01-07 00:08:52.196268 | LOOP [ensure-podman : Find distribution installation]
2026-01-07 00:08:52.218348 | controller | ok: "/var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-07 00:08:52.226738 | controller | included: /var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-07 00:08:52.233777 | 
2026-01-07 00:08:52.233853 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-07 00:09:59.524366 | controller | changed
2026-01-07 00:09:59.531079 | 
2026-01-07 00:09:59.531147 | TASK [ensure-podman : Fetch podman version]
2026-01-07 00:10:00.059630 | controller | Client:       Podman Engine
2026-01-07 00:10:00.086085 | controller | Version:      4.6.2
2026-01-07 00:10:00.086106 | controller | API Version:  4.6.2
2026-01-07 00:10:00.086113 | controller | Go Version:   go1.19.12
2026-01-07 00:10:00.086133 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-07 00:10:00.086142 | controller | OS/Arch:      linux/amd64
2026-01-07 00:10:00.563863 | controller | ok: Runtime: 0:00:00.196621
2026-01-07 00:10:00.578701 | 
2026-01-07 00:10:00.578849 | TASK [ensure-podman : Print podman version installed]
2026-01-07 00:10:00.619286 | Podman version: Client:       Podman Engine
2026-01-07 00:10:00.619628 | Version:      4.6.2
2026-01-07 00:10:00.619694 | API Version:  4.6.2
2026-01-07 00:10:00.619738 | Go Version:   go1.19.12
2026-01-07 00:10:00.619778 | Built:        Mon Aug 28 19:38:31 2023
2026-01-07 00:10:00.619823 | OS/Arch:      linux/amd64
2026-01-07 00:10:00.635567 | 
2026-01-07 00:10:00.635733 | TASK [ensure-podman : Validate podman engine]
2026-01-07 00:10:01.180550 | controller | skipping: Conditional result was False
2026-01-07 00:10:01.194620 | 
2026-01-07 00:10:01.194782 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-07 00:10:01.221744 | controller | skipping: Conditional result was False
2026-01-07 00:10:01.247768 | 
2026-01-07 00:10:01.247924 | TASK [Ensure python3.8 is present]
2026-01-07 00:10:01.274237 | controller | skipping: Conditional result was False
2026-01-07 00:10:01.288239 | 
2026-01-07 00:10:01.288384 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-07 00:10:01.309952 | controller | ok
2026-01-07 00:10:01.341050 | 
2026-01-07 00:10:01.341165 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-07 00:10:02.776069 | controller | ok: Nothing to do
2026-01-07 00:10:02.790742 | 
2026-01-07 00:10:02.790909 | TASK [our-ensure-python : Also install python3-devel]
2026-01-07 00:10:12.500739 | controller | changed
2026-01-07 00:10:12.516637 | 
2026-01-07 00:10:12.516754 | TASK [Run ensure-virtualenv role]
2026-01-07 00:10:12.537283 | controller | ok
2026-01-07 00:10:12.561799 | 
2026-01-07 00:10:12.561917 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-07 00:10:12.774940 | controller | /usr/bin/virtualenv
2026-01-07 00:10:13.096489 | controller | ok: Runtime: 0:00:00.005467
2026-01-07 00:10:13.131976 | 
2026-01-07 00:10:13.132141 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-07 00:10:13.156249 | controller | skipping: Conditional result was False
2026-01-07 00:10:13.156520 | controller | ok: All items complete
2026-01-07 00:10:13.156548 | 
2026-01-07 00:10:13.170179 | 
2026-01-07 00:10:13.170322 | TASK [Find the full path of the Python interpreter]
2026-01-07 00:10:13.375332 | controller | /usr/bin/python3
2026-01-07 00:10:13.701569 | controller | ok
2026-01-07 00:10:13.710447 | 
2026-01-07 00:10:13.710587 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-07 00:10:14.630072 | controller | created virtual environment CPython3.11.0.final.0-64 in 494ms
2026-01-07 00:10:14.656202 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-07 00:10:14.656272 | 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-07 00:10:14.656283 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-07 00:10:14.656298 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-07 00:10:14.758974 | controller | changed
2026-01-07 00:10:14.773438 | 
2026-01-07 00:10:14.773611 | TASK [Set selinux package]
2026-01-07 00:10:14.812616 | controller | ok
2026-01-07 00:10:14.826424 | 
2026-01-07 00:10:14.826563 | TASK [Set selinux package (Fedora)]
2026-01-07 00:10:14.880353 | controller | ok
2026-01-07 00:10:14.890818 | 
2026-01-07 00:10:14.890951 | TASK [Install selinux into virtualenv]
2026-01-07 00:10:28.434832 | controller | Collecting selinux-please-lie-to-me
2026-01-07 00:10:40.696550 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-07 00:10:41.009357 | controller | Collecting setuptools<50.0.0
2026-01-07 00:10:41.014994 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-07 00:10:41.053285 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 23.0 MB/s eta 0:00:00
2026-01-07 00:10:41.133939 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-07 00:10:41.134058 | controller |   Attempting uninstall: setuptools
2026-01-07 00:10:41.136461 | controller |     Found existing installation: setuptools 62.6.0
2026-01-07 00:10:41.195577 | controller |     Uninstalling setuptools-62.6.0:
2026-01-07 00:10:41.203314 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-07 00:10:41.704933 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-07 00:10:53.066412 | controller |
2026-01-07 00:10:53.147122 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-07 00:10:53.147164 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-07 00:10:53.457493 | controller | ok: Runtime: 0:00:38.026564
2026-01-07 00:10:53.463597 | 
2026-01-07 00:10:53.463664 | TASK [Install pytest-forked into virtualenv]
2026-01-07 00:11:05.320472 | controller | Collecting pytest-forked
2026-01-07 00:11:15.510585 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-07 00:11:15.559549 | controller | Collecting py
2026-01-07 00:11:15.564106 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-07 00:11:15.586730 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00
2026-01-07 00:11:15.700216 | controller | Collecting pytest>=3.10
2026-01-07 00:11:15.705912 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-07 00:11:15.719924 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 33.0 MB/s eta 0:00:00
2026-01-07 00:11:15.762609 | controller | Collecting iniconfig>=1.0.1
2026-01-07 00:11:15.766564 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-07 00:11:15.814682 | controller | Collecting packaging>=22
2026-01-07 00:11:15.817684 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-07 00:11:15.825806 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.6 MB/s eta 0:00:00
2026-01-07 00:11:15.860960 | controller | Collecting pluggy<2,>=1.5
2026-01-07 00:11:15.864061 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-07 00:11:15.913929 | controller | Collecting pygments>=2.7.2
2026-01-07 00:11:15.918212 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-07 00:11:15.942735 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 56.1 MB/s eta 0:00:00
2026-01-07 00:11:16.010526 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-07 00:11:17.064923 | 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-07 00:11:17.073498 | controller |
2026-01-07 00:11:17.142862 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-07 00:11:17.142902 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-07 00:11:17.505302 | controller | ok: Runtime: 0:00:23.465658
2026-01-07 00:11:17.511713 | 
2026-01-07 00:11:17.511784 | TASK [Update pip]
2026-01-07 00:11:18.020945 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-07 00:11:27.912987 | controller | Collecting pip
2026-01-07 00:11:40.089468 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-07 00:11:40.154612 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 31.4 MB/s eta 0:00:00
2026-01-07 00:11:40.217474 | controller | Installing collected packages: pip
2026-01-07 00:11:40.217648 | controller |   Attempting uninstall: pip
2026-01-07 00:11:40.219859 | controller |     Found existing installation: pip 22.2.2
2026-01-07 00:11:40.358789 | controller |     Uninstalling pip-22.2.2:
2026-01-07 00:11:40.373663 | controller |       Successfully uninstalled pip-22.2.2
2026-01-07 00:11:41.194668 | controller | Successfully installed pip-25.3
2026-01-07 00:11:41.556940 | controller | ok: Runtime: 0:00:23.544380
2026-01-07 00:11:41.563626 | 
2026-01-07 00:11:41.563716 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-07 00:11:41.801961 | controller | changed
2026-01-07 00:11:41.842739 | 
2026-01-07 00:11:41.842874 | TASK [Install ansible into virtualenv]
2026-01-07 00:11:42.321780 | controller | Processing ./src/github.com/ansible/ansible
2026-01-07 00:11:42.325045 | controller |   Installing build dependencies: started
2026-01-07 00:12:05.048136 | controller |   Installing build dependencies: finished with status 'done'
2026-01-07 00:12:05.048751 | controller |   Getting requirements to build wheel: started
2026-01-07 00:12:05.774488 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-07 00:12:05.775662 | controller |   Preparing metadata (pyproject.toml): started
2026-01-07 00:12:06.235274 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-07 00:12:06.241303 | 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-07 00:12:06.247185 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-07 00:12:06.383495 | controller | ERROR
2026-01-07 00:12:06.383614 | controller | {
2026-01-07 00:12:06.383642 | controller |   "delta": "0:00:24.297554",
2026-01-07 00:12:06.383661 | controller |   "end": "2026-01-07 00:12:06.340719",
2026-01-07 00:12:06.383678 | controller |   "msg": "non-zero return code",
2026-01-07 00:12:06.383702 | controller |   "rc": 1,
2026-01-07 00:12:06.383719 | controller |   "start": "2026-01-07 00:11:42.043165"
2026-01-07 00:12:06.383735 | controller | }
failure
2026-01-07 00:12:06.385147 | 
2026-01-07 00:12:06.385196 | PLAY RECAP
2026-01-07 00:12:06.385240 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-07 00:12:06.385265 | 
2026-01-07 00:12:06.488707 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-07 00:12:06.489685 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-07 00:12:07.108884 | 
2026-01-07 00:12:07.109034 | PLAY [all]
2026-01-07 00:12:07.137541 | 
2026-01-07 00:12:07.137672 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-07 00:12:07.410533 | controller | changed: non-zero return code
2026-01-07 00:12:07.422968 | 
2026-01-07 00:12:07.423181 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-07 00:12:07.448431 | controller | skipping: Conditional result was False
2026-01-07 00:12:07.454554 | 
2026-01-07 00:12:07.454628 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-07 00:12:07.484707 | 
2026-01-07 00:12:07.484859 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-07 00:12:07.514471 | 
2026-01-07 00:12:07.514728 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-07 00:12:07.538342 | controller | skipping: Conditional result was False
2026-01-07 00:12:07.555304 | 
2026-01-07 00:12:07.555635 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-07 00:12:07.586906 | 
2026-01-07 00:12:07.587260 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-07 00:12:07.612705 | controller | skipping: Conditional result was False
2026-01-07 00:12:07.622239 | 
2026-01-07 00:12:07.622358 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-07 00:12:07.646893 | controller | skipping: Conditional result was False
2026-01-07 00:12:07.655342 | 
2026-01-07 00:12:07.655445 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-07 00:12:07.679937 | controller | skipping: Conditional result was False
2026-01-07 00:12:07.717637 | 
2026-01-07 00:12:07.717741 | PLAY RECAP
2026-01-07 00:12:07.717794 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-07 00:12:07.717822 | 
2026-01-07 00:12:07.858244 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-07 00:12:07.859233 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-07 00:12:08.471268 | 
2026-01-07 00:12:08.471381 | PLAY [all:!appliance*]
2026-01-07 00:12:08.493693 | 
2026-01-07 00:12:08.493795 | TASK [unregister the node]
2026-01-07 00:12:09.025003 | controller | skipping: Conditional result was False
2026-01-07 00:12:09.038593 | 
2026-01-07 00:12:09.038816 | TASK [include_role : fetch-output]
2026-01-07 00:12:09.088396 | controller | ok
2026-01-07 00:12:09.121622 | 
2026-01-07 00:12:09.121783 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-07 00:12:09.178606 | controller | skipping: Conditional result was False
2026-01-07 00:12:09.189654 | 
2026-01-07 00:12:09.189799 | TASK [fetch-output : Set log path for single node]
2026-01-07 00:12:09.231126 | controller | ok
2026-01-07 00:12:09.236707 | 
2026-01-07 00:12:09.236784 | LOOP [fetch-output : Ensure local output dirs]
2026-01-07 00:12:09.638724 | controller -> localhost | ok: "/var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/logs"
2026-01-07 00:12:09.887247 | controller -> localhost | changed: "/var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/artifacts"
2026-01-07 00:12:10.123430 | controller -> localhost | changed: "/var/lib/zuul/builds/662e025151ea4b8cbc84dd2c3b7a8978/work/docs"
2026-01-07 00:12:10.142871 | 
2026-01-07 00:12:10.143010 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-07 00:12:10.849353 | controller | changed:
2026-01-07 00:12:10.849593 | controller | .d..t...... ./
2026-01-07 00:12:10.849640 | controller | cd+++++++++ controller/
2026-01-07 00:12:10.849690 | controller | changed: All items complete
2026-01-07 00:12:10.849724 | 
2026-01-07 00:12:11.339552 | controller | changed: .d..t...... ./
2026-01-07 00:12:11.852203 | controller | changed: .d..t...... ./
2026-01-07 00:12:11.872613 | 
2026-01-07 00:12:11.872728 | TASK [include_role : fetch-output-openshift]
2026-01-07 00:12:11.886876 | controller | skipping: Conditional result was False
2026-01-07 00:12:11.894528 | 
2026-01-07 00:12:11.894610 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-07 00:12:11.940064 | controller | skipping: Conditional result was False
2026-01-07 00:12:11.954568 | controller | skipping: Conditional result was False
2026-01-07 00:12:11.990102 | 
2026-01-07 00:12:11.990211 | PLAY [localhost]
2026-01-07 00:12:12.004216 | 
2026-01-07 00:12:12.004332 | TASK [Run Zuul manifest role]
2026-01-07 00:12:12.025577 | localhost | ok
2026-01-07 00:12:12.044815 | 
2026-01-07 00:12:12.044937 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-07 00:12:12.421277 | localhost | changed
2026-01-07 00:12:12.425983 | 
2026-01-07 00:12:12.426068 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-07 00:12:12.454165 | localhost | ok
2026-01-07 00:12:12.462490 | 
2026-01-07 00:12:12.462583 | TASK [Set zuul-log-path fact]
2026-01-07 00:12:12.481635 | localhost | ok
2026-01-07 00:12:12.495080 | 
2026-01-07 00:12:12.495174 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-07 00:12:12.524978 | localhost | ok
2026-01-07 00:12:12.533756 | 
2026-01-07 00:12:12.533857 | LOOP [Run upload-logs-swift role]
2026-01-07 00:12:12.571346 | localhost | Output suppressed because no_log was given
2026-01-07 00:12:12.598403 | 
2026-01-07 00:12:12.598513 | TASK [Set zuul-log-path fact]
2026-01-07 00:12:12.622456 | localhost | skipping: Conditional result was False
2026-01-07 00:12:12.627398 | 
2026-01-07 00:12:12.627466 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-07 00:12:13.049923 | localhost -> localhost | ok: Runtime: 0:00:00.008644
2026-01-07 00:12:13.057157 | 
2026-01-07 00:12:13.057267 | TASK [upload-logs-swift : Upload logs to swift]