2026-01-31 00:06:49.049266 | Job console starting...
2026-01-31 00:06:49.057741 | Updating repositories
2026-01-31 00:06:51.860971 | Preparing job workspace
2026-01-31 00:06:56.128819 | Running Ansible setup...
2026-01-31 00:07:01.132181 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-31 00:07:01.819699 | 
2026-01-31 00:07:01.820050 | PLAY [localhost]
2026-01-31 00:07:01.835536 | 
2026-01-31 00:07:01.835785 | TASK [Gathering Facts]
2026-01-31 00:07:02.822175 | localhost | ok
2026-01-31 00:07:02.837659 | 
2026-01-31 00:07:02.837802 | TASK [Setup log path fact]
2026-01-31 00:07:02.856409 | localhost | ok
2026-01-31 00:07:02.871124 | 
2026-01-31 00:07:02.871245 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-31 00:07:02.899590 | localhost | ok
2026-01-31 00:07:02.908973 | 
2026-01-31 00:07:02.909085 | TASK [emit-job-header : Print job information]
2026-01-31 00:07:02.939570 | # Job Information
2026-01-31 00:07:02.939802 | Ansible Version: 2.15.12
2026-01-31 00:07:02.939847 | Job: ansible-test-sanity-docker-devel
2026-01-31 00:07:02.939878 | Pipeline: periodic
2026-01-31 00:07:02.939906 | Executor: ze04.softwarefactory-project.io
2026-01-31 00:07:02.939933 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-31 00:07:02.939964 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/284/ansible/284b5e72e0ba48129285b68bd3fcc5f3/
2026-01-31 00:07:02.939992 | Event ID: d2ac577d17c84cbe949600e8ba7c97bc
2026-01-31 00:07:02.945479 | 
2026-01-31 00:07:02.945566 | LOOP [emit-job-header : Print node information]
2026-01-31 00:07:03.054488 | localhost | ok:
2026-01-31 00:07:03.054805 | localhost | # Node Information
2026-01-31 00:07:03.054876 | localhost | Inventory Hostname: controller
2026-01-31 00:07:03.054933 | localhost | Hostname: np0005603401
2026-01-31 00:07:03.054987 | localhost | Username: zuul
2026-01-31 00:07:03.055180 | localhost | Distro: Fedora 37
2026-01-31 00:07:03.055257 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-31 00:07:03.055328 | localhost | Region: ca-ymq-1
2026-01-31 00:07:03.055399 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-31 00:07:03.055454 | localhost | Product Name: OpenStack Nova
2026-01-31 00:07:03.055497 | localhost | Interface IP: 162.253.55.62
2026-01-31 00:07:03.073733 | 
2026-01-31 00:07:03.073872 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-31 00:07:03.456109 | localhost -> localhost | changed
2026-01-31 00:07:03.472414 | 
2026-01-31 00:07:03.472622 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-31 00:07:04.359829 | localhost -> localhost | changed
2026-01-31 00:07:04.382353 | 
2026-01-31 00:07:04.382462 | PLAY [all:!appliance*]
2026-01-31 00:07:04.412766 | 
2026-01-31 00:07:04.412922 | TASK [include_role : start-zuul-console]
2026-01-31 00:07:04.433557 | controller | ok
2026-01-31 00:07:04.448172 | 
2026-01-31 00:07:04.448281 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-31 00:07:04.828312 | controller | ok
2026-01-31 00:07:04.844879 | 
2026-01-31 00:07:04.845026 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-31 00:07:05.829279 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-31 00:07:05.836274 | 
2026-01-31 00:07:05.836414 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-31 00:07:06.370590 | controller | skipping: Conditional result was False
2026-01-31 00:07:06.379306 | 
2026-01-31 00:07:06.379395 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-31 00:07:06.405176 | controller | skipping: Conditional result was False
2026-01-31 00:07:06.413175 | 
2026-01-31 00:07:06.413295 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-31 00:07:06.447324 | controller | skipping: Conditional result was False
2026-01-31 00:07:06.457652 | 
2026-01-31 00:07:06.457819 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-31 00:07:06.483096 | controller | skipping: Conditional result was False
2026-01-31 00:07:06.492288 | 
2026-01-31 00:07:06.492398 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-31 00:07:06.516403 | controller | skipping: Conditional result was False
2026-01-31 00:07:06.526056 | 
2026-01-31 00:07:06.526175 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-31 00:07:06.551301 | controller | skipping: Conditional result was False
2026-01-31 00:07:06.570285 | 
2026-01-31 00:07:06.570421 | TASK [Disable Fedora Modular]
2026-01-31 00:07:06.819056 | controller | changed
2026-01-31 00:07:06.827723 | 
2026-01-31 00:07:06.827860 | TASK [Enable EPEL]
2026-01-31 00:07:06.853182 | controller | skipping: Conditional result was False
2026-01-31 00:07:06.861838 | 
2026-01-31 00:07:06.861934 | TASK [Register the RHEL node]
2026-01-31 00:07:07.409481 | 
2026-01-31 00:07:07.409643 | TASK [Show the subscription-manager status]
2026-01-31 00:07:07.974190 | controller | skipping: Conditional result was False
2026-01-31 00:07:07.983835 | 
2026-01-31 00:07:07.983957 | TASK [Enable EPEL on RHEL]
2026-01-31 00:07:08.519926 | controller | skipping: Conditional result was False
2026-01-31 00:07:08.528671 | 
2026-01-31 00:07:08.528793 | TASK [Install git and tox]
2026-01-31 00:08:34.671782 | controller | changed
2026-01-31 00:08:34.685417 | 
2026-01-31 00:08:34.685619 | TASK [include_role : prepare-workspace]
2026-01-31 00:08:34.728475 | controller | ok
2026-01-31 00:08:34.751214 | 
2026-01-31 00:08:34.751334 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-31 00:08:34.977594 | controller | ok
2026-01-31 00:08:34.987760 | 
2026-01-31 00:08:34.987892 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-31 00:08:47.787089 | controller | Output suppressed because no_log was given
2026-01-31 00:08:47.829777 | 
2026-01-31 00:08:47.829907 | TASK [include_role : prepare-workspace-openshift]
2026-01-31 00:08:47.857112 | controller | skipping: Conditional result was False
2026-01-31 00:08:47.891086 | 
2026-01-31 00:08:47.891166 | PLAY [all:!appliance]
2026-01-31 00:08:47.912498 | 
2026-01-31 00:08:47.912594 | TASK [Run add-build-sshkey role (RSA)]
2026-01-31 00:08:47.936985 | controller | ok
2026-01-31 00:08:47.957778 | 
2026-01-31 00:08:47.957894 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-31 00:08:48.237280 | controller -> localhost | ok
2026-01-31 00:08:48.247583 | 
2026-01-31 00:08:48.247728 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-31 00:08:48.276652 | controller | ok
2026-01-31 00:08:48.297259 | controller | included: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-31 00:08:48.306713 | 
2026-01-31 00:08:48.306868 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-31 00:08:48.792348 | controller -> localhost | Generating public/private rsa key pair.
2026-01-31 00:08:48.792635 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/284b5e72e0ba48129285b68bd3fcc5f3_id_rsa.
2026-01-31 00:08:48.792701 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/284b5e72e0ba48129285b68bd3fcc5f3_id_rsa.pub.
2026-01-31 00:08:48.792743 | controller -> localhost | The key fingerprint is:
2026-01-31 00:08:48.792775 | controller -> localhost | SHA256:x7z86Uu/G5hP+YocL3Ukl29cN8VYEg153OvDS5fx57Y zuul-build-sshkey
2026-01-31 00:08:48.792806 | controller -> localhost | The key's randomart image is:
2026-01-31 00:08:48.792836 | controller -> localhost | +---[RSA 2048]----+
2026-01-31 00:08:48.792866 | controller -> localhost | |              +Xo|
2026-01-31 00:08:48.792897 | controller -> localhost | |              o.B|
2026-01-31 00:08:48.792925 | controller -> localhost | |               .+|
2026-01-31 00:08:48.792953 | controller -> localhost | |         o    .==|
2026-01-31 00:08:48.792983 | controller -> localhost | |        S +   o=O|
2026-01-31 00:08:48.793024 | controller -> localhost | |         o . o.BO|
2026-01-31 00:08:48.793062 | controller -> localhost | |          o =.=+=|
2026-01-31 00:08:48.793096 | controller -> localhost | |           +.O +o|
2026-01-31 00:08:48.793138 | controller -> localhost | |           .BoBEo|
2026-01-31 00:08:48.793180 | controller -> localhost | +----[SHA256]-----+
2026-01-31 00:08:48.793247 | controller -> localhost | ok: Runtime: 0:00:00.056214
2026-01-31 00:08:48.804217 | 
2026-01-31 00:08:48.804336 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-31 00:08:48.840059 | controller | ok
2026-01-31 00:08:48.855669 | controller | included: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-31 00:08:48.869240 | 
2026-01-31 00:08:48.869374 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-31 00:08:48.895011 | controller | skipping: Conditional result was False
2026-01-31 00:08:48.904991 | 
2026-01-31 00:08:48.905135 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-31 00:13:49.073044 | controller | changed
2026-01-31 00:13:49.080918 | 
2026-01-31 00:13:49.081040 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-31 00:13:49.307153 | controller | ok
2026-01-31 00:13:49.314496 | 
2026-01-31 00:13:49.314575 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-31 00:13:49.905664 | controller | changed
2026-01-31 00:13:49.914572 | 
2026-01-31 00:13:49.914774 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-31 00:13:50.528220 | controller | changed
2026-01-31 00:13:50.534947 | 
2026-01-31 00:13:50.535022 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-31 00:13:50.550525 | controller | skipping: Conditional result was False
2026-01-31 00:13:50.560448 | 
2026-01-31 00:13:50.560544 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-31 00:13:50.955105 | controller -> localhost | changed
2026-01-31 00:13:50.972249 | 
2026-01-31 00:13:50.972345 | TASK [add-build-sshkey : Add back temp key]
2026-01-31 00:13:51.263104 | controller -> localhost | Identity added: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/284b5e72e0ba48129285b68bd3fcc5f3_id_rsa (zuul-build-sshkey)
2026-01-31 00:13:51.263393 | controller -> localhost | ok: Runtime: 0:00:00.008301
2026-01-31 00:13:51.271211 | 
2026-01-31 00:13:51.271278 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-31 00:13:51.664960 | controller | ok
2026-01-31 00:13:51.681612 | 
2026-01-31 00:13:51.681809 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-31 00:13:51.716975 | controller | skipping: Conditional result was False
2026-01-31 00:13:51.734284 | 
2026-01-31 00:13:51.734416 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-31 00:13:51.768147 | controller | ok
2026-01-31 00:13:51.793973 | 
2026-01-31 00:13:51.794101 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-31 00:13:52.063147 | controller -> localhost | ok
2026-01-31 00:13:52.091131 | 
2026-01-31 00:13:52.091387 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-31 00:13:52.135300 | controller | ok
2026-01-31 00:13:52.160931 | controller | included: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-31 00:13:52.172567 | 
2026-01-31 00:13:52.172904 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-31 00:13:52.490073 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-31 00:13:52.490211 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/284b5e72e0ba48129285b68bd3fcc5f3_id_ecdsa.
2026-01-31 00:13:52.490237 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/284b5e72e0ba48129285b68bd3fcc5f3_id_ecdsa.pub.
2026-01-31 00:13:52.490266 | controller -> localhost | The key fingerprint is:
2026-01-31 00:13:52.490285 | controller -> localhost | SHA256:QR8K4i8Lj8bwp8Jrez8N6pC0yUAVe+gZHnsQV66X1ho zuul-build-sshkey
2026-01-31 00:13:52.490303 | controller -> localhost | The key's randomart image is:
2026-01-31 00:13:52.490321 | controller -> localhost | +---[ECDSA 521]---+
2026-01-31 00:13:52.490338 | controller -> localhost | |   +o.o.. .      |
2026-01-31 00:13:52.490355 | controller -> localhost | |  ..=..o o .     |
2026-01-31 00:13:52.490371 | controller -> localhost | | . *.. .o .      |
2026-01-31 00:13:52.490388 | controller -> localhost | |. o B.. o.       |
2026-01-31 00:13:52.490405 | controller -> localhost | |o..=.o.ES.       |
2026-01-31 00:13:52.490421 | controller -> localhost | |++++.+o o        |
2026-01-31 00:13:52.490438 | controller -> localhost | |.*= = o.         |
2026-01-31 00:13:52.490455 | controller -> localhost | |.+.= . .         |
2026-01-31 00:13:52.490471 | controller -> localhost | |.+*....          |
2026-01-31 00:13:52.490488 | controller -> localhost | +----[SHA256]-----+
2026-01-31 00:13:52.490526 | controller -> localhost | ok: Runtime: 0:00:00.007670
2026-01-31 00:13:52.496385 | 
2026-01-31 00:13:52.496446 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-31 00:13:52.526529 | controller | ok
2026-01-31 00:13:52.534331 | controller | included: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-31 00:13:52.543008 | 
2026-01-31 00:13:52.543086 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-31 00:13:52.558061 | controller | skipping: Conditional result was False
2026-01-31 00:13:52.570232 | 
2026-01-31 00:13:52.570372 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-31 00:13:52.839049 | controller | changed
2026-01-31 00:13:52.847769 | 
2026-01-31 00:13:52.847872 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-31 00:13:53.057801 | controller | ok
2026-01-31 00:13:53.069501 | 
2026-01-31 00:13:53.069638 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-31 00:13:53.672857 | controller | changed
2026-01-31 00:13:53.678761 | 
2026-01-31 00:13:53.678835 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-31 00:13:54.277850 | controller | changed
2026-01-31 00:13:54.284428 | 
2026-01-31 00:13:54.284527 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-31 00:13:54.308928 | controller | skipping: Conditional result was False
2026-01-31 00:13:54.316444 | 
2026-01-31 00:13:54.316546 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-31 00:13:54.565891 | controller -> localhost | changed
2026-01-31 00:13:54.582951 | 
2026-01-31 00:13:54.583063 | TASK [add-build-sshkey : Add back temp key]
2026-01-31 00:13:54.863915 | controller -> localhost | Identity added: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/284b5e72e0ba48129285b68bd3fcc5f3_id_ecdsa (zuul-build-sshkey)
2026-01-31 00:13:54.864312 | controller -> localhost | ok: Runtime: 0:00:00.008482
2026-01-31 00:13:54.875270 | 
2026-01-31 00:13:54.875435 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-31 00:13:55.094772 | controller | ok
2026-01-31 00:13:55.100852 | 
2026-01-31 00:13:55.100947 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-31 00:13:55.126114 | controller | skipping: Conditional result was False
2026-01-31 00:13:55.146721 | 
2026-01-31 00:13:55.146890 | TASK [include_role : remove-zuul-sshkey]
2026-01-31 00:13:55.163882 | controller | skipping: Conditional result was False
2026-01-31 00:13:55.174061 | 
2026-01-31 00:13:55.174164 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-31 00:13:55.412031 | controller | ok: "logs"
2026-01-31 00:13:55.412498 | controller | ok: All items complete
2026-01-31 00:13:55.412543 | 
2026-01-31 00:13:55.608708 | controller | ok: "artifacts"
2026-01-31 00:13:55.794173 | controller | ok: "docs"
2026-01-31 00:13:55.805154 | 
2026-01-31 00:13:55.805271 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-31 00:13:56.023783 | controller | changed: "logs"
2026-01-31 00:13:56.216906 | controller | changed: "artifacts"
2026-01-31 00:13:56.408051 | controller | changed: "docs"
2026-01-31 00:13:56.486428 | 
2026-01-31 00:13:56.486559 | PLAY RECAP
2026-01-31 00:13:56.486614 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-31 00:13:56.486645 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-31 00:13:56.486666 | 
2026-01-31 00:13:56.654324 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-31 00:13:56.656142 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-31 00:13:57.341713 | 
2026-01-31 00:13:57.341899 | PLAY [all]
2026-01-31 00:13:57.381310 | 
2026-01-31 00:13:57.381492 | TASK [Install binary dependencies]
2026-01-31 00:13:57.446767 | controller | ok
2026-01-31 00:13:57.475376 | 
2026-01-31 00:13:57.475571 | TASK [bindep : Include find tasks]
2026-01-31 00:13:57.510196 | controller | ok
2026-01-31 00:13:57.522777 | controller | included: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-31 00:13:57.532003 | 
2026-01-31 00:13:57.532162 | TASK [bindep : Look for bindep.txt]
2026-01-31 00:13:58.101092 | controller | ok
2026-01-31 00:13:58.119031 | 
2026-01-31 00:13:58.119185 | TASK [bindep : Define bindep_file fact]
2026-01-31 00:13:58.144576 | controller | skipping: Conditional result was False
2026-01-31 00:13:58.152850 | 
2026-01-31 00:13:58.152935 | TASK [bindep : Look for other-requirements.txt]
2026-01-31 00:13:58.359754 | controller | ok
2026-01-31 00:13:58.367187 | 
2026-01-31 00:13:58.367266 | TASK [bindep : Define bindep_file fact]
2026-01-31 00:13:58.391812 | controller | skipping: Conditional result was False
2026-01-31 00:13:58.400072 | 
2026-01-31 00:13:58.400152 | TASK [bindep : Look for bindep fallback file]
2026-01-31 00:13:58.444924 | controller | skipping: Conditional result was False
2026-01-31 00:13:58.453154 | 
2026-01-31 00:13:58.453305 | TASK [bindep : Define bindep_file fact]
2026-01-31 00:13:58.477332 | controller | skipping: Conditional result was False
2026-01-31 00:13:58.484452 | 
2026-01-31 00:13:58.484546 | TASK [bindep : Include bindep tasks]
2026-01-31 00:13:58.518484 | controller | skipping: Conditional result was False
2026-01-31 00:13:58.525641 | 
2026-01-31 00:13:58.525757 | TASK [bindep : Include install tasks]
2026-01-31 00:13:58.560081 | controller | skipping: Conditional result was False
2026-01-31 00:13:58.566972 | 
2026-01-31 00:13:58.567051 | LOOP [bindep : Include package tasks]
2026-01-31 00:13:58.646029 | 
2026-01-31 00:13:58.646248 | TASK [Run test-setup role]
2026-01-31 00:13:58.670646 | controller | ok
2026-01-31 00:13:58.692057 | 
2026-01-31 00:13:58.692187 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-31 00:13:58.937750 | controller | ok
2026-01-31 00:13:58.946276 | 
2026-01-31 00:13:58.946375 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-31 00:13:59.487163 | controller | skipping: Conditional result was False
2026-01-31 00:13:59.524135 | 
2026-01-31 00:13:59.524328 | PLAY RECAP
2026-01-31 00:13:59.524387 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-31 00:13:59.524416 | 
2026-01-31 00:13:59.665480 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-31 00:13:59.666664 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-31 00:14:00.328787 | 
2026-01-31 00:14:00.328954 | PLAY [controller]
2026-01-31 00:14:00.357581 | 
2026-01-31 00:14:00.357754 | TASK [Create the /root directory]
2026-01-31 00:14:00.889097 | controller | ok
2026-01-31 00:14:00.899878 | 
2026-01-31 00:14:00.900132 | TASK [Install glibc-langpack-en]
2026-01-31 00:14:04.716882 | controller | ok: Nothing to do
2026-01-31 00:14:04.732407 | 
2026-01-31 00:14:04.732723 | TASK [Ensure controller directory exists]
2026-01-31 00:14:04.943596 | controller | changed
2026-01-31 00:14:04.950059 | 
2026-01-31 00:14:04.950135 | TASK [Install container runtime]
2026-01-31 00:14:05.022219 | controller | ok
2026-01-31 00:14:05.086443 | 
2026-01-31 00:14:05.086802 | LOOP [ensure-podman : Find distribution installation]
2026-01-31 00:14:05.129279 | controller | ok: "/var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-31 00:14:05.147701 | controller | included: /var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-31 00:14:05.154844 | 
2026-01-31 00:14:05.154926 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-31 00:15:09.997195 | controller | changed
2026-01-31 00:15:10.009006 | 
2026-01-31 00:15:10.009147 | TASK [ensure-podman : Fetch podman version]
2026-01-31 00:15:10.552539 | controller | Client:       Podman Engine
2026-01-31 00:15:10.583005 | controller | Version:      4.6.2
2026-01-31 00:15:10.583048 | controller | API Version:  4.6.2
2026-01-31 00:15:10.583061 | controller | Go Version:   go1.19.12
2026-01-31 00:15:10.583085 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-31 00:15:10.583099 | controller | OS/Arch:      linux/amd64
2026-01-31 00:15:11.061121 | controller | ok: Runtime: 0:00:00.182721
2026-01-31 00:15:11.067943 | 
2026-01-31 00:15:11.068030 | TASK [ensure-podman : Print podman version installed]
2026-01-31 00:15:11.098127 | Podman version: Client:       Podman Engine
2026-01-31 00:15:11.098286 | Version:      4.6.2
2026-01-31 00:15:11.098321 | API Version:  4.6.2
2026-01-31 00:15:11.098349 | Go Version:   go1.19.12
2026-01-31 00:15:11.098373 | Built:        Mon Aug 28 19:38:31 2023
2026-01-31 00:15:11.098401 | OS/Arch:      linux/amd64
2026-01-31 00:15:11.104751 | 
2026-01-31 00:15:11.104822 | TASK [ensure-podman : Validate podman engine]
2026-01-31 00:15:11.637297 | controller | skipping: Conditional result was False
2026-01-31 00:15:11.653194 | 
2026-01-31 00:15:11.653348 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-31 00:15:11.680118 | controller | skipping: Conditional result was False
2026-01-31 00:15:11.710159 | 
2026-01-31 00:15:11.710330 | TASK [Ensure python3.8 is present]
2026-01-31 00:15:11.725884 | controller | skipping: Conditional result was False
2026-01-31 00:15:11.734587 | 
2026-01-31 00:15:11.734730 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-31 00:15:11.759309 | controller | ok
2026-01-31 00:15:11.865533 | 
2026-01-31 00:15:11.865897 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-31 00:15:13.428602 | controller | ok: Nothing to do
2026-01-31 00:15:13.438216 | 
2026-01-31 00:15:13.438362 | TASK [our-ensure-python : Also install python3-devel]
2026-01-31 00:15:22.499277 | controller | changed
2026-01-31 00:15:22.512009 | 
2026-01-31 00:15:22.512115 | TASK [Run ensure-virtualenv role]
2026-01-31 00:15:22.542403 | controller | ok
2026-01-31 00:15:22.570006 | 
2026-01-31 00:15:22.570290 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-31 00:15:23.003679 | controller | /usr/bin/virtualenv
2026-01-31 00:15:23.107046 | controller | ok: Runtime: 0:00:00.003343
2026-01-31 00:15:23.122268 | 
2026-01-31 00:15:23.122437 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-31 00:15:23.162546 | controller | skipping: Conditional result was False
2026-01-31 00:15:23.163001 | controller | ok: All items complete
2026-01-31 00:15:23.163049 | 
2026-01-31 00:15:23.196716 | 
2026-01-31 00:15:23.196929 | TASK [Find the full path of the Python interpreter]
2026-01-31 00:15:23.454847 | controller | /usr/bin/python3
2026-01-31 00:15:23.780365 | controller | ok
2026-01-31 00:15:23.787509 | 
2026-01-31 00:15:23.787639 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-31 00:15:24.654144 | controller | created virtual environment CPython3.11.0.final.0-64 in 508ms
2026-01-31 00:15:24.670852 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-31 00:15:24.670889 | 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-31 00:15:24.670899 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-31 00:15:24.670913 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-31 00:15:24.833767 | controller | changed
2026-01-31 00:15:24.842076 | 
2026-01-31 00:15:24.842165 | TASK [Set selinux package]
2026-01-31 00:15:24.864895 | controller | ok
2026-01-31 00:15:24.871761 | 
2026-01-31 00:15:24.871867 | TASK [Set selinux package (Fedora)]
2026-01-31 00:15:24.904926 | controller | ok
2026-01-31 00:15:24.911845 | 
2026-01-31 00:15:24.911932 | TASK [Install selinux into virtualenv]
2026-01-31 00:15:26.186182 | controller | Collecting selinux-please-lie-to-me
2026-01-31 00:15:26.226374 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-31 00:15:26.532437 | controller | Collecting setuptools<50.0.0
2026-01-31 00:15:26.545032 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-31 00:15:26.581163 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.8 MB/s eta 0:00:00
2026-01-31 00:15:26.665010 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-31 00:15:26.665228 | controller |   Attempting uninstall: setuptools
2026-01-31 00:15:26.667742 | controller |     Found existing installation: setuptools 62.6.0
2026-01-31 00:15:26.730294 | controller |     Uninstalling setuptools-62.6.0:
2026-01-31 00:15:26.738433 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-31 00:15:27.102386 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-31 00:15:27.231347 | controller |
2026-01-31 00:15:27.322199 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-31 00:15:27.322239 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-31 00:15:27.461650 | controller | ok: Runtime: 0:00:02.183788
2026-01-31 00:15:27.476153 | 
2026-01-31 00:15:27.476306 | TASK [Install pytest-forked into virtualenv]
2026-01-31 00:15:28.088817 | controller | Collecting pytest-forked
2026-01-31 00:15:28.122804 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-31 00:15:28.163168 | controller | Collecting py
2026-01-31 00:15:28.166510 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-31 00:15:28.184716 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.5 MB/s eta 0:00:00
2026-01-31 00:15:28.295315 | controller | Collecting pytest>=3.10
2026-01-31 00:15:28.299256 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-31 00:15:28.316997 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 24.6 MB/s eta 0:00:00
2026-01-31 00:15:28.355890 | controller | Collecting iniconfig>=1.0.1
2026-01-31 00:15:28.359169 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-31 00:15:28.405257 | controller | Collecting packaging>=22
2026-01-31 00:15:28.408392 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-01-31 00:15:28.415887 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 12.6 MB/s eta 0:00:00
2026-01-31 00:15:28.485910 | controller | Collecting pluggy<2,>=1.5
2026-01-31 00:15:28.489111 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-31 00:15:28.532853 | controller | Collecting pygments>=2.7.2
2026-01-31 00:15:28.536010 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-31 00:15:28.556945 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 66.1 MB/s eta 0:00:00
2026-01-31 00:15:28.624804 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-31 00:15:29.722495 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-01-31 00:15:29.731137 | controller |
2026-01-31 00:15:29.800126 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-31 00:15:29.800169 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-31 00:15:30.046268 | controller | ok: Runtime: 0:00:02.076346
2026-01-31 00:15:30.052672 | 
2026-01-31 00:15:30.052774 | TASK [Update pip]
2026-01-31 00:15:30.545981 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-31 00:15:30.677134 | controller | Collecting pip
2026-01-31 00:15:30.710226 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-31 00:15:30.763361 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.7 MB/s eta 0:00:00
2026-01-31 00:15:30.831012 | controller | Installing collected packages: pip
2026-01-31 00:15:30.831229 | controller |   Attempting uninstall: pip
2026-01-31 00:15:30.833356 | controller |     Found existing installation: pip 22.2.2
2026-01-31 00:15:30.971597 | controller |     Uninstalling pip-22.2.2:
2026-01-31 00:15:30.986678 | controller |       Successfully uninstalled pip-22.2.2
2026-01-31 00:15:31.792815 | controller | Successfully installed pip-25.3
2026-01-31 00:15:32.093070 | controller | ok: Runtime: 0:00:01.612451
2026-01-31 00:15:32.100454 | 
2026-01-31 00:15:32.100558 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-31 00:15:32.315849 | controller | changed
2026-01-31 00:15:32.324813 | 
2026-01-31 00:15:32.324968 | TASK [Install ansible into virtualenv]
2026-01-31 00:15:32.819584 | controller | Processing ./src/github.com/ansible/ansible
2026-01-31 00:15:32.822882 | controller |   Installing build dependencies: started
2026-01-31 00:15:33.681803 | controller |   Installing build dependencies: finished with status 'done'
2026-01-31 00:15:33.682671 | controller |   Getting requirements to build wheel: started
2026-01-31 00:15:34.415159 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-31 00:15:34.873773 | controller |   Preparing metadata (pyproject.toml): started
2026-01-31 00:15:34.873809 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-31 00:15:34.874450 | 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-31 00:15:34.877047 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-31 00:15:35.370704 | controller | ERROR
2026-01-31 00:15:35.370912 | controller | {
2026-01-31 00:15:35.370947 | controller |   "delta": "0:00:02.400676",
2026-01-31 00:15:35.370974 | controller |   "end": "2026-01-31 00:15:34.935286",
2026-01-31 00:15:35.370998 | controller |   "msg": "non-zero return code",
2026-01-31 00:15:35.371033 | controller |   "rc": 1,
2026-01-31 00:15:35.371053 | controller |   "start": "2026-01-31 00:15:32.534610"
2026-01-31 00:15:35.371070 | controller | }
failure
2026-01-31 00:15:35.372529 | 
2026-01-31 00:15:35.372586 | PLAY RECAP
2026-01-31 00:15:35.372633 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-31 00:15:35.372660 | 
2026-01-31 00:15:35.498933 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-31 00:15:35.500206 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-31 00:15:36.133713 | 
2026-01-31 00:15:36.133879 | PLAY [all]
2026-01-31 00:15:36.215708 | 
2026-01-31 00:15:36.215872 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-31 00:15:36.595027 | controller | changed: non-zero return code
2026-01-31 00:15:36.601312 | 
2026-01-31 00:15:36.601391 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-31 00:15:36.625956 | controller | skipping: Conditional result was False
2026-01-31 00:15:36.632541 | 
2026-01-31 00:15:36.632619 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-31 00:15:36.664106 | 
2026-01-31 00:15:36.664259 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-31 00:15:36.695753 | 
2026-01-31 00:15:36.695925 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-31 00:15:36.721453 | controller | skipping: Conditional result was False
2026-01-31 00:15:36.732392 | 
2026-01-31 00:15:36.732512 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-31 00:15:36.766661 | 
2026-01-31 00:15:36.766877 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-31 00:15:36.792840 | controller | skipping: Conditional result was False
2026-01-31 00:15:36.801791 | 
2026-01-31 00:15:36.801919 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-31 00:15:36.827307 | controller | skipping: Conditional result was False
2026-01-31 00:15:36.838204 | 
2026-01-31 00:15:36.838328 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-31 00:15:36.864149 | controller | skipping: Conditional result was False
2026-01-31 00:15:36.904773 | 
2026-01-31 00:15:36.904900 | PLAY RECAP
2026-01-31 00:15:36.904956 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-31 00:15:36.904985 | 
2026-01-31 00:15:37.021858 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-31 00:15:37.023011 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-31 00:15:37.751811 | 
2026-01-31 00:15:37.752064 | PLAY [all:!appliance*]
2026-01-31 00:15:37.776175 | 
2026-01-31 00:15:37.776352 | TASK [unregister the node]
2026-01-31 00:15:38.315991 | controller | skipping: Conditional result was False
2026-01-31 00:15:38.323515 | 
2026-01-31 00:15:38.323669 | TASK [include_role : fetch-output]
2026-01-31 00:15:38.354961 | controller | ok
2026-01-31 00:15:38.377114 | 
2026-01-31 00:15:38.377241 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-31 00:15:38.422160 | controller | skipping: Conditional result was False
2026-01-31 00:15:38.431300 | 
2026-01-31 00:15:38.431431 | TASK [fetch-output : Set log path for single node]
2026-01-31 00:15:38.462254 | controller | ok
2026-01-31 00:15:38.467807 | 
2026-01-31 00:15:38.467884 | LOOP [fetch-output : Ensure local output dirs]
2026-01-31 00:15:38.864633 | controller -> localhost | ok: "/var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/logs"
2026-01-31 00:15:39.082493 | controller -> localhost | changed: "/var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/artifacts"
2026-01-31 00:15:39.312515 | controller -> localhost | changed: "/var/lib/zuul/builds/284b5e72e0ba48129285b68bd3fcc5f3/work/docs"
2026-01-31 00:15:39.338873 | 
2026-01-31 00:15:39.339110 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-31 00:15:39.987397 | controller | changed:
2026-01-31 00:15:39.987610 | controller | .d..t...... ./
2026-01-31 00:15:39.987654 | controller | cd+++++++++ controller/
2026-01-31 00:15:39.987748 | controller | changed: All items complete
2026-01-31 00:15:39.987786 | 
2026-01-31 00:15:40.484636 | controller | changed: .d..t...... ./
2026-01-31 00:15:40.982922 | controller | changed: .d..t...... ./
2026-01-31 00:15:41.007171 | 
2026-01-31 00:15:41.007328 | TASK [include_role : fetch-output-openshift]
2026-01-31 00:15:41.023599 | controller | skipping: Conditional result was False
2026-01-31 00:15:41.034276 | 
2026-01-31 00:15:41.034437 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-31 00:15:41.063999 | controller | skipping: Conditional result was False
2026-01-31 00:15:41.072379 | controller | skipping: Conditional result was False
2026-01-31 00:15:41.119749 | 
2026-01-31 00:15:41.119858 | PLAY [localhost]
2026-01-31 00:15:41.133716 | 
2026-01-31 00:15:41.133854 | TASK [Run Zuul manifest role]
2026-01-31 00:15:41.153959 | localhost | ok
2026-01-31 00:15:41.171867 | 
2026-01-31 00:15:41.172010 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-31 00:15:41.581569 | localhost | changed
2026-01-31 00:15:41.589629 | 
2026-01-31 00:15:41.589794 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-31 00:15:41.622626 | localhost | ok
2026-01-31 00:15:41.638202 | 
2026-01-31 00:15:41.638369 | TASK [Set zuul-log-path fact]
2026-01-31 00:15:41.660486 | localhost | ok
2026-01-31 00:15:41.682714 | 
2026-01-31 00:15:41.682870 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-31 00:15:41.728240 | localhost | ok
2026-01-31 00:15:41.740714 | 
2026-01-31 00:15:41.740862 | LOOP [Run upload-logs-swift role]
2026-01-31 00:15:41.766670 | localhost | Output suppressed because no_log was given
2026-01-31 00:15:41.793655 | 
2026-01-31 00:15:41.793779 | TASK [Set zuul-log-path fact]
2026-01-31 00:15:41.817586 | localhost | skipping: Conditional result was False
2026-01-31 00:15:41.823104 | 
2026-01-31 00:15:41.823191 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-31 00:15:42.257725 | localhost -> localhost | ok: Runtime: 0:00:00.007405
2026-01-31 00:15:42.268977 | 
2026-01-31 00:15:42.269115 | TASK [upload-logs-swift : Upload logs to swift]