2026-01-05 00:21:24.054938 | Job console starting...
2026-01-05 00:21:24.065208 | Updating repositories
2026-01-05 00:21:24.174601 | Preparing job workspace
2026-01-05 00:21:27.852611 | Running Ansible setup...
2026-01-05 00:21:35.329103 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-05 00:21:35.965980 | 
2026-01-05 00:21:35.966113 | PLAY [localhost]
2026-01-05 00:21:35.974624 | 
2026-01-05 00:21:35.974694 | TASK [Gathering Facts]
2026-01-05 00:21:37.018319 | localhost | ok
2026-01-05 00:21:37.049048 | 
2026-01-05 00:21:37.049266 | TASK [Setup log path fact]
2026-01-05 00:21:37.072656 | localhost | ok
2026-01-05 00:21:37.093323 | 
2026-01-05 00:21:37.093471 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-05 00:21:37.125123 | localhost | ok
2026-01-05 00:21:37.137654 | 
2026-01-05 00:21:37.137840 | TASK [emit-job-header : Print job information]
2026-01-05 00:21:37.179795 | # Job Information
2026-01-05 00:21:37.180011 | Ansible Version: 2.15.12
2026-01-05 00:21:37.180063 | Job: ansible-test-sanity-docker-milestone
2026-01-05 00:21:37.180096 | Pipeline: periodic
2026-01-05 00:21:37.180125 | Executor: ze03.softwarefactory-project.io
2026-01-05 00:21:37.180153 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-05 00:21:37.180184 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/de7/ansible/de792228e0494e168236c54c5a91d076/
2026-01-05 00:21:37.180213 | Event ID: 19345726fd1140bdae6ad9d74d038fac
2026-01-05 00:21:37.186041 | 
2026-01-05 00:21:37.186136 | LOOP [emit-job-header : Print node information]
2026-01-05 00:21:37.298833 | localhost | ok:
2026-01-05 00:21:37.299069 | localhost | # Node Information
2026-01-05 00:21:37.299098 | localhost | Inventory Hostname: controller
2026-01-05 00:21:37.299119 | localhost | Hostname: np0005574140
2026-01-05 00:21:37.299137 | localhost | Username: zuul
2026-01-05 00:21:37.299162 | localhost | Distro: Fedora 37
2026-01-05 00:21:37.299181 | localhost | Provider: ansible-vexxhost-ams1
2026-01-05 00:21:37.299198 | localhost | Region: ams1
2026-01-05 00:21:37.299214 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-05 00:21:37.299230 | localhost | Product Name: OpenStack Nova
2026-01-05 00:21:37.299246 | localhost | Interface IP: 38.129.16.147
2026-01-05 00:21:37.322491 | 
2026-01-05 00:21:37.322718 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-05 00:21:37.749955 | localhost -> localhost | changed
2026-01-05 00:21:37.755974 | 
2026-01-05 00:21:37.756076 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-05 00:21:38.607149 | localhost -> localhost | changed
2026-01-05 00:21:38.627649 | 
2026-01-05 00:21:38.627733 | PLAY [all:!appliance*]
2026-01-05 00:21:38.644555 | 
2026-01-05 00:21:38.644672 | TASK [include_role : start-zuul-console]
2026-01-05 00:21:38.663975 | controller | ok
2026-01-05 00:21:38.677793 | 
2026-01-05 00:21:38.677893 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-05 00:21:39.724514 | controller | ok
2026-01-05 00:21:39.739504 | 
2026-01-05 00:21:39.739659 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-05 00:22:02.032790 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-05 00:22:02.044235 | 
2026-01-05 00:22:02.044381 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-05 00:22:02.409930 | controller | skipping: Conditional result was False
2026-01-05 00:22:02.419308 | 
2026-01-05 00:22:02.419427 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-05 00:22:02.446891 | controller | skipping: Conditional result was False
2026-01-05 00:22:02.454540 | 
2026-01-05 00:22:02.454643 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-05 00:22:02.479085 | controller | skipping: Conditional result was False
2026-01-05 00:22:02.488237 | 
2026-01-05 00:22:02.488356 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-05 00:22:02.503423 | controller | skipping: Conditional result was False
2026-01-05 00:22:02.511315 | 
2026-01-05 00:22:02.511427 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-05 00:22:02.526131 | controller | skipping: Conditional result was False
2026-01-05 00:22:02.533875 | 
2026-01-05 00:22:02.533994 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-05 00:22:02.548432 | controller | skipping: Conditional result was False
2026-01-05 00:22:02.560979 | 
2026-01-05 00:22:02.561171 | TASK [Disable Fedora Modular]
2026-01-05 00:22:03.630943 | controller | changed
2026-01-05 00:22:03.637976 | 
2026-01-05 00:22:03.638107 | TASK [Enable EPEL]
2026-01-05 00:22:03.664519 | controller | skipping: Conditional result was False
2026-01-05 00:22:03.673478 | 
2026-01-05 00:22:03.673635 | TASK [Register the RHEL node]
2026-01-05 00:22:04.069223 | 
2026-01-05 00:22:04.069422 | TASK [Show the subscription-manager status]
2026-01-05 00:22:04.446557 | controller | skipping: Conditional result was False
2026-01-05 00:22:04.453991 | 
2026-01-05 00:22:04.454105 | TASK [Enable EPEL on RHEL]
2026-01-05 00:22:04.825204 | controller | skipping: Conditional result was False
2026-01-05 00:22:04.831425 | 
2026-01-05 00:22:04.831497 | TASK [Install git and tox]
2026-01-05 00:23:54.949304 | controller | changed
2026-01-05 00:23:54.956844 | 
2026-01-05 00:23:54.957005 | TASK [include_role : prepare-workspace]
2026-01-05 00:23:54.987624 | controller | ok
2026-01-05 00:23:55.021111 | 
2026-01-05 00:23:55.021258 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-05 00:23:55.813528 | controller | ok
2026-01-05 00:23:55.820425 | 
2026-01-05 00:23:55.820505 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-05 00:24:11.658015 | controller | Output suppressed because no_log was given
2026-01-05 00:24:11.668739 | 
2026-01-05 00:24:11.668853 | TASK [include_role : prepare-workspace-openshift]
2026-01-05 00:24:11.684524 | controller | skipping: Conditional result was False
2026-01-05 00:24:11.708109 | 
2026-01-05 00:24:11.708209 | PLAY [all:!appliance]
2026-01-05 00:24:11.725987 | 
2026-01-05 00:24:11.726111 | TASK [Run add-build-sshkey role (RSA)]
2026-01-05 00:24:11.747160 | controller | ok
2026-01-05 00:24:11.765620 | 
2026-01-05 00:24:11.765779 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-05 00:24:12.004204 | controller -> localhost | ok
2026-01-05 00:24:12.013521 | 
2026-01-05 00:24:12.013645 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-05 00:24:12.044975 | controller | ok
2026-01-05 00:24:12.060162 | controller | included: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-05 00:24:12.066559 | 
2026-01-05 00:24:12.066639 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-05 00:24:12.540533 | controller -> localhost | Generating public/private rsa key pair.
2026-01-05 00:24:12.540768 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/de792228e0494e168236c54c5a91d076_id_rsa.
2026-01-05 00:24:12.540801 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/de792228e0494e168236c54c5a91d076_id_rsa.pub.
2026-01-05 00:24:12.540823 | controller -> localhost | The key fingerprint is:
2026-01-05 00:24:12.540843 | controller -> localhost | SHA256:lVvXnz0ejZBzqwcw+8Db3r6HhQ2g91YvnaPTIdLY1H0 zuul-build-sshkey
2026-01-05 00:24:12.540862 | controller -> localhost | The key's randomart image is:
2026-01-05 00:24:12.540880 | controller -> localhost | +---[RSA 2048]----+
2026-01-05 00:24:12.540898 | controller -> localhost | |                 |
2026-01-05 00:24:12.540917 | controller -> localhost | |           ... . |
2026-01-05 00:24:12.540934 | controller -> localhost | |          =.=.+ o|
2026-01-05 00:24:12.540951 | controller -> localhost | |         o.*.*.+E|
2026-01-05 00:24:12.540967 | controller -> localhost | |        S =.*.oXB|
2026-01-05 00:24:12.540999 | controller -> localhost | |           B **+B|
2026-01-05 00:24:12.541032 | controller -> localhost | |          . =.==o|
2026-01-05 00:24:12.541053 | controller -> localhost | |           . =...|
2026-01-05 00:24:12.541071 | controller -> localhost | |            ..=o |
2026-01-05 00:24:12.541092 | controller -> localhost | +----[SHA256]-----+
2026-01-05 00:24:12.541140 | controller -> localhost | ok: Runtime: 0:00:00.068781
2026-01-05 00:24:12.548605 | 
2026-01-05 00:24:12.548761 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-05 00:24:12.580411 | controller | ok
2026-01-05 00:24:12.592160 | controller | included: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-05 00:24:12.605609 | 
2026-01-05 00:24:12.605763 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-05 00:24:12.631149 | controller | skipping: Conditional result was False
2026-01-05 00:24:12.639990 | 
2026-01-05 00:24:12.640114 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-05 00:24:13.727978 | controller | changed
2026-01-05 00:24:13.762869 | 
2026-01-05 00:24:13.762994 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-05 00:24:14.414228 | controller | ok
2026-01-05 00:24:14.429134 | 
2026-01-05 00:24:14.429357 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-05 00:24:17.520503 | controller | changed
2026-01-05 00:24:17.533789 | 
2026-01-05 00:24:17.533959 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-05 00:24:20.629703 | controller | changed
2026-01-05 00:24:20.643943 | 
2026-01-05 00:24:20.644135 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-05 00:24:20.670683 | controller | skipping: Conditional result was False
2026-01-05 00:24:20.680990 | 
2026-01-05 00:24:20.681156 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-05 00:24:21.096430 | controller -> localhost | changed
2026-01-05 00:24:21.118493 | 
2026-01-05 00:24:21.118664 | TASK [add-build-sshkey : Add back temp key]
2026-01-05 00:24:21.424347 | controller -> localhost | Identity added: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/de792228e0494e168236c54c5a91d076_id_rsa (zuul-build-sshkey)
2026-01-05 00:24:21.424671 | controller -> localhost | ok: Runtime: 0:00:00.008931
2026-01-05 00:24:21.435146 | 
2026-01-05 00:24:21.435298 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-05 00:24:22.371251 | controller | ok
2026-01-05 00:24:22.379322 | 
2026-01-05 00:24:22.379458 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-05 00:24:22.415064 | controller | skipping: Conditional result was False
2026-01-05 00:24:22.427519 | 
2026-01-05 00:24:22.427642 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-05 00:24:22.448592 | controller | ok
2026-01-05 00:24:22.465124 | 
2026-01-05 00:24:22.465235 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-05 00:24:22.737515 | controller -> localhost | ok
2026-01-05 00:24:22.747392 | 
2026-01-05 00:24:22.747510 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-05 00:24:22.785205 | controller | ok
2026-01-05 00:24:22.805749 | controller | included: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-05 00:24:22.815009 | 
2026-01-05 00:24:22.815118 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-05 00:24:23.104939 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-05 00:24:23.105130 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/de792228e0494e168236c54c5a91d076_id_ecdsa.
2026-01-05 00:24:23.105159 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/de792228e0494e168236c54c5a91d076_id_ecdsa.pub.
2026-01-05 00:24:23.105191 | controller -> localhost | The key fingerprint is:
2026-01-05 00:24:23.105212 | controller -> localhost | SHA256:ZVIQxQfaAhop4N01lhGqfZ6D5IsMymGJWgIlGhlNmZE zuul-build-sshkey
2026-01-05 00:24:23.105233 | controller -> localhost | The key's randomart image is:
2026-01-05 00:24:23.105253 | controller -> localhost | +---[ECDSA 521]---+
2026-01-05 00:24:23.105272 | controller -> localhost | |o+o=...**=+.     |
2026-01-05 00:24:23.105291 | controller -> localhost | |.oE oo+o.+. .    |
2026-01-05 00:24:23.105309 | controller -> localhost | |+..o.o  + +.     |
2026-01-05 00:24:23.105328 | controller -> localhost | |.+  o    =       |
2026-01-05 00:24:23.105346 | controller -> localhost | |o  . o .S        |
2026-01-05 00:24:23.105364 | controller -> localhost | |o . o + .        |
2026-01-05 00:24:23.105382 | controller -> localhost | |o=.  o +         |
2026-01-05 00:24:23.105400 | controller -> localhost | |=o+ . . .        |
2026-01-05 00:24:23.105418 | controller -> localhost | |o. o .           |
2026-01-05 00:24:23.105436 | controller -> localhost | +----[SHA256]-----+
2026-01-05 00:24:23.105483 | controller -> localhost | ok: Runtime: 0:00:00.017275
2026-01-05 00:24:23.112539 | 
2026-01-05 00:24:23.112618 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-05 00:24:23.147189 | controller | ok
2026-01-05 00:24:23.158652 | controller | included: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-05 00:24:23.172950 | 
2026-01-05 00:24:23.173089 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-05 00:24:23.199817 | controller | skipping: Conditional result was False
2026-01-05 00:24:23.211919 | 
2026-01-05 00:24:23.212042 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-05 00:24:24.141938 | controller | changed
2026-01-05 00:24:24.147999 | 
2026-01-05 00:24:24.148067 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-05 00:24:24.797461 | controller | ok
2026-01-05 00:24:24.805166 | 
2026-01-05 00:24:24.805306 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-05 00:24:27.862532 | controller | changed
2026-01-05 00:24:27.871132 | 
2026-01-05 00:24:27.871227 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-05 00:24:30.910476 | controller | changed
2026-01-05 00:24:30.926109 | 
2026-01-05 00:24:30.926298 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-05 00:24:30.954953 | controller | skipping: Conditional result was False
2026-01-05 00:24:30.970914 | 
2026-01-05 00:24:30.971073 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-05 00:24:31.277705 | controller -> localhost | changed
2026-01-05 00:24:31.289926 | 
2026-01-05 00:24:31.290017 | TASK [add-build-sshkey : Add back temp key]
2026-01-05 00:24:31.568445 | controller -> localhost | Identity added: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/de792228e0494e168236c54c5a91d076_id_ecdsa (zuul-build-sshkey)
2026-01-05 00:24:31.568977 | controller -> localhost | ok: Runtime: 0:00:00.008476
2026-01-05 00:24:31.575959 | 
2026-01-05 00:24:31.576027 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-05 00:24:32.341882 | controller | ok
2026-01-05 00:24:32.350794 | 
2026-01-05 00:24:32.350933 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-05 00:24:32.386170 | controller | skipping: Conditional result was False
2026-01-05 00:24:32.398550 | 
2026-01-05 00:24:32.398669 | TASK [include_role : remove-zuul-sshkey]
2026-01-05 00:24:32.423237 | controller | skipping: Conditional result was False
2026-01-05 00:24:32.429662 | 
2026-01-05 00:24:32.429768 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-05 00:24:33.067611 | controller | ok: "logs"
2026-01-05 00:24:33.068036 | controller | ok: All items complete
2026-01-05 00:24:33.068071 | 
2026-01-05 00:24:33.690247 | controller | ok: "artifacts"
2026-01-05 00:24:34.321844 | controller | ok: "docs"
2026-01-05 00:24:34.340676 | 
2026-01-05 00:24:34.340882 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-05 00:24:35.068285 | controller | changed: "logs"
2026-01-05 00:24:35.683360 | controller | changed: "artifacts"
2026-01-05 00:24:36.288592 | controller | changed: "docs"
2026-01-05 00:24:36.325443 | 
2026-01-05 00:24:36.325569 | PLAY RECAP
2026-01-05 00:24:36.325620 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-05 00:24:36.325649 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-05 00:24:36.325669 | 
2026-01-05 00:24:36.457144 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-05 00:24:36.459182 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-05 00:24:37.120621 | 
2026-01-05 00:24:37.120808 | PLAY [all]
2026-01-05 00:24:37.151000 | 
2026-01-05 00:24:37.151158 | TASK [Install binary dependencies]
2026-01-05 00:24:37.203463 | controller | ok
2026-01-05 00:24:37.224210 | 
2026-01-05 00:24:37.224346 | TASK [bindep : Include find tasks]
2026-01-05 00:24:37.254428 | controller | ok
2026-01-05 00:24:37.262651 | controller | included: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-05 00:24:37.270129 | 
2026-01-05 00:24:37.270241 | TASK [bindep : Look for bindep.txt]
2026-01-05 00:24:38.200176 | controller | ok
2026-01-05 00:24:38.208424 | 
2026-01-05 00:24:38.208515 | TASK [bindep : Define bindep_file fact]
2026-01-05 00:24:38.223743 | controller | skipping: Conditional result was False
2026-01-05 00:24:38.230468 | 
2026-01-05 00:24:38.230553 | TASK [bindep : Look for other-requirements.txt]
2026-01-05 00:24:38.854863 | controller | ok
2026-01-05 00:24:38.864326 | 
2026-01-05 00:24:38.864489 | TASK [bindep : Define bindep_file fact]
2026-01-05 00:24:38.889830 | controller | skipping: Conditional result was False
2026-01-05 00:24:38.896718 | 
2026-01-05 00:24:38.896871 | TASK [bindep : Look for bindep fallback file]
2026-01-05 00:24:38.920977 | controller | skipping: Conditional result was False
2026-01-05 00:24:38.927262 | 
2026-01-05 00:24:38.927335 | TASK [bindep : Define bindep_file fact]
2026-01-05 00:24:38.951299 | controller | skipping: Conditional result was False
2026-01-05 00:24:38.959352 | 
2026-01-05 00:24:38.959440 | TASK [bindep : Include bindep tasks]
2026-01-05 00:24:38.984381 | controller | skipping: Conditional result was False
2026-01-05 00:24:38.992759 | 
2026-01-05 00:24:38.992844 | TASK [bindep : Include install tasks]
2026-01-05 00:24:39.018390 | controller | skipping: Conditional result was False
2026-01-05 00:24:39.026680 | 
2026-01-05 00:24:39.026783 | LOOP [bindep : Include package tasks]
2026-01-05 00:24:39.098958 | 
2026-01-05 00:24:39.099154 | TASK [Run test-setup role]
2026-01-05 00:24:39.121496 | controller | ok
2026-01-05 00:24:39.143999 | 
2026-01-05 00:24:39.144100 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-05 00:24:39.879444 | controller | ok
2026-01-05 00:24:39.888272 | 
2026-01-05 00:24:39.888389 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-05 00:24:40.261032 | controller | skipping: Conditional result was False
2026-01-05 00:24:40.288328 | 
2026-01-05 00:24:40.288497 | PLAY RECAP
2026-01-05 00:24:40.288548 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-05 00:24:40.288570 | 
2026-01-05 00:24:40.414491 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-05 00:24:40.415434 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-05 00:24:41.072738 | 
2026-01-05 00:24:41.072877 | PLAY [controller]
2026-01-05 00:24:41.093920 | 
2026-01-05 00:24:41.094026 | TASK [Create the /root directory]
2026-01-05 00:24:42.188488 | controller | ok
2026-01-05 00:24:42.199338 | 
2026-01-05 00:24:42.199500 | TASK [Install glibc-langpack-en]
2026-01-05 00:24:50.406221 | controller | ok: Nothing to do
2026-01-05 00:24:50.419402 | 
2026-01-05 00:24:50.419521 | TASK [Ensure controller directory exists]
2026-01-05 00:24:51.287781 | controller | changed
2026-01-05 00:24:51.295352 | 
2026-01-05 00:24:51.295482 | TASK [Install container runtime]
2026-01-05 00:24:51.338917 | controller | ok
2026-01-05 00:24:51.386579 | 
2026-01-05 00:24:51.386752 | LOOP [ensure-podman : Find distribution installation]
2026-01-05 00:24:51.418449 | controller | ok: "/var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-05 00:24:51.430677 | controller | included: /var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-05 00:24:51.439335 | 
2026-01-05 00:24:51.439440 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-05 00:26:49.553501 | controller | changed
2026-01-05 00:26:49.566042 | 
2026-01-05 00:26:49.566161 | TASK [ensure-podman : Fetch podman version]
2026-01-05 00:26:50.702554 | controller | Client:       Podman Engine
2026-01-05 00:26:50.736769 | controller | Version:      4.6.2
2026-01-05 00:26:50.736837 | controller | API Version:  4.6.2
2026-01-05 00:26:50.736846 | controller | Go Version:   go1.19.12
2026-01-05 00:26:50.736868 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-05 00:26:50.736877 | controller | OS/Arch:      linux/amd64
2026-01-05 00:26:50.941777 | controller | ok: Runtime: 0:00:00.276717
2026-01-05 00:26:50.956406 | 
2026-01-05 00:26:50.956589 | TASK [ensure-podman : Print podman version installed]
2026-01-05 00:26:50.987324 | Podman version: Client:       Podman Engine
2026-01-05 00:26:50.987572 | Version:      4.6.2
2026-01-05 00:26:50.987632 | API Version:  4.6.2
2026-01-05 00:26:50.987678 | Go Version:   go1.19.12
2026-01-05 00:26:50.987719 | Built:        Mon Aug 28 19:38:31 2023
2026-01-05 00:26:50.987809 | OS/Arch:      linux/amd64
2026-01-05 00:26:51.000398 | 
2026-01-05 00:26:51.000541 | TASK [ensure-podman : Validate podman engine]
2026-01-05 00:26:51.369960 | controller | skipping: Conditional result was False
2026-01-05 00:26:51.386850 | 
2026-01-05 00:26:51.387059 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-05 00:26:51.406201 | controller | skipping: Conditional result was False
2026-01-05 00:26:51.439023 | 
2026-01-05 00:26:51.439248 | TASK [Ensure python3.8 is present]
2026-01-05 00:26:51.457700 | controller | skipping: Conditional result was False
2026-01-05 00:26:51.468719 | 
2026-01-05 00:26:51.468943 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-05 00:26:51.493471 | controller | ok
2026-01-05 00:26:51.516045 | 
2026-01-05 00:26:51.516238 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-05 00:26:55.492894 | controller | ok: Nothing to do
2026-01-05 00:26:55.506486 | 
2026-01-05 00:26:55.506653 | TASK [our-ensure-python : Also install python3-devel]
2026-01-05 00:27:10.759258 | controller | changed
2026-01-05 00:27:10.770835 | 
2026-01-05 00:27:10.770935 | TASK [Run ensure-virtualenv role]
2026-01-05 00:27:10.799791 | controller | ok
2026-01-05 00:27:10.869497 | 
2026-01-05 00:27:10.869621 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-05 00:27:11.616979 | controller | /usr/bin/virtualenv
2026-01-05 00:27:12.224983 | controller | ok: Runtime: 0:00:00.009953
2026-01-05 00:27:12.233461 | 
2026-01-05 00:27:12.233557 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-05 00:27:12.274287 | controller | skipping: Conditional result was False
2026-01-05 00:27:12.274834 | controller | ok: All items complete
2026-01-05 00:27:12.274903 | 
2026-01-05 00:27:12.295179 | 
2026-01-05 00:27:12.295326 | TASK [Find the full path of the Python interpreter]
2026-01-05 00:27:13.068715 | controller | /usr/bin/python3
2026-01-05 00:27:13.660385 | controller | ok
2026-01-05 00:27:13.668484 | 
2026-01-05 00:27:13.668606 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-05 00:27:15.444264 | controller | created virtual environment CPython3.11.0.final.0-64 in 822ms
2026-01-05 00:27:15.543697 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-05 00:27:15.543803 | 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-05 00:27:15.543829 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-05 00:27:15.543854 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-05 00:27:16.036031 | controller | changed
2026-01-05 00:27:16.043350 | 
2026-01-05 00:27:16.043448 | TASK [Set selinux package]
2026-01-05 00:27:16.065611 | controller | ok
2026-01-05 00:27:16.074833 | 
2026-01-05 00:27:16.074935 | TASK [Set selinux package (Fedora)]
2026-01-05 00:27:16.123989 | controller | ok
2026-01-05 00:27:16.136509 | 
2026-01-05 00:27:16.136710 | TASK [Install selinux into virtualenv]
2026-01-05 00:27:19.428742 | controller | Collecting selinux-please-lie-to-me
2026-01-05 00:27:19.498218 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-05 00:27:20.042876 | controller | Collecting setuptools<50.0.0
2026-01-05 00:27:20.049708 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-05 00:27:20.107598 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.5 MB/s eta 0:00:00
2026-01-05 00:27:20.252415 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-05 00:27:20.252746 | controller |   Attempting uninstall: setuptools
2026-01-05 00:27:20.258766 | controller |     Found existing installation: setuptools 62.6.0
2026-01-05 00:27:20.359449 | controller |     Uninstalling setuptools-62.6.0:
2026-01-05 00:27:20.381259 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-05 00:27:21.239524 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-05 00:27:21.438310 | controller |
2026-01-05 00:27:21.722961 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-05 00:27:21.723018 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-05 00:27:22.028497 | controller | ok: Runtime: 0:00:04.689172
2026-01-05 00:27:22.034632 | 
2026-01-05 00:27:22.034706 | TASK [Install pytest-forked into virtualenv]
2026-01-05 00:27:23.582712 | controller | Collecting pytest-forked
2026-01-05 00:27:23.644654 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-05 00:27:23.708066 | controller | Collecting py
2026-01-05 00:27:23.712867 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-05 00:27:23.743723 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.6 MB/s eta 0:00:00
2026-01-05 00:27:23.941399 | controller | Collecting pytest>=3.10
2026-01-05 00:27:23.946534 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-05 00:27:23.973331 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 15.8 MB/s eta 0:00:00
2026-01-05 00:27:24.041627 | controller | Collecting iniconfig>=1.0.1
2026-01-05 00:27:24.047313 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-05 00:27:24.111662 | controller | Collecting packaging>=22
2026-01-05 00:27:24.117599 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-05 00:27:24.132204 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 5.7 MB/s eta 0:00:00
2026-01-05 00:27:24.188757 | controller | Collecting pluggy<2,>=1.5
2026-01-05 00:27:24.199114 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-05 00:27:24.297523 | controller | Collecting pygments>=2.7.2
2026-01-05 00:27:24.303009 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-05 00:27:24.334999 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 44.8 MB/s eta 0:00:00
2026-01-05 00:27:24.505405 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-05 00:27:27.080643 | 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-05 00:27:27.097420 | controller |
2026-01-05 00:27:27.309781 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-05 00:27:27.309831 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-05 00:27:27.920295 | controller | ok: Runtime: 0:00:04.479588
2026-01-05 00:27:27.926581 | 
2026-01-05 00:27:27.926686 | TASK [Update pip]
2026-01-05 00:27:29.340388 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-05 00:27:29.603910 | controller | Collecting pip
2026-01-05 00:27:29.696382 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-05 00:27:29.784353 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 21.3 MB/s eta 0:00:00
2026-01-05 00:27:29.898223 | controller | Installing collected packages: pip
2026-01-05 00:27:29.898421 | controller |   Attempting uninstall: pip
2026-01-05 00:27:29.901783 | controller |     Found existing installation: pip 22.2.2
2026-01-05 00:27:30.133746 | controller |     Uninstalling pip-22.2.2:
2026-01-05 00:27:30.160060 | controller |       Successfully uninstalled pip-22.2.2
2026-01-05 00:27:31.956597 | controller | Successfully installed pip-25.3
2026-01-05 00:27:32.313577 | controller | ok: Runtime: 0:00:03.306229
2026-01-05 00:27:32.322198 | 
2026-01-05 00:27:32.322303 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-05 00:27:33.266937 | controller | changed
2026-01-05 00:27:33.276022 | 
2026-01-05 00:27:33.276166 | TASK [Install ansible into virtualenv]
2026-01-05 00:27:34.566576 | controller | Processing ./src/github.com/ansible/ansible
2026-01-05 00:27:34.571730 | controller |   Installing build dependencies: started
2026-01-05 00:27:36.390623 | controller |   Installing build dependencies: finished with status 'done'
2026-01-05 00:27:36.390853 | controller |   Getting requirements to build wheel: started
2026-01-05 00:27:37.939856 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-05 00:27:37.940955 | controller |   Preparing metadata (pyproject.toml): started
2026-01-05 00:27:38.823150 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-05 00:27:38.825987 | 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-05 00:27:38.829835 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-05 00:27:39.188155 | controller | ERROR
2026-01-05 00:27:39.188406 | controller | {
2026-01-05 00:27:39.188450 | controller |   "delta": "0:00:04.976648",
2026-01-05 00:27:39.188479 | controller |   "end": "2026-01-05 00:27:38.988478",
2026-01-05 00:27:39.188506 | controller |   "msg": "non-zero return code",
2026-01-05 00:27:39.188552 | controller |   "rc": 1,
2026-01-05 00:27:39.188592 | controller |   "start": "2026-01-05 00:27:34.011830"
2026-01-05 00:27:39.188633 | controller | }
failure
2026-01-05 00:27:39.190842 | 
2026-01-05 00:27:39.190916 | PLAY RECAP
2026-01-05 00:27:39.190979 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-05 00:27:39.191010 | 
2026-01-05 00:27:39.323696 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-05 00:27:39.324965 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-05 00:27:39.932524 | 
2026-01-05 00:27:39.932633 | PLAY [all]
2026-01-05 00:27:39.954035 | 
2026-01-05 00:27:39.954123 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-05 00:27:41.830132 | controller | changed: non-zero return code
2026-01-05 00:27:41.842771 | 
2026-01-05 00:27:41.843052 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-05 00:27:41.872564 | controller | skipping: Conditional result was False
2026-01-05 00:27:41.884496 | 
2026-01-05 00:27:41.884720 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-05 00:27:41.935767 | 
2026-01-05 00:27:41.936067 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-05 00:27:41.974767 | 
2026-01-05 00:27:41.975042 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-05 00:27:42.001753 | controller | skipping: Conditional result was False
2026-01-05 00:27:42.011709 | 
2026-01-05 00:27:42.011852 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-05 00:27:42.046830 | 
2026-01-05 00:27:42.047103 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-05 00:27:42.074844 | controller | skipping: Conditional result was False
2026-01-05 00:27:42.082506 | 
2026-01-05 00:27:42.082630 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-05 00:27:42.109035 | controller | skipping: Conditional result was False
2026-01-05 00:27:42.117987 | 
2026-01-05 00:27:42.118127 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-05 00:27:42.135812 | controller | skipping: Conditional result was False
2026-01-05 00:27:42.176999 | 
2026-01-05 00:27:42.177658 | PLAY RECAP
2026-01-05 00:27:42.177707 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-05 00:27:42.177746 | 
2026-01-05 00:27:42.420217 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-05 00:27:42.421415 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-05 00:27:43.197249 | 
2026-01-05 00:27:43.197450 | PLAY [all:!appliance*]
2026-01-05 00:27:43.223468 | 
2026-01-05 00:27:43.223627 | TASK [unregister the node]
2026-01-05 00:27:43.579578 | controller | skipping: Conditional result was False
2026-01-05 00:27:43.587914 | 
2026-01-05 00:27:43.588045 | TASK [include_role : fetch-output]
2026-01-05 00:27:43.621141 | controller | ok
2026-01-05 00:27:43.647481 | 
2026-01-05 00:27:43.647630 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-05 00:27:43.715031 | controller | skipping: Conditional result was False
2026-01-05 00:27:43.724041 | 
2026-01-05 00:27:43.724201 | TASK [fetch-output : Set log path for single node]
2026-01-05 00:27:43.757272 | controller | ok
2026-01-05 00:27:43.765053 | 
2026-01-05 00:27:43.765154 | LOOP [fetch-output : Ensure local output dirs]
2026-01-05 00:27:44.214682 | controller -> localhost | ok: "/var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/logs"
2026-01-05 00:27:44.457152 | controller -> localhost | changed: "/var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/artifacts"
2026-01-05 00:27:44.677265 | controller -> localhost | changed: "/var/lib/zuul/builds/de792228e0494e168236c54c5a91d076/work/docs"
2026-01-05 00:27:44.692174 | 
2026-01-05 00:27:44.692397 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-05 00:27:46.900056 | controller | changed:
2026-01-05 00:27:46.900364 | controller | .d..t...... ./
2026-01-05 00:27:46.900432 | controller | cd+++++++++ controller/
2026-01-05 00:27:46.900510 | controller | changed: All items complete
2026-01-05 00:27:46.900563 | 
2026-01-05 00:27:48.955366 | controller | changed: .d..t...... ./
2026-01-05 00:27:51.049319 | controller | changed: .d..t...... ./
2026-01-05 00:27:51.067910 | 
2026-01-05 00:27:51.068053 | TASK [include_role : fetch-output-openshift]
2026-01-05 00:27:51.083925 | controller | skipping: Conditional result was False
2026-01-05 00:27:51.095112 | 
2026-01-05 00:27:51.095224 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-05 00:27:51.129365 | controller | skipping: Conditional result was False
2026-01-05 00:27:51.140196 | controller | skipping: Conditional result was False
2026-01-05 00:27:51.202074 | 
2026-01-05 00:27:51.202272 | PLAY [localhost]
2026-01-05 00:27:51.221216 | 
2026-01-05 00:27:51.221320 | TASK [Run Zuul manifest role]
2026-01-05 00:27:51.243159 | localhost | ok
2026-01-05 00:27:51.272271 | 
2026-01-05 00:27:51.272386 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-05 00:27:51.668877 | localhost | changed
2026-01-05 00:27:51.678720 | 
2026-01-05 00:27:51.678884 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-05 00:27:51.714213 | localhost | ok
2026-01-05 00:27:51.732875 | 
2026-01-05 00:27:51.733020 | TASK [Set zuul-log-path fact]
2026-01-05 00:27:51.755901 | localhost | ok
2026-01-05 00:27:51.810349 | 
2026-01-05 00:27:51.810510 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-05 00:27:51.842924 | localhost | ok
2026-01-05 00:27:51.855013 | 
2026-01-05 00:27:51.855138 | LOOP [Run upload-logs-swift role]
2026-01-05 00:27:51.891323 | localhost | Output suppressed because no_log was given
2026-01-05 00:27:51.948091 | 
2026-01-05 00:27:51.948223 | TASK [Set zuul-log-path fact]
2026-01-05 00:27:51.994349 | localhost | skipping: Conditional result was False
2026-01-05 00:27:52.003194 | 
2026-01-05 00:27:52.003318 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-05 00:27:52.448802 | localhost -> localhost | ok: Runtime: 0:00:00.008833
2026-01-05 00:27:52.456037 | 
2026-01-05 00:27:52.456172 | TASK [upload-logs-swift : Upload logs to swift]