2026-01-04 00:07:12.241507 | Job console starting...
2026-01-04 00:07:12.259018 | Updating repositories
2026-01-04 00:07:12.407153 | Preparing job workspace
2026-01-04 00:07:16.370054 | Running Ansible setup...
2026-01-04 00:07:21.304158 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-04 00:07:21.886547 | 
2026-01-04 00:07:21.886660 | PLAY [localhost]
2026-01-04 00:07:21.894795 | 
2026-01-04 00:07:21.894863 | TASK [Gathering Facts]
2026-01-04 00:07:22.825365 | localhost | ok
2026-01-04 00:07:22.839388 | 
2026-01-04 00:07:22.839503 | TASK [Setup log path fact]
2026-01-04 00:07:22.857850 | localhost | ok
2026-01-04 00:07:22.873091 | 
2026-01-04 00:07:22.873195 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-04 00:07:22.901036 | localhost | ok
2026-01-04 00:07:22.909804 | 
2026-01-04 00:07:22.909893 | TASK [emit-job-header : Print job information]
2026-01-04 00:07:22.938288 | # Job Information
2026-01-04 00:07:22.938490 | Ansible Version: 2.15.12
2026-01-04 00:07:22.938525 | Job: ansible-test-sanity-docker-devel
2026-01-04 00:07:22.938548 | Pipeline: periodic
2026-01-04 00:07:22.938567 | Executor: ze02.softwarefactory-project.io
2026-01-04 00:07:22.938587 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-04 00:07:22.938610 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/25f/ansible/25f559d1b232413eba3ff1e7857aa718/
2026-01-04 00:07:22.938630 | Event ID: 4040b8efc4c7403f988e7928565c0397
2026-01-04 00:07:22.942494 | 
2026-01-04 00:07:22.942564 | LOOP [emit-job-header : Print node information]
2026-01-04 00:07:23.037848 | localhost | ok:
2026-01-04 00:07:23.038038 | localhost | # Node Information
2026-01-04 00:07:23.038066 | localhost | Inventory Hostname: controller
2026-01-04 00:07:23.038086 | localhost | Hostname: np0005573910
2026-01-04 00:07:23.038105 | localhost | Username: zuul
2026-01-04 00:07:23.038129 | localhost | Distro: Fedora 37
2026-01-04 00:07:23.038148 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-04 00:07:23.038166 | localhost | Region: ca-ymq-1
2026-01-04 00:07:23.038183 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-04 00:07:23.038201 | localhost | Product Name: OpenStack Nova
2026-01-04 00:07:23.038218 | localhost | Interface IP: 162.253.55.70
2026-01-04 00:07:23.050584 | 
2026-01-04 00:07:23.050705 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-04 00:07:23.513344 | localhost -> localhost | changed
2026-01-04 00:07:23.518839 | 
2026-01-04 00:07:23.518920 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-04 00:07:24.369796 | localhost -> localhost | changed
2026-01-04 00:07:24.390482 | 
2026-01-04 00:07:24.390552 | PLAY [all:!appliance*]
2026-01-04 00:07:24.424183 | 
2026-01-04 00:07:24.424316 | TASK [include_role : start-zuul-console]
2026-01-04 00:07:24.443481 | controller | ok
2026-01-04 00:07:24.458407 | 
2026-01-04 00:07:24.458476 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-04 00:07:24.822574 | controller | ok
2026-01-04 00:07:24.843984 | 
2026-01-04 00:07:24.844097 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-04 00:07:25.579027 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-04 00:07:25.585362 | 
2026-01-04 00:07:25.585461 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-04 00:07:26.119108 | controller | skipping: Conditional result was False
2026-01-04 00:07:26.125619 | 
2026-01-04 00:07:26.125744 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-04 00:07:26.183171 | controller | skipping: Conditional result was False
2026-01-04 00:07:26.189302 | 
2026-01-04 00:07:26.189426 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-04 00:07:26.213297 | controller | skipping: Conditional result was False
2026-01-04 00:07:26.219350 | 
2026-01-04 00:07:26.219442 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-04 00:07:26.233233 | controller | skipping: Conditional result was False
2026-01-04 00:07:26.240060 | 
2026-01-04 00:07:26.240175 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-04 00:07:26.256992 | controller | skipping: Conditional result was False
2026-01-04 00:07:26.263786 | 
2026-01-04 00:07:26.263889 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-04 00:07:26.280498 | controller | skipping: Conditional result was False
2026-01-04 00:07:26.293445 | 
2026-01-04 00:07:26.293543 | TASK [Disable Fedora Modular]
2026-01-04 00:07:26.547645 | controller | changed
2026-01-04 00:07:26.553791 | 
2026-01-04 00:07:26.553860 | TASK [Enable EPEL]
2026-01-04 00:07:26.577961 | controller | skipping: Conditional result was False
2026-01-04 00:07:26.585359 | 
2026-01-04 00:07:26.585440 | TASK [Register the RHEL node]
2026-01-04 00:07:27.126501 | 
2026-01-04 00:07:27.126721 | TASK [Show the subscription-manager status]
2026-01-04 00:07:27.698857 | controller | skipping: Conditional result was False
2026-01-04 00:07:27.714825 | 
2026-01-04 00:07:27.714958 | TASK [Enable EPEL on RHEL]
2026-01-04 00:07:28.300769 | controller | skipping: Conditional result was False
2026-01-04 00:07:28.322883 | 
2026-01-04 00:07:28.323113 | TASK [Install git and tox]
2026-01-04 00:09:24.567253 | controller | changed
2026-01-04 00:09:24.583502 | 
2026-01-04 00:09:24.583737 | TASK [include_role : prepare-workspace]
2026-01-04 00:09:24.614910 | controller | ok
2026-01-04 00:09:24.649965 | 
2026-01-04 00:09:24.650100 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-04 00:09:24.885362 | controller | ok
2026-01-04 00:09:24.892435 | 
2026-01-04 00:09:24.892507 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-04 00:09:37.072303 | controller | Output suppressed because no_log was given
2026-01-04 00:09:37.087027 | 
2026-01-04 00:09:37.087118 | TASK [include_role : prepare-workspace-openshift]
2026-01-04 00:09:37.104130 | controller | skipping: Conditional result was False
2026-01-04 00:09:37.165228 | 
2026-01-04 00:09:37.165314 | PLAY [all:!appliance]
2026-01-04 00:09:37.183888 | 
2026-01-04 00:09:37.183970 | TASK [Run add-build-sshkey role (RSA)]
2026-01-04 00:09:37.216832 | controller | ok
2026-01-04 00:09:37.235803 | 
2026-01-04 00:09:37.235884 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-04 00:09:37.528896 | controller -> localhost | ok
2026-01-04 00:09:37.538566 | 
2026-01-04 00:09:37.538648 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-04 00:09:37.566262 | controller | ok
2026-01-04 00:09:37.585779 | controller | included: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-04 00:09:37.592717 | 
2026-01-04 00:09:37.592804 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-04 00:09:38.221349 | controller -> localhost | Generating public/private rsa key pair.
2026-01-04 00:09:38.221794 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/25f559d1b232413eba3ff1e7857aa718_id_rsa.
2026-01-04 00:09:38.221893 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/25f559d1b232413eba3ff1e7857aa718_id_rsa.pub.
2026-01-04 00:09:38.221942 | controller -> localhost | The key fingerprint is:
2026-01-04 00:09:38.221987 | controller -> localhost | SHA256:RLffUZTgDIaSYw/TEP6t+JCkK40Fy0Kyx8yPFhpl01g zuul-build-sshkey
2026-01-04 00:09:38.222029 | controller -> localhost | The key's randomart image is:
2026-01-04 00:09:38.222070 | controller -> localhost | +---[RSA 2048]----+
2026-01-04 00:09:38.222110 | controller -> localhost | |       o* oo ...+|
2026-01-04 00:09:38.222151 | controller -> localhost | |    E .O +..+  o |
2026-01-04 00:09:38.222191 | controller -> localhost | |   +  ..B .  o.  |
2026-01-04 00:09:38.222230 | controller -> localhost | |..=..  ..... . . |
2026-01-04 00:09:38.222268 | controller -> localhost | |oB..o  .S. .. .  |
2026-01-04 00:09:38.222323 | controller -> localhost | |o.*o .o o .      |
2026-01-04 00:09:38.222379 | controller -> localhost | | +.++. + .       |
2026-01-04 00:09:38.222422 | controller -> localhost | |. oo... o        |
2026-01-04 00:09:38.222463 | controller -> localhost | | .  ..   .       |
2026-01-04 00:09:38.222508 | controller -> localhost | +----[SHA256]-----+
2026-01-04 00:09:38.222629 | controller -> localhost | ok: Runtime: 0:00:00.160492
2026-01-04 00:09:38.236453 | 
2026-01-04 00:09:38.236593 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-04 00:09:38.275413 | controller | ok
2026-01-04 00:09:38.291300 | controller | included: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-04 00:09:38.304087 | 
2026-01-04 00:09:38.304217 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-04 00:09:38.331224 | controller | skipping: Conditional result was False
2026-01-04 00:09:38.342345 | 
2026-01-04 00:09:38.342466 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-04 00:09:38.763171 | controller | changed
2026-01-04 00:09:38.776959 | 
2026-01-04 00:09:38.777153 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-04 00:09:39.016819 | controller | ok
2026-01-04 00:09:39.031897 | 
2026-01-04 00:09:39.032099 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-04 00:09:39.651984 | controller | changed
2026-01-04 00:09:39.665616 | 
2026-01-04 00:09:39.665826 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-04 00:09:40.292889 | controller | changed
2026-01-04 00:09:40.307045 | 
2026-01-04 00:09:40.307370 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-04 00:09:40.346560 | controller | skipping: Conditional result was False
2026-01-04 00:09:40.358536 | 
2026-01-04 00:09:40.358650 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-04 00:09:40.795404 | controller -> localhost | changed
2026-01-04 00:09:40.822302 | 
2026-01-04 00:09:40.822517 | TASK [add-build-sshkey : Add back temp key]
2026-01-04 00:09:41.211357 | controller -> localhost | Identity added: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/25f559d1b232413eba3ff1e7857aa718_id_rsa (zuul-build-sshkey)
2026-01-04 00:09:41.211873 | controller -> localhost | ok: Runtime: 0:00:00.014058
2026-01-04 00:09:41.226556 | 
2026-01-04 00:09:41.226730 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-04 00:09:41.572856 | controller | ok
2026-01-04 00:09:41.585326 | 
2026-01-04 00:09:41.585472 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-04 00:09:41.635175 | controller | skipping: Conditional result was False
2026-01-04 00:09:41.661950 | 
2026-01-04 00:09:41.662184 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-04 00:09:41.714208 | controller | ok
2026-01-04 00:09:41.746309 | 
2026-01-04 00:09:41.746512 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-04 00:09:42.063404 | controller -> localhost | ok
2026-01-04 00:09:42.078960 | 
2026-01-04 00:09:42.079267 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-04 00:09:42.126202 | controller | ok
2026-01-04 00:09:42.139105 | controller | included: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-04 00:09:42.146099 | 
2026-01-04 00:09:42.146187 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-04 00:09:42.522056 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-04 00:09:42.522527 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/25f559d1b232413eba3ff1e7857aa718_id_ecdsa.
2026-01-04 00:09:42.522613 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/25f559d1b232413eba3ff1e7857aa718_id_ecdsa.pub.
2026-01-04 00:09:42.522774 | controller -> localhost | The key fingerprint is:
2026-01-04 00:09:42.522827 | controller -> localhost | SHA256:kyWZYhNSOuIAUJnchZHmqsQ5ncnYdVxZ7q5U/5ny0fA zuul-build-sshkey
2026-01-04 00:09:42.522871 | controller -> localhost | The key's randomart image is:
2026-01-04 00:09:42.522912 | controller -> localhost | +---[ECDSA 521]---+
2026-01-04 00:09:42.522952 | controller -> localhost | |+o.+o*+   o.     |
2026-01-04 00:09:42.522992 | controller -> localhost | |. + =o . =.      |
2026-01-04 00:09:42.523030 | controller -> localhost | |. .oo = = ..     |
2026-01-04 00:09:42.523070 | controller -> localhost | | o ..+ = +.      |
2026-01-04 00:09:42.523107 | controller -> localhost | |. B.+ . S  o  .  |
2026-01-04 00:09:42.523144 | controller -> localhost | | *.*     .o .  o.|
2026-01-04 00:09:42.523182 | controller -> localhost | |...      . . . .E|
2026-01-04 00:09:42.523218 | controller -> localhost | |.       . .  .. +|
2026-01-04 00:09:42.523256 | controller -> localhost | |         .    o= |
2026-01-04 00:09:42.523294 | controller -> localhost | +----[SHA256]-----+
2026-01-04 00:09:42.523409 | controller -> localhost | ok: Runtime: 0:00:00.015585
2026-01-04 00:09:42.541392 | 
2026-01-04 00:09:42.541628 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-04 00:09:42.585211 | controller | ok
2026-01-04 00:09:42.601623 | controller | included: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-04 00:09:42.614598 | 
2026-01-04 00:09:42.614740 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-04 00:09:42.652554 | controller | skipping: Conditional result was False
2026-01-04 00:09:42.661644 | 
2026-01-04 00:09:42.661764 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-04 00:09:42.934486 | controller | changed
2026-01-04 00:09:42.948708 | 
2026-01-04 00:09:42.948875 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-04 00:09:43.178765 | controller | ok
2026-01-04 00:09:43.194658 | 
2026-01-04 00:09:43.194878 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-04 00:09:43.836436 | controller | changed
2026-01-04 00:09:43.851017 | 
2026-01-04 00:09:43.851187 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-04 00:09:44.550646 | controller | changed
2026-01-04 00:09:44.560359 | 
2026-01-04 00:09:44.560504 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-04 00:09:44.597988 | controller | skipping: Conditional result was False
2026-01-04 00:09:44.606786 | 
2026-01-04 00:09:44.606878 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-04 00:09:44.903299 | controller -> localhost | changed
2026-01-04 00:09:44.934654 | 
2026-01-04 00:09:44.934892 | TASK [add-build-sshkey : Add back temp key]
2026-01-04 00:09:45.325870 | controller -> localhost | Identity added: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/25f559d1b232413eba3ff1e7857aa718_id_ecdsa (zuul-build-sshkey)
2026-01-04 00:09:45.326212 | controller -> localhost | ok: Runtime: 0:00:00.009227
2026-01-04 00:09:45.336575 | 
2026-01-04 00:09:45.336793 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-04 00:09:45.571061 | controller | ok
2026-01-04 00:09:45.580999 | 
2026-01-04 00:09:45.581139 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-04 00:09:45.630518 | controller | skipping: Conditional result was False
2026-01-04 00:09:45.650493 | 
2026-01-04 00:09:45.651324 | TASK [include_role : remove-zuul-sshkey]
2026-01-04 00:09:45.679611 | controller | skipping: Conditional result was False
2026-01-04 00:09:45.691568 | 
2026-01-04 00:09:45.691794 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-04 00:09:45.939514 | controller | ok: "logs"
2026-01-04 00:09:45.940137 | controller | ok: All items complete
2026-01-04 00:09:45.940196 | 
2026-01-04 00:09:46.141800 | controller | ok: "artifacts"
2026-01-04 00:09:46.343729 | controller | ok: "docs"
2026-01-04 00:09:46.358444 | 
2026-01-04 00:09:46.358784 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-04 00:09:46.599340 | controller | changed: "logs"
2026-01-04 00:09:46.786991 | controller | changed: "artifacts"
2026-01-04 00:09:46.974959 | controller | changed: "docs"
2026-01-04 00:09:47.028852 | 
2026-01-04 00:09:47.029025 | PLAY RECAP
2026-01-04 00:09:47.029080 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-04 00:09:47.029106 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-04 00:09:47.029124 | 
2026-01-04 00:09:47.218261 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-04 00:09:47.219618 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-04 00:09:47.801369 | 
2026-01-04 00:09:47.801485 | PLAY [all]
2026-01-04 00:09:47.823495 | 
2026-01-04 00:09:47.823593 | TASK [Install binary dependencies]
2026-01-04 00:09:47.921028 | controller | ok
2026-01-04 00:09:47.958449 | 
2026-01-04 00:09:47.958578 | TASK [bindep : Include find tasks]
2026-01-04 00:09:48.007204 | controller | ok
2026-01-04 00:09:48.025926 | controller | included: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-04 00:09:48.035722 | 
2026-01-04 00:09:48.035808 | TASK [bindep : Look for bindep.txt]
2026-01-04 00:09:48.404552 | controller | ok
2026-01-04 00:09:48.419074 | 
2026-01-04 00:09:48.419274 | TASK [bindep : Define bindep_file fact]
2026-01-04 00:09:48.448559 | controller | skipping: Conditional result was False
2026-01-04 00:09:48.464789 | 
2026-01-04 00:09:48.464992 | TASK [bindep : Look for other-requirements.txt]
2026-01-04 00:09:48.700554 | controller | ok
2026-01-04 00:09:48.717029 | 
2026-01-04 00:09:48.717243 | TASK [bindep : Define bindep_file fact]
2026-01-04 00:09:48.758827 | controller | skipping: Conditional result was False
2026-01-04 00:09:48.773610 | 
2026-01-04 00:09:48.773848 | TASK [bindep : Look for bindep fallback file]
2026-01-04 00:09:48.804046 | controller | skipping: Conditional result was False
2026-01-04 00:09:48.819809 | 
2026-01-04 00:09:48.819985 | TASK [bindep : Define bindep_file fact]
2026-01-04 00:09:48.847604 | controller | skipping: Conditional result was False
2026-01-04 00:09:48.857454 | 
2026-01-04 00:09:48.857552 | TASK [bindep : Include bindep tasks]
2026-01-04 00:09:48.883486 | controller | skipping: Conditional result was False
2026-01-04 00:09:48.892424 | 
2026-01-04 00:09:48.892518 | TASK [bindep : Include install tasks]
2026-01-04 00:09:48.918087 | controller | skipping: Conditional result was False
2026-01-04 00:09:48.928914 | 
2026-01-04 00:09:48.929047 | LOOP [bindep : Include package tasks]
2026-01-04 00:09:49.002592 | 
2026-01-04 00:09:49.002934 | TASK [Run test-setup role]
2026-01-04 00:09:49.029863 | controller | ok
2026-01-04 00:09:49.054232 | 
2026-01-04 00:09:49.054337 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-04 00:09:49.263813 | controller | ok
2026-01-04 00:09:49.273291 | 
2026-01-04 00:09:49.273389 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-04 00:09:49.817957 | controller | skipping: Conditional result was False
2026-01-04 00:09:49.845409 | 
2026-01-04 00:09:49.845508 | PLAY RECAP
2026-01-04 00:09:49.845559 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-04 00:09:49.845581 | 
2026-01-04 00:09:50.014205 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-04 00:09:50.016719 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-04 00:09:50.628230 | 
2026-01-04 00:09:50.628382 | PLAY [controller]
2026-01-04 00:09:50.648653 | 
2026-01-04 00:09:50.648745 | TASK [Create the /root directory]
2026-01-04 00:09:51.038989 | controller | ok
2026-01-04 00:09:51.054507 | 
2026-01-04 00:09:51.054979 | TASK [Install glibc-langpack-en]
2026-01-04 00:09:54.976212 | controller | ok: Nothing to do
2026-01-04 00:09:54.990260 | 
2026-01-04 00:09:54.990401 | TASK [Ensure controller directory exists]
2026-01-04 00:09:55.224231 | controller | changed
2026-01-04 00:09:55.232915 | 
2026-01-04 00:09:55.233007 | TASK [Install container runtime]
2026-01-04 00:09:55.301863 | controller | ok
2026-01-04 00:09:55.367397 | 
2026-01-04 00:09:55.367537 | LOOP [ensure-podman : Find distribution installation]
2026-01-04 00:09:55.401911 | controller | ok: "/var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-04 00:09:55.413411 | controller | included: /var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-04 00:09:55.420023 | 
2026-01-04 00:09:55.420090 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-04 00:11:01.075606 | controller | changed
2026-01-04 00:11:01.082731 | 
2026-01-04 00:11:01.082798 | TASK [ensure-podman : Fetch podman version]
2026-01-04 00:11:01.687615 | controller | Client:       Podman Engine
2026-01-04 00:11:01.687724 | controller | Version:      4.6.2
2026-01-04 00:11:01.687769 | controller | API Version:  4.6.2
2026-01-04 00:11:01.687811 | controller | Go Version:   go1.19.12
2026-01-04 00:11:01.687862 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-04 00:11:01.687905 | controller | OS/Arch:      linux/amd64
2026-01-04 00:11:02.132731 | controller | ok: Runtime: 0:00:00.215690
2026-01-04 00:11:02.146818 | 
2026-01-04 00:11:02.147002 | TASK [ensure-podman : Print podman version installed]
2026-01-04 00:11:02.188183 | Podman version: Client:       Podman Engine
2026-01-04 00:11:02.188441 | Version:      4.6.2
2026-01-04 00:11:02.188506 | API Version:  4.6.2
2026-01-04 00:11:02.188554 | Go Version:   go1.19.12
2026-01-04 00:11:02.188597 | Built:        Mon Aug 28 19:38:31 2023
2026-01-04 00:11:02.188645 | OS/Arch:      linux/amd64
2026-01-04 00:11:02.202251 | 
2026-01-04 00:11:02.202393 | TASK [ensure-podman : Validate podman engine]
2026-01-04 00:11:02.746143 | controller | skipping: Conditional result was False
2026-01-04 00:11:02.759546 | 
2026-01-04 00:11:02.759750 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-04 00:11:02.786921 | controller | skipping: Conditional result was False
2026-01-04 00:11:02.810449 | 
2026-01-04 00:11:02.810586 | TASK [Ensure python3.8 is present]
2026-01-04 00:11:02.837787 | controller | skipping: Conditional result was False
2026-01-04 00:11:02.850376 | 
2026-01-04 00:11:02.850507 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-04 00:11:02.882515 | controller | ok
2026-01-04 00:11:02.912785 | 
2026-01-04 00:11:02.912887 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-04 00:11:04.298343 | controller | ok: Nothing to do
2026-01-04 00:11:04.315086 | 
2026-01-04 00:11:04.315368 | TASK [our-ensure-python : Also install python3-devel]
2026-01-04 00:11:13.625341 | controller | changed
2026-01-04 00:11:13.636258 | 
2026-01-04 00:11:13.636321 | TASK [Run ensure-virtualenv role]
2026-01-04 00:11:13.663476 | controller | ok
2026-01-04 00:11:13.695063 | 
2026-01-04 00:11:13.695167 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-04 00:11:13.943617 | controller | /usr/bin/virtualenv
2026-01-04 00:11:14.256965 | controller | ok: Runtime: 0:00:00.004808
2026-01-04 00:11:14.263470 | 
2026-01-04 00:11:14.263546 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-04 00:11:14.304915 | controller | skipping: Conditional result was False
2026-01-04 00:11:14.305384 | controller | ok: All items complete
2026-01-04 00:11:14.305439 | 
2026-01-04 00:11:14.319290 | 
2026-01-04 00:11:14.319375 | TASK [Find the full path of the Python interpreter]
2026-01-04 00:11:14.541212 | controller | /usr/bin/python3
2026-01-04 00:11:14.851506 | controller | ok
2026-01-04 00:11:14.864265 | 
2026-01-04 00:11:14.864401 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-04 00:11:15.714122 | controller | created virtual environment CPython3.11.0.final.0-64 in 473ms
2026-01-04 00:11:15.737659 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-04 00:11:15.737925 | 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-04 00:11:15.738054 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-04 00:11:15.738237 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-04 00:11:15.918875 | controller | changed
2026-01-04 00:11:15.927263 | 
2026-01-04 00:11:15.927350 | TASK [Set selinux package]
2026-01-04 00:11:15.964632 | controller | ok
2026-01-04 00:11:15.976326 | 
2026-01-04 00:11:15.976455 | TASK [Set selinux package (Fedora)]
2026-01-04 00:11:16.035457 | controller | ok
2026-01-04 00:11:16.046661 | 
2026-01-04 00:11:16.047452 | TASK [Install selinux into virtualenv]
2026-01-04 00:11:41.599307 | controller | Collecting selinux-please-lie-to-me
2026-01-04 00:11:53.853047 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-04 00:11:54.166331 | controller | Collecting setuptools<50.0.0
2026-01-04 00:11:54.172538 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-04 00:11:54.233188 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 14.6 MB/s eta 0:00:00
2026-01-04 00:11:54.313723 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-04 00:11:54.313936 | controller |   Attempting uninstall: setuptools
2026-01-04 00:11:54.316349 | controller |     Found existing installation: setuptools 62.6.0
2026-01-04 00:11:54.375524 | controller |     Uninstalling setuptools-62.6.0:
2026-01-04 00:11:54.383444 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-04 00:11:54.742888 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-04 00:12:06.228566 | controller |
2026-01-04 00:12:06.306649 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-04 00:12:06.306698 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-04 00:12:06.635253 | controller | ok: Runtime: 0:00:49.972694
2026-01-04 00:12:06.649572 | 
2026-01-04 00:12:06.649778 | TASK [Install pytest-forked into virtualenv]
2026-01-04 00:12:18.484107 | controller | Collecting pytest-forked
2026-01-04 00:12:28.665676 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-04 00:12:28.713309 | controller | Collecting py
2026-01-04 00:12:28.718498 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-04 00:12:28.742773 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.3 MB/s eta 0:00:00
2026-01-04 00:12:28.844289 | controller | Collecting pytest>=3.10
2026-01-04 00:12:28.849219 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-04 00:12:28.863560 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 34.8 MB/s eta 0:00:00
2026-01-04 00:12:28.905960 | controller | Collecting iniconfig>=1.0.1
2026-01-04 00:12:28.909833 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-04 00:12:28.953301 | controller | Collecting packaging>=22
2026-01-04 00:12:28.956562 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-04 00:12:28.965002 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.9 MB/s eta 0:00:00
2026-01-04 00:12:29.001130 | controller | Collecting pluggy<2,>=1.5
2026-01-04 00:12:29.004628 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-04 00:12:29.057226 | controller | Collecting pygments>=2.7.2
2026-01-04 00:12:29.062489 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-04 00:12:29.083115 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 74.1 MB/s eta 0:00:00
2026-01-04 00:12:29.151406 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-04 00:12:30.241158 | 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-04 00:12:30.250253 | controller |
2026-01-04 00:12:30.339255 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-04 00:12:30.340037 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-04 00:12:30.712097 | controller | ok: Runtime: 0:00:23.460925
2026-01-04 00:12:30.718221 | 
2026-01-04 00:12:30.718281 | TASK [Update pip]
2026-01-04 00:12:31.209691 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-04 00:12:43.676759 | controller | Collecting pip
2026-01-04 00:13:19.873320 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-04 00:13:19.932901 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 32.8 MB/s eta 0:00:00
2026-01-04 00:13:20.005754 | controller | Installing collected packages: pip
2026-01-04 00:13:20.006037 | controller |   Attempting uninstall: pip
2026-01-04 00:13:20.008271 | controller |     Found existing installation: pip 22.2.2
2026-01-04 00:13:20.148355 | controller |     Uninstalling pip-22.2.2:
2026-01-04 00:13:20.164234 | controller |       Successfully uninstalled pip-22.2.2
2026-01-04 00:13:21.026682 | controller | Successfully installed pip-25.3
2026-01-04 00:13:21.279746 | controller | ok: Runtime: 0:00:50.216275
2026-01-04 00:13:21.292178 | 
2026-01-04 00:13:21.292319 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-04 00:13:21.533479 | controller | changed
2026-01-04 00:13:21.546262 | 
2026-01-04 00:13:21.546404 | TASK [Install ansible into virtualenv]
2026-01-04 00:13:22.069856 | controller | Processing ./src/github.com/ansible/ansible
2026-01-04 00:13:22.073297 | controller |   Installing build dependencies: started
2026-01-04 00:13:44.800203 | controller |   Installing build dependencies: finished with status 'done'
2026-01-04 00:13:44.802643 | controller |   Getting requirements to build wheel: started
2026-01-04 00:13:45.558861 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-04 00:13:45.561677 | controller |   Preparing metadata (pyproject.toml): started
2026-01-04 00:13:46.056970 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-04 00:13:46.061197 | 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-04 00:13:46.064664 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-04 00:13:46.620297 | controller | ERROR
2026-01-04 00:13:46.620652 | controller | {
2026-01-04 00:13:46.620789 | controller |   "delta": "0:00:24.384155",
2026-01-04 00:13:46.620853 | controller |   "end": "2026-01-04 00:13:46.169117",
2026-01-04 00:13:46.621097 | controller |   "msg": "non-zero return code",
2026-01-04 00:13:46.621209 | controller |   "rc": 1,
2026-01-04 00:13:46.621272 | controller |   "start": "2026-01-04 00:13:21.784962"
2026-01-04 00:13:46.621330 | controller | }
failure
2026-01-04 00:13:46.625398 | 
2026-01-04 00:13:46.625509 | PLAY RECAP
2026-01-04 00:13:46.625602 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-04 00:13:46.625650 | 
2026-01-04 00:13:46.770742 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-04 00:13:46.771922 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-04 00:13:47.385735 | 
2026-01-04 00:13:47.385875 | PLAY [all]
2026-01-04 00:13:47.407537 | 
2026-01-04 00:13:47.407657 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-04 00:13:47.697551 | controller | changed: non-zero return code
2026-01-04 00:13:47.706108 | 
2026-01-04 00:13:47.706210 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-04 00:13:47.733716 | controller | skipping: Conditional result was False
2026-01-04 00:13:47.749380 | 
2026-01-04 00:13:47.749535 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-04 00:13:47.789068 | 
2026-01-04 00:13:47.789307 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-04 00:13:47.825842 | 
2026-01-04 00:13:47.826027 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-04 00:13:47.852261 | controller | skipping: Conditional result was False
2026-01-04 00:13:47.863779 | 
2026-01-04 00:13:47.863924 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-04 00:13:47.900373 | 
2026-01-04 00:13:47.900600 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-04 00:13:47.926921 | controller | skipping: Conditional result was False
2026-01-04 00:13:47.935567 | 
2026-01-04 00:13:47.935687 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-04 00:13:47.962134 | controller | skipping: Conditional result was False
2026-01-04 00:13:47.971055 | 
2026-01-04 00:13:47.971177 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-04 00:13:47.997935 | controller | skipping: Conditional result was False
2026-01-04 00:13:48.034973 | 
2026-01-04 00:13:48.035055 | PLAY RECAP
2026-01-04 00:13:48.035099 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-04 00:13:48.035118 | 
2026-01-04 00:13:48.187687 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-04 00:13:48.188730 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-04 00:13:48.813931 | 
2026-01-04 00:13:48.814070 | PLAY [all:!appliance*]
2026-01-04 00:13:48.835799 | 
2026-01-04 00:13:48.835888 | TASK [unregister the node]
2026-01-04 00:13:49.370481 | controller | skipping: Conditional result was False
2026-01-04 00:13:49.383463 | 
2026-01-04 00:13:49.383632 | TASK [include_role : fetch-output]
2026-01-04 00:13:49.421378 | controller | ok
2026-01-04 00:13:49.463547 | 
2026-01-04 00:13:49.463724 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-04 00:13:49.540045 | controller | skipping: Conditional result was False
2026-01-04 00:13:49.552739 | 
2026-01-04 00:13:49.552884 | TASK [fetch-output : Set log path for single node]
2026-01-04 00:13:49.600792 | controller | ok
2026-01-04 00:13:49.612416 | 
2026-01-04 00:13:49.612552 | LOOP [fetch-output : Ensure local output dirs]
2026-01-04 00:13:50.079950 | controller -> localhost | ok: "/var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/logs"
2026-01-04 00:13:50.331547 | controller -> localhost | changed: "/var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/artifacts"
2026-01-04 00:13:50.576609 | controller -> localhost | changed: "/var/lib/zuul/builds/25f559d1b232413eba3ff1e7857aa718/work/docs"
2026-01-04 00:13:50.605514 | 
2026-01-04 00:13:50.605783 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-04 00:13:51.374471 | controller | changed:
2026-01-04 00:13:51.374752 | controller | .d..t...... ./
2026-01-04 00:13:51.374792 | controller | cd+++++++++ controller/
2026-01-04 00:13:51.374837 | controller | changed: All items complete
2026-01-04 00:13:51.374865 | 
2026-01-04 00:13:51.921491 | controller | changed: .d..t...... ./
2026-01-04 00:13:52.443158 | controller | changed: .d..t...... ./
2026-01-04 00:13:52.484016 | 
2026-01-04 00:13:52.484276 | TASK [include_role : fetch-output-openshift]
2026-01-04 00:13:52.514234 | controller | skipping: Conditional result was False
2026-01-04 00:13:52.529358 | 
2026-01-04 00:13:52.529511 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-04 00:13:52.581776 | controller | skipping: Conditional result was False
2026-01-04 00:13:52.594879 | controller | skipping: Conditional result was False
2026-01-04 00:13:52.652322 | 
2026-01-04 00:13:52.652523 | PLAY [localhost]
2026-01-04 00:13:52.670248 | 
2026-01-04 00:13:52.670339 | TASK [Run Zuul manifest role]
2026-01-04 00:13:52.702070 | localhost | ok
2026-01-04 00:13:52.723712 | 
2026-01-04 00:13:52.723897 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-04 00:13:53.239498 | localhost | changed
2026-01-04 00:13:53.260106 | 
2026-01-04 00:13:53.260263 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-04 00:13:53.298046 | localhost | ok
2026-01-04 00:13:53.316278 | 
2026-01-04 00:13:53.316370 | TASK [Set zuul-log-path fact]
2026-01-04 00:13:53.338630 | localhost | ok
2026-01-04 00:13:53.360149 | 
2026-01-04 00:13:53.360295 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-04 00:13:53.403259 | localhost | ok
2026-01-04 00:13:53.416039 | 
2026-01-04 00:13:53.416128 | LOOP [Run upload-logs-swift role]
2026-01-04 00:13:53.464599 | localhost | Output suppressed because no_log was given
2026-01-04 00:13:53.493765 | 
2026-01-04 00:13:53.493914 | TASK [Set zuul-log-path fact]
2026-01-04 00:13:53.530446 | localhost | skipping: Conditional result was False
2026-01-04 00:13:53.541306 | 
2026-01-04 00:13:53.541443 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-04 00:13:54.038760 | localhost -> localhost | ok: Runtime: 0:00:00.006052
2026-01-04 00:13:54.049789 | 
2026-01-04 00:13:54.049919 | TASK [upload-logs-swift : Upload logs to swift]