2025-12-05 00:25:41.400699 | Job console starting...
2025-12-05 00:25:41.412106 | Updating repositories
2025-12-05 00:25:41.566113 | Preparing job workspace
2025-12-05 00:25:45.264032 | Running Ansible setup...
2025-12-05 00:25:53.102377 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-05 00:25:53.706465 | 
2025-12-05 00:25:53.706583 | PLAY [localhost]
2025-12-05 00:25:53.715176 | 
2025-12-05 00:25:53.715249 | TASK [Gathering Facts]
2025-12-05 00:25:54.732449 | localhost | ok
2025-12-05 00:25:54.749162 | 
2025-12-05 00:25:54.749295 | TASK [Setup log path fact]
2025-12-05 00:25:54.768544 | localhost | ok
2025-12-05 00:25:54.780691 | 
2025-12-05 00:25:54.780788 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 00:25:54.809347 | localhost | ok
2025-12-05 00:25:54.817294 | 
2025-12-05 00:25:54.817362 | TASK [emit-job-header : Print job information]
2025-12-05 00:25:54.864615 | # Job Information
2025-12-05 00:25:54.864761 | Ansible Version: 2.15.12
2025-12-05 00:25:54.864797 | Job: ansible-test-sanity-docker-milestone
2025-12-05 00:25:54.864842 | Pipeline: periodic
2025-12-05 00:25:54.864863 | Executor: ze03.softwarefactory-project.io
2025-12-05 00:25:54.864882 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-05 00:25:54.864905 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/542/ansible/5426493c40a842d0a8ab53d4359f6816/
2025-12-05 00:25:54.864925 | Event ID: 7d72bd1c9b21479fafd0f66ddaa3b50f
2025-12-05 00:25:54.868650 | 
2025-12-05 00:25:54.868715 | LOOP [emit-job-header : Print node information]
2025-12-05 00:25:54.988097 | localhost | ok:
2025-12-05 00:25:54.988389 | localhost | # Node Information
2025-12-05 00:25:54.988449 | localhost | Inventory Hostname: controller
2025-12-05 00:25:54.988526 | localhost | Hostname: np0005546228
2025-12-05 00:25:54.988569 | localhost | Username: zuul
2025-12-05 00:25:54.988613 | localhost | Distro: Fedora 37
2025-12-05 00:25:54.988653 | localhost | Provider: ansible-vexxhost-ams1
2025-12-05 00:25:54.988692 | localhost | Region: ams1
2025-12-05 00:25:54.988763 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-05 00:25:54.988812 | localhost | Product Name: OpenStack Nova
2025-12-05 00:25:54.988851 | localhost | Interface IP: 38.129.16.140
2025-12-05 00:25:55.000662 | 
2025-12-05 00:25:55.000753 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-05 00:25:55.403215 | localhost -> localhost | changed
2025-12-05 00:25:55.418481 | 
2025-12-05 00:25:55.418647 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-05 00:25:56.219825 | localhost -> localhost | changed
2025-12-05 00:25:56.239969 | 
2025-12-05 00:25:56.240051 | PLAY [all:!appliance*]
2025-12-05 00:25:56.256761 | 
2025-12-05 00:25:56.256865 | TASK [include_role : start-zuul-console]
2025-12-05 00:25:56.276441 | controller | ok
2025-12-05 00:25:56.290371 | 
2025-12-05 00:25:56.290475 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-05 00:25:57.418698 | controller | ok
2025-12-05 00:25:57.445601 | 
2025-12-05 00:25:57.445782 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-05 00:25:59.768480 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-05 00:25:59.783127 | 
2025-12-05 00:25:59.783266 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-05 00:26:00.161868 | controller | skipping: Conditional result was False
2025-12-05 00:26:00.170893 | 
2025-12-05 00:26:00.170988 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-05 00:26:00.206625 | controller | skipping: Conditional result was False
2025-12-05 00:26:00.215825 | 
2025-12-05 00:26:00.215947 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-05 00:26:00.251751 | controller | skipping: Conditional result was False
2025-12-05 00:26:00.261063 | 
2025-12-05 00:26:00.261148 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-05 00:26:00.286803 | controller | skipping: Conditional result was False
2025-12-05 00:26:00.295630 | 
2025-12-05 00:26:00.295711 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-05 00:26:00.321128 | controller | skipping: Conditional result was False
2025-12-05 00:26:00.331536 | 
2025-12-05 00:26:00.331805 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-05 00:26:00.358044 | controller | skipping: Conditional result was False
2025-12-05 00:26:00.373855 | 
2025-12-05 00:26:00.373959 | TASK [Disable Fedora Modular]
2025-12-05 00:26:01.515976 | controller | changed
2025-12-05 00:26:01.530460 | 
2025-12-05 00:26:01.530607 | TASK [Enable EPEL]
2025-12-05 00:26:01.557450 | controller | skipping: Conditional result was False
2025-12-05 00:26:01.571319 | 
2025-12-05 00:26:01.571463 | TASK [Register the RHEL node]
2025-12-05 00:26:01.984763 | 
2025-12-05 00:26:01.985035 | TASK [Show the subscription-manager status]
2025-12-05 00:26:02.379136 | controller | skipping: Conditional result was False
2025-12-05 00:26:02.393786 | 
2025-12-05 00:26:02.393958 | TASK [Enable EPEL on RHEL]
2025-12-05 00:26:02.795941 | controller | skipping: Conditional result was False
2025-12-05 00:26:02.809677 | 
2025-12-05 00:26:02.809842 | TASK [Install git and tox]
2025-12-05 00:28:10.938402 | controller | changed
2025-12-05 00:28:10.953031 | 
2025-12-05 00:28:10.953167 | TASK [include_role : prepare-workspace]
2025-12-05 00:28:10.992628 | controller | ok
2025-12-05 00:28:11.029785 | 
2025-12-05 00:28:11.029896 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-05 00:28:11.973950 | controller | ok
2025-12-05 00:28:11.987242 | 
2025-12-05 00:28:11.987378 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-05 00:28:27.673178 | controller | Output suppressed because no_log was given
2025-12-05 00:28:27.693678 | 
2025-12-05 00:28:27.693822 | TASK [include_role : prepare-workspace-openshift]
2025-12-05 00:28:27.718828 | controller | skipping: Conditional result was False
2025-12-05 00:28:27.783495 | 
2025-12-05 00:28:27.783597 | PLAY [all:!appliance]
2025-12-05 00:28:27.799433 | 
2025-12-05 00:28:27.799505 | TASK [Run add-build-sshkey role (RSA)]
2025-12-05 00:28:27.830129 | controller | ok
2025-12-05 00:28:27.845584 | 
2025-12-05 00:28:27.845666 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 00:28:28.144997 | controller -> localhost | ok
2025-12-05 00:28:28.158200 | 
2025-12-05 00:28:28.158281 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 00:28:28.199076 | controller | ok
2025-12-05 00:28:28.223000 | controller | included: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 00:28:28.232630 | 
2025-12-05 00:28:28.232713 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 00:28:28.683468 | controller -> localhost | Generating public/private rsa key pair.
2025-12-05 00:28:28.683699 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/5426493c40a842d0a8ab53d4359f6816_id_rsa.
2025-12-05 00:28:28.683763 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/5426493c40a842d0a8ab53d4359f6816_id_rsa.pub.
2025-12-05 00:28:28.683796 | controller -> localhost | The key fingerprint is:
2025-12-05 00:28:28.683825 | controller -> localhost | SHA256:8hMk3RCCmCjGF7wILIT0C0re9jTv8DYWas+YClrHDnw zuul-build-sshkey
2025-12-05 00:28:28.683853 | controller -> localhost | The key's randomart image is:
2025-12-05 00:28:28.683880 | controller -> localhost | +---[RSA 2048]----+
2025-12-05 00:28:28.683907 | controller -> localhost | |*+.+... o.       |
2025-12-05 00:28:28.683936 | controller -> localhost | |*++o.  o o       |
2025-12-05 00:28:28.683962 | controller -> localhost | |=oo.. . o .      |
2025-12-05 00:28:28.683989 | controller -> localhost | |+.o..  o         |
2025-12-05 00:28:28.684016 | controller -> localhost | |.. + o. S        |
2025-12-05 00:28:28.684055 | controller -> localhost | | ...o o+ .       |
2025-12-05 00:28:28.684088 | controller -> localhost | | .+ Eo..+        |
2025-12-05 00:28:28.684116 | controller -> localhost | |...= oB+ .       |
2025-12-05 00:28:28.684143 | controller -> localhost | |.  .+o+=.        |
2025-12-05 00:28:28.684174 | controller -> localhost | +----[SHA256]-----+
2025-12-05 00:28:28.684244 | controller -> localhost | ok: Runtime: 0:00:00.035014
2025-12-05 00:28:28.694183 | 
2025-12-05 00:28:28.694294 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 00:28:28.717781 | controller | ok
2025-12-05 00:28:28.732556 | controller | included: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 00:28:28.746375 | 
2025-12-05 00:28:28.746460 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 00:28:28.761217 | controller | skipping: Conditional result was False
2025-12-05 00:28:28.768887 | 
2025-12-05 00:28:28.768983 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 00:28:29.828553 | controller | changed
2025-12-05 00:28:29.836980 | 
2025-12-05 00:28:29.837072 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 00:28:30.492500 | controller | ok
2025-12-05 00:28:30.501214 | 
2025-12-05 00:28:30.501282 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 00:28:33.571996 | controller | changed
2025-12-05 00:28:33.586214 | 
2025-12-05 00:28:33.586363 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 00:28:36.655143 | controller | changed
2025-12-05 00:28:36.667340 | 
2025-12-05 00:28:36.667430 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 00:28:36.692049 | controller | skipping: Conditional result was False
2025-12-05 00:28:36.701143 | 
2025-12-05 00:28:36.701246 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 00:28:37.084294 | controller -> localhost | changed
2025-12-05 00:28:37.116590 | 
2025-12-05 00:28:37.116746 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 00:28:37.389211 | controller -> localhost | Identity added: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/5426493c40a842d0a8ab53d4359f6816_id_rsa (zuul-build-sshkey)
2025-12-05 00:28:37.389517 | controller -> localhost | ok: Runtime: 0:00:00.011571
2025-12-05 00:28:37.399417 | 
2025-12-05 00:28:37.399518 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 00:28:38.339537 | controller | ok
2025-12-05 00:28:38.351153 | 
2025-12-05 00:28:38.351258 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 00:28:38.376840 | controller | skipping: Conditional result was False
2025-12-05 00:28:38.395481 | 
2025-12-05 00:28:38.395607 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-05 00:28:38.429200 | controller | ok
2025-12-05 00:28:38.462400 | 
2025-12-05 00:28:38.462539 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 00:28:38.731387 | controller -> localhost | ok
2025-12-05 00:28:38.738097 | 
2025-12-05 00:28:38.738186 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 00:28:38.779578 | controller | ok
2025-12-05 00:28:38.790360 | controller | included: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 00:28:38.796519 | 
2025-12-05 00:28:38.796581 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 00:28:39.064068 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-05 00:28:39.064256 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/5426493c40a842d0a8ab53d4359f6816_id_ecdsa.
2025-12-05 00:28:39.064284 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/5426493c40a842d0a8ab53d4359f6816_id_ecdsa.pub.
2025-12-05 00:28:39.064313 | controller -> localhost | The key fingerprint is:
2025-12-05 00:28:39.064333 | controller -> localhost | SHA256:iNEhBzYkFP3ex2gtPWEsrVZlLdzoDl56hU6ov/IEs2A zuul-build-sshkey
2025-12-05 00:28:39.064352 | controller -> localhost | The key's randomart image is:
2025-12-05 00:28:39.064370 | controller -> localhost | +---[ECDSA 521]---+
2025-12-05 00:28:39.064387 | controller -> localhost | | .++*.o    . +   |
2025-12-05 00:28:39.064404 | controller -> localhost | |   o.= .    * o  |
2025-12-05 00:28:39.064420 | controller -> localhost | |    ...  o = o   |
2025-12-05 00:28:39.064437 | controller -> localhost | |     o... O = .  |
2025-12-05 00:28:39.064454 | controller -> localhost | |    ..E.S% O .   |
2025-12-05 00:28:39.064471 | controller -> localhost | |     ...O+O +    |
2025-12-05 00:28:39.064487 | controller -> localhost | |       o.+.o     |
2025-12-05 00:28:39.064504 | controller -> localhost | |        ...      |
2025-12-05 00:28:39.064521 | controller -> localhost | |         oo.     |
2025-12-05 00:28:39.064537 | controller -> localhost | +----[SHA256]-----+
2025-12-05 00:28:39.064587 | controller -> localhost | ok: Runtime: 0:00:00.007791
2025-12-05 00:28:39.071453 | 
2025-12-05 00:28:39.071521 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 00:28:39.091829 | controller | ok
2025-12-05 00:28:39.099265 | controller | included: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 00:28:39.108843 | 
2025-12-05 00:28:39.108911 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 00:28:39.123099 | controller | skipping: Conditional result was False
2025-12-05 00:28:39.129971 | 
2025-12-05 00:28:39.130037 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 00:28:40.038244 | controller | changed
2025-12-05 00:28:40.044394 | 
2025-12-05 00:28:40.044461 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 00:28:40.771566 | controller | ok
2025-12-05 00:28:40.779487 | 
2025-12-05 00:28:40.779572 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 00:28:43.858108 | controller | changed
2025-12-05 00:28:43.865371 | 
2025-12-05 00:28:43.865452 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 00:28:46.920462 | controller | changed
2025-12-05 00:28:46.930557 | 
2025-12-05 00:28:46.930663 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 00:28:46.957264 | controller | skipping: Conditional result was False
2025-12-05 00:28:46.967290 | 
2025-12-05 00:28:46.967384 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 00:28:47.228515 | controller -> localhost | changed
2025-12-05 00:28:47.245090 | 
2025-12-05 00:28:47.245178 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 00:28:47.528594 | controller -> localhost | Identity added: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/5426493c40a842d0a8ab53d4359f6816_id_ecdsa (zuul-build-sshkey)
2025-12-05 00:28:47.528812 | controller -> localhost | ok: Runtime: 0:00:00.014045
2025-12-05 00:28:47.535246 | 
2025-12-05 00:28:47.535308 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 00:28:48.343152 | controller | ok
2025-12-05 00:28:48.356381 | 
2025-12-05 00:28:48.356530 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 00:28:48.395010 | controller | skipping: Conditional result was False
2025-12-05 00:28:48.426128 | 
2025-12-05 00:28:48.426328 | TASK [include_role : remove-zuul-sshkey]
2025-12-05 00:28:48.454593 | controller | skipping: Conditional result was False
2025-12-05 00:28:48.470971 | 
2025-12-05 00:28:48.471140 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 00:28:49.151441 | controller | ok: "logs"
2025-12-05 00:28:49.151680 | controller | ok: All items complete
2025-12-05 00:28:49.151707 | 
2025-12-05 00:28:49.814213 | controller | ok: "artifacts"
2025-12-05 00:28:50.455213 | controller | ok: "docs"
2025-12-05 00:28:50.484642 | 
2025-12-05 00:28:50.484903 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 00:28:51.198774 | controller | changed: "logs"
2025-12-05 00:28:51.866955 | controller | changed: "artifacts"
2025-12-05 00:28:52.538481 | controller | changed: "docs"
2025-12-05 00:28:52.584649 | 
2025-12-05 00:28:52.584782 | PLAY RECAP
2025-12-05 00:28:52.584828 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-05 00:28:52.584854 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 00:28:52.584873 | 
2025-12-05 00:28:52.713013 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-05 00:28:52.713891 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 00:28:53.296195 | 
2025-12-05 00:28:53.296311 | PLAY [all]
2025-12-05 00:28:53.318625 | 
2025-12-05 00:28:53.318744 | TASK [Install binary dependencies]
2025-12-05 00:28:53.388990 | controller | ok
2025-12-05 00:28:53.408863 | 
2025-12-05 00:28:53.408995 | TASK [bindep : Include find tasks]
2025-12-05 00:28:53.438553 | controller | ok
2025-12-05 00:28:53.446354 | controller | included: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-05 00:28:53.452447 | 
2025-12-05 00:28:53.452507 | TASK [bindep : Look for bindep.txt]
2025-12-05 00:28:54.399520 | controller | ok
2025-12-05 00:28:54.413942 | 
2025-12-05 00:28:54.414100 | TASK [bindep : Define bindep_file fact]
2025-12-05 00:28:54.442225 | controller | skipping: Conditional result was False
2025-12-05 00:28:54.456575 | 
2025-12-05 00:28:54.456769 | TASK [bindep : Look for other-requirements.txt]
2025-12-05 00:28:55.128639 | controller | ok
2025-12-05 00:28:55.142410 | 
2025-12-05 00:28:55.142561 | TASK [bindep : Define bindep_file fact]
2025-12-05 00:28:55.179760 | controller | skipping: Conditional result was False
2025-12-05 00:28:55.194251 | 
2025-12-05 00:28:55.194399 | TASK [bindep : Look for bindep fallback file]
2025-12-05 00:28:55.231659 | controller | skipping: Conditional result was False
2025-12-05 00:28:55.245404 | 
2025-12-05 00:28:55.245553 | TASK [bindep : Define bindep_file fact]
2025-12-05 00:28:55.282395 | controller | skipping: Conditional result was False
2025-12-05 00:28:55.295856 | 
2025-12-05 00:28:55.295994 | TASK [bindep : Include bindep tasks]
2025-12-05 00:28:55.333424 | controller | skipping: Conditional result was False
2025-12-05 00:28:55.347227 | 
2025-12-05 00:28:55.347368 | TASK [bindep : Include install tasks]
2025-12-05 00:28:55.384294 | controller | skipping: Conditional result was False
2025-12-05 00:28:55.397817 | 
2025-12-05 00:28:55.397957 | LOOP [bindep : Include package tasks]
2025-12-05 00:28:55.480806 | 
2025-12-05 00:28:55.481066 | TASK [Run test-setup role]
2025-12-05 00:28:55.509466 | controller | ok
2025-12-05 00:28:55.538819 | 
2025-12-05 00:28:55.538916 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-05 00:28:56.282675 | controller | ok
2025-12-05 00:28:56.296371 | 
2025-12-05 00:28:56.296509 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-05 00:28:56.684891 | controller | skipping: Conditional result was False
2025-12-05 00:28:56.721654 | 
2025-12-05 00:28:56.721781 | PLAY RECAP
2025-12-05 00:28:56.721837 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-05 00:28:56.721867 | 
2025-12-05 00:28:56.828794 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-05 00:28:56.830522 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-05 00:28:57.420632 | 
2025-12-05 00:28:57.420776 | PLAY [controller]
2025-12-05 00:28:57.440869 | 
2025-12-05 00:28:57.440963 | TASK [Create the /root directory]
2025-12-05 00:28:58.615894 | controller | ok
2025-12-05 00:28:58.629312 | 
2025-12-05 00:28:58.629491 | TASK [Install glibc-langpack-en]
2025-12-05 00:29:06.733072 | controller | ok: Nothing to do
2025-12-05 00:29:06.741708 | 
2025-12-05 00:29:06.741809 | TASK [Ensure controller directory exists]
2025-12-05 00:29:07.626488 | controller | changed
2025-12-05 00:29:07.640554 | 
2025-12-05 00:29:07.640700 | TASK [Install container runtime]
2025-12-05 00:29:07.712069 | controller | ok
2025-12-05 00:29:07.778659 | 
2025-12-05 00:29:07.778818 | LOOP [ensure-podman : Find distribution installation]
2025-12-05 00:29:07.813165 | controller | ok: "/var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-05 00:29:07.824721 | controller | included: /var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-05 00:29:07.833957 | 
2025-12-05 00:29:07.834068 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-05 00:31:10.513824 | controller | changed
2025-12-05 00:31:10.527938 | 
2025-12-05 00:31:10.528098 | TASK [ensure-podman : Fetch podman version]
2025-12-05 00:31:11.622108 | controller | Client:       Podman Engine
2025-12-05 00:31:11.622225 | controller | Version:      4.6.2
2025-12-05 00:31:11.622270 | controller | API Version:  4.6.2
2025-12-05 00:31:11.622312 | controller | Go Version:   go1.19.12
2025-12-05 00:31:11.622370 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-05 00:31:11.622414 | controller | OS/Arch:      linux/amd64
2025-12-05 00:31:11.899533 | controller | ok: Runtime: 0:00:00.252836
2025-12-05 00:31:11.908961 | 
2025-12-05 00:31:11.909144 | TASK [ensure-podman : Print podman version installed]
2025-12-05 00:31:11.940966 | Podman version: Client:       Podman Engine
2025-12-05 00:31:11.941141 | Version:      4.6.2
2025-12-05 00:31:11.941172 | API Version:  4.6.2
2025-12-05 00:31:11.941192 | Go Version:   go1.19.12
2025-12-05 00:31:11.941210 | Built:        Mon Aug 28 19:38:31 2023
2025-12-05 00:31:11.941228 | OS/Arch:      linux/amd64
2025-12-05 00:31:11.949175 | 
2025-12-05 00:31:11.949259 | TASK [ensure-podman : Validate podman engine]
2025-12-05 00:31:12.316047 | controller | skipping: Conditional result was False
2025-12-05 00:31:12.332812 | 
2025-12-05 00:31:12.333029 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-05 00:31:12.361325 | controller | skipping: Conditional result was False
2025-12-05 00:31:12.379095 | 
2025-12-05 00:31:12.379190 | TASK [Ensure python3.8 is present]
2025-12-05 00:31:12.404106 | controller | skipping: Conditional result was False
2025-12-05 00:31:12.412824 | 
2025-12-05 00:31:12.412935 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-05 00:31:12.436955 | controller | ok
2025-12-05 00:31:12.464935 | 
2025-12-05 00:31:12.465084 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-05 00:31:15.930799 | controller | ok: Nothing to do
2025-12-05 00:31:15.943244 | 
2025-12-05 00:31:15.943378 | TASK [our-ensure-python : Also install python3-devel]
2025-12-05 00:31:30.998773 | controller | changed
2025-12-05 00:31:31.015457 | 
2025-12-05 00:31:31.015742 | TASK [Run ensure-virtualenv role]
2025-12-05 00:31:31.039179 | controller | ok
2025-12-05 00:31:31.061101 | 
2025-12-05 00:31:31.061192 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-05 00:31:31.824651 | controller | /usr/bin/virtualenv
2025-12-05 00:31:32.417334 | controller | ok: Runtime: 0:00:00.004662
2025-12-05 00:31:32.430544 | 
2025-12-05 00:31:32.430681 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-05 00:31:32.468167 | controller | skipping: Conditional result was False
2025-12-05 00:31:32.468631 | controller | ok: All items complete
2025-12-05 00:31:32.468690 | 
2025-12-05 00:31:32.494481 | 
2025-12-05 00:31:32.494685 | TASK [Find the full path of the Python interpreter]
2025-12-05 00:31:33.260603 | controller | /usr/bin/python3
2025-12-05 00:31:33.861267 | controller | ok
2025-12-05 00:31:33.873785 | 
2025-12-05 00:31:33.873924 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-05 00:31:35.809753 | controller | created virtual environment CPython3.11.0.final.0-64 in 943ms
2025-12-05 00:31:35.870736 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-05 00:31:35.870808 | 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)
2025-12-05 00:31:35.870828 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-05 00:31:35.870851 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-05 00:31:36.281642 | controller | changed
2025-12-05 00:31:36.288199 | 
2025-12-05 00:31:36.288266 | TASK [Set selinux package]
2025-12-05 00:31:36.307798 | controller | ok
2025-12-05 00:31:36.313403 | 
2025-12-05 00:31:36.313471 | TASK [Set selinux package (Fedora)]
2025-12-05 00:31:36.344630 | controller | ok
2025-12-05 00:31:36.351403 | 
2025-12-05 00:31:36.351483 | TASK [Install selinux into virtualenv]
2025-12-05 00:31:39.420672 | controller | Collecting selinux-please-lie-to-me
2025-12-05 00:31:39.489104 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-05 00:31:39.972161 | controller | Collecting setuptools<50.0.0
2025-12-05 00:31:39.977939 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-05 00:31:40.215065 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 3.4 MB/s eta 0:00:00
2025-12-05 00:31:40.406260 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-05 00:31:40.408260 | controller |   Attempting uninstall: setuptools
2025-12-05 00:31:40.408294 | controller |     Found existing installation: setuptools 62.6.0
2025-12-05 00:31:40.507622 | controller |     Uninstalling setuptools-62.6.0:
2025-12-05 00:31:40.521440 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-05 00:31:41.229418 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-05 00:31:41.456720 | controller |
2025-12-05 00:31:41.748101 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-05 00:31:41.748167 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-05 00:31:42.226293 | controller | ok: Runtime: 0:00:04.559574
2025-12-05 00:31:42.238205 | 
2025-12-05 00:31:42.238334 | TASK [Install pytest-forked into virtualenv]
2025-12-05 00:31:43.749750 | controller | Collecting pytest-forked
2025-12-05 00:31:43.811361 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-05 00:31:43.874632 | controller | Collecting py
2025-12-05 00:31:43.879375 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-05 00:31:43.918688 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.8 MB/s eta 0:00:00
2025-12-05 00:31:44.108104 | controller | Collecting pytest>=3.10
2025-12-05 00:31:44.118392 | controller |   Downloading pytest-9.0.1-py3-none-any.whl (373 kB)
2025-12-05 00:31:44.143495 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 17.8 MB/s eta 0:00:00
2025-12-05 00:31:44.218794 | controller | Collecting iniconfig>=1.0.1
2025-12-05 00:31:44.227732 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-05 00:31:44.288499 | controller | Collecting packaging>=22
2025-12-05 00:31:44.292638 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-05 00:31:44.305596 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 7.1 MB/s eta 0:00:00
2025-12-05 00:31:44.362230 | controller | Collecting pluggy<2,>=1.5
2025-12-05 00:31:44.367868 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-05 00:31:44.436783 | controller | Collecting pygments>=2.7.2
2025-12-05 00:31:44.441857 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-05 00:31:44.480523 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 35.8 MB/s eta 0:00:00
2025-12-05 00:31:44.595791 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-05 00:31:47.038032 | 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.1 pytest-forked-1.6.0
2025-12-05 00:31:47.053063 | controller |
2025-12-05 00:31:47.315489 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-05 00:31:47.315569 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-05 00:31:47.632359 | controller | ok: Runtime: 0:00:04.269397
2025-12-05 00:31:47.646879 | 
2025-12-05 00:31:47.647073 | TASK [Update pip]
2025-12-05 00:31:49.055796 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-05 00:31:49.311860 | controller | Collecting pip
2025-12-05 00:31:49.375136 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-05 00:31:49.451827 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 25.2 MB/s eta 0:00:00
2025-12-05 00:31:49.593413 | controller | Installing collected packages: pip
2025-12-05 00:31:49.596459 | controller |   Attempting uninstall: pip
2025-12-05 00:31:49.601889 | controller |     Found existing installation: pip 22.2.2
2025-12-05 00:31:49.857011 | controller |     Uninstalling pip-22.2.2:
2025-12-05 00:31:49.886129 | controller |       Successfully uninstalled pip-22.2.2
2025-12-05 00:31:51.743164 | controller | Successfully installed pip-25.3
2025-12-05 00:31:52.546640 | controller | ok: Runtime: 0:00:03.510778
2025-12-05 00:31:52.559695 | 
2025-12-05 00:31:52.559899 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-05 00:31:53.447379 | controller | changed
2025-12-05 00:31:53.459628 | 
2025-12-05 00:31:53.459812 | TASK [Install ansible into virtualenv]
2025-12-05 00:31:54.697005 | controller | Processing ./src/github.com/ansible/ansible
2025-12-05 00:31:54.702896 | controller |   Installing build dependencies: started
2025-12-05 00:31:56.531745 | controller |   Installing build dependencies: finished with status 'done'
2025-12-05 00:31:56.533666 | controller |   Getting requirements to build wheel: started
2025-12-05 00:31:58.149461 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-05 00:31:58.150155 | controller |   Preparing metadata (pyproject.toml): started
2025-12-05 00:31:59.083472 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-05 00:31:59.088314 | 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.
2025-12-05 00:31:59.091953 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-05 00:31:59.872668 | controller | ERROR
2025-12-05 00:31:59.873030 | controller | {
2025-12-05 00:31:59.873096 | controller |   "delta": "0:00:05.138471",
2025-12-05 00:31:59.873140 | controller |   "end": "2025-12-05 00:31:59.255135",
2025-12-05 00:31:59.873179 | controller |   "msg": "non-zero return code",
2025-12-05 00:31:59.873233 | controller |   "rc": 1,
2025-12-05 00:31:59.873271 | controller |   "start": "2025-12-05 00:31:54.116664"
2025-12-05 00:31:59.873307 | controller | }
failure
2025-12-05 00:31:59.875766 | 
2025-12-05 00:31:59.875863 | PLAY RECAP
2025-12-05 00:31:59.875973 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-05 00:31:59.876022 | 
2025-12-05 00:32:00.005770 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-05 00:32:00.008061 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 00:32:00.629854 | 
2025-12-05 00:32:00.629962 | PLAY [all]
2025-12-05 00:32:00.651539 | 
2025-12-05 00:32:00.651627 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-05 00:32:02.561149 | controller | changed: non-zero return code
2025-12-05 00:32:02.574213 | 
2025-12-05 00:32:02.574373 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-05 00:32:02.602380 | controller | skipping: Conditional result was False
2025-12-05 00:32:02.618152 | 
2025-12-05 00:32:02.618320 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-05 00:32:02.663868 | 
2025-12-05 00:32:02.664137 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-05 00:32:02.708541 | 
2025-12-05 00:32:02.708940 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-05 00:32:02.737240 | controller | skipping: Conditional result was False
2025-12-05 00:32:02.751230 | 
2025-12-05 00:32:02.751377 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-05 00:32:02.791909 | 
2025-12-05 00:32:02.792175 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-05 00:32:02.819319 | controller | skipping: Conditional result was False
2025-12-05 00:32:02.833493 | 
2025-12-05 00:32:02.833722 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-05 00:32:02.862516 | controller | skipping: Conditional result was False
2025-12-05 00:32:02.878310 | 
2025-12-05 00:32:02.878489 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-05 00:32:02.906698 | controller | skipping: Conditional result was False
2025-12-05 00:32:02.959847 | 
2025-12-05 00:32:02.959956 | PLAY RECAP
2025-12-05 00:32:02.960018 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-05 00:32:02.960049 | 
2025-12-05 00:32:03.058241 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-05 00:32:03.059132 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-05 00:32:03.618295 | 
2025-12-05 00:32:03.618401 | PLAY [all:!appliance*]
2025-12-05 00:32:03.639707 | 
2025-12-05 00:32:03.639805 | TASK [unregister the node]
2025-12-05 00:32:03.991813 | controller | skipping: Conditional result was False
2025-12-05 00:32:04.005020 | 
2025-12-05 00:32:04.005216 | TASK [include_role : fetch-output]
2025-12-05 00:32:04.041546 | controller | ok
2025-12-05 00:32:04.071808 | 
2025-12-05 00:32:04.071971 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 00:32:04.148721 | controller | skipping: Conditional result was False
2025-12-05 00:32:04.159623 | 
2025-12-05 00:32:04.159785 | TASK [fetch-output : Set log path for single node]
2025-12-05 00:32:04.203451 | controller | ok
2025-12-05 00:32:04.212057 | 
2025-12-05 00:32:04.212157 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 00:32:04.653661 | controller -> localhost | ok: "/var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/logs"
2025-12-05 00:32:04.955354 | controller -> localhost | changed: "/var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/artifacts"
2025-12-05 00:32:05.221297 | controller -> localhost | changed: "/var/lib/zuul/builds/5426493c40a842d0a8ab53d4359f6816/work/docs"
2025-12-05 00:32:05.246418 | 
2025-12-05 00:32:05.246596 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 00:32:07.505816 | controller | changed:
2025-12-05 00:32:07.506008 | controller | .d..t...... ./
2025-12-05 00:32:07.506037 | controller | cd+++++++++ controller/
2025-12-05 00:32:07.506070 | controller | changed: All items complete
2025-12-05 00:32:07.506091 | 
2025-12-05 00:32:09.539194 | controller | changed: .d..t...... ./
2025-12-05 00:32:11.667551 | controller | changed: .d..t...... ./
2025-12-05 00:32:11.699464 | 
2025-12-05 00:32:11.699662 | TASK [include_role : fetch-output-openshift]
2025-12-05 00:32:11.726549 | controller | skipping: Conditional result was False
2025-12-05 00:32:11.742109 | 
2025-12-05 00:32:11.742262 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-05 00:32:11.790752 | controller | skipping: Conditional result was False
2025-12-05 00:32:11.802108 | controller | skipping: Conditional result was False
2025-12-05 00:32:11.868824 | 
2025-12-05 00:32:11.868958 | PLAY [localhost]
2025-12-05 00:32:11.887683 | 
2025-12-05 00:32:11.887798 | TASK [Run Zuul manifest role]
2025-12-05 00:32:11.908834 | localhost | ok
2025-12-05 00:32:11.927332 | 
2025-12-05 00:32:11.927457 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-05 00:32:12.318317 | localhost | changed
2025-12-05 00:32:12.328644 | 
2025-12-05 00:32:12.328807 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-05 00:32:12.364936 | localhost | ok
2025-12-05 00:32:12.384366 | 
2025-12-05 00:32:12.384538 | TASK [Set zuul-log-path fact]
2025-12-05 00:32:12.438426 | localhost | ok
2025-12-05 00:32:12.454944 | 
2025-12-05 00:32:12.455067 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 00:32:12.493461 | localhost | ok
2025-12-05 00:32:12.501344 | 
2025-12-05 00:32:12.501402 | LOOP [Run upload-logs-swift role]
2025-12-05 00:32:12.547647 | localhost | Output suppressed because no_log was given
2025-12-05 00:32:12.591921 | 
2025-12-05 00:32:12.592016 | TASK [Set zuul-log-path fact]
2025-12-05 00:32:12.628142 | localhost | skipping: Conditional result was False
2025-12-05 00:32:12.639259 | 
2025-12-05 00:32:12.639404 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-05 00:32:13.074589 | localhost -> localhost | ok: Runtime: 0:00:00.007799
2025-12-05 00:32:13.086286 | 
2025-12-05 00:32:13.086427 | TASK [upload-logs-swift : Upload logs to swift]