2026-01-26 00:14:14.891687 | Job console starting...
2026-01-26 00:14:14.905818 | Updating repositories
2026-01-26 00:14:15.014168 | Preparing job workspace
2026-01-26 00:14:19.968065 | Running Ansible setup...
2026-01-26 00:14:24.467436 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-26 00:14:25.079659 | 
2026-01-26 00:14:25.079804 | PLAY [localhost]
2026-01-26 00:14:25.088367 | 
2026-01-26 00:14:25.088453 | TASK [Gathering Facts]
2026-01-26 00:14:26.039580 | localhost | ok
2026-01-26 00:14:26.057541 | 
2026-01-26 00:14:26.057698 | TASK [Setup log path fact]
2026-01-26 00:14:26.075332 | localhost | ok
2026-01-26 00:14:26.088069 | 
2026-01-26 00:14:26.088159 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 00:14:26.125929 | localhost | ok
2026-01-26 00:14:26.134266 | 
2026-01-26 00:14:26.134366 | TASK [emit-job-header : Print job information]
2026-01-26 00:14:26.182525 | # Job Information
2026-01-26 00:14:26.182682 | Ansible Version: 2.15.12
2026-01-26 00:14:26.182714 | Job: ansible-test-sanity-docker-milestone
2026-01-26 00:14:26.182756 | Pipeline: periodic
2026-01-26 00:14:26.182777 | Executor: ze03.softwarefactory-project.io
2026-01-26 00:14:26.182795 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-26 00:14:26.182816 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/87b/ansible/87bca2e62b7d4ad99e7f7ad86cb2cd00/
2026-01-26 00:14:26.182836 | Event ID: 4b9b1c413fcf4b5b911f7b1cc126ee08
2026-01-26 00:14:26.186587 | 
2026-01-26 00:14:26.186648 | LOOP [emit-job-header : Print node information]
2026-01-26 00:14:26.299120 | localhost | ok:
2026-01-26 00:14:26.299497 | localhost | # Node Information
2026-01-26 00:14:26.299588 | localhost | Inventory Hostname: controller
2026-01-26 00:14:26.299641 | localhost | Hostname: np0005595221
2026-01-26 00:14:26.299686 | localhost | Username: zuul
2026-01-26 00:14:26.299772 | localhost | Distro: Fedora 37
2026-01-26 00:14:26.299828 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-26 00:14:26.299872 | localhost | Region: ca-ymq-1
2026-01-26 00:14:26.299911 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-26 00:14:26.299950 | localhost | Product Name: OpenStack Nova
2026-01-26 00:14:26.299989 | localhost | Interface IP: 162.253.55.250
2026-01-26 00:14:26.321225 | 
2026-01-26 00:14:26.321394 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-26 00:14:26.767124 | localhost -> localhost | changed
2026-01-26 00:14:26.773799 | 
2026-01-26 00:14:26.773886 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-26 00:14:27.684807 | localhost -> localhost | changed
2026-01-26 00:14:27.732111 | 
2026-01-26 00:14:27.732214 | PLAY [all:!appliance*]
2026-01-26 00:14:27.756229 | 
2026-01-26 00:14:27.756405 | TASK [include_role : start-zuul-console]
2026-01-26 00:14:27.778448 | controller | ok
2026-01-26 00:14:27.799284 | 
2026-01-26 00:14:27.799415 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-26 00:14:28.189318 | controller | ok
2026-01-26 00:14:28.201853 | 
2026-01-26 00:14:28.201979 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-26 00:14:29.193397 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-26 00:14:29.203612 | 
2026-01-26 00:14:29.203775 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-26 00:14:29.750369 | controller | skipping: Conditional result was False
2026-01-26 00:14:29.757493 | 
2026-01-26 00:14:29.757594 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-26 00:14:29.781913 | controller | skipping: Conditional result was False
2026-01-26 00:14:29.791644 | 
2026-01-26 00:14:29.791830 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-26 00:14:29.826388 | controller | skipping: Conditional result was False
2026-01-26 00:14:29.832566 | 
2026-01-26 00:14:29.832640 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-26 00:14:29.846835 | controller | skipping: Conditional result was False
2026-01-26 00:14:29.853569 | 
2026-01-26 00:14:29.853655 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-26 00:14:29.880370 | controller | skipping: Conditional result was False
2026-01-26 00:14:29.887105 | 
2026-01-26 00:14:29.887184 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-26 00:14:29.913155 | controller | skipping: Conditional result was False
2026-01-26 00:14:29.925848 | 
2026-01-26 00:14:29.925932 | TASK [Disable Fedora Modular]
2026-01-26 00:14:30.159503 | controller | changed
2026-01-26 00:14:30.167859 | 
2026-01-26 00:14:30.167987 | TASK [Enable EPEL]
2026-01-26 00:14:30.192131 | controller | skipping: Conditional result was False
2026-01-26 00:14:30.198706 | 
2026-01-26 00:14:30.198804 | TASK [Register the RHEL node]
2026-01-26 00:14:30.749444 | 
2026-01-26 00:14:30.749656 | TASK [Show the subscription-manager status]
2026-01-26 00:14:30.827500 | controller | skipping: Conditional result was False
2026-01-26 00:14:30.834573 | 
2026-01-26 00:14:30.834675 | TASK [Enable EPEL on RHEL]
2026-01-26 00:14:31.368114 | controller | skipping: Conditional result was False
2026-01-26 00:14:31.377007 | 
2026-01-26 00:14:31.377153 | TASK [Install git and tox]
2026-01-26 00:15:50.043827 | controller | changed
2026-01-26 00:15:50.052456 | 
2026-01-26 00:15:50.052578 | TASK [include_role : prepare-workspace]
2026-01-26 00:15:50.079349 | controller | ok
2026-01-26 00:15:50.110135 | 
2026-01-26 00:15:50.110280 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-26 00:15:50.335373 | controller | ok
2026-01-26 00:15:50.342225 | 
2026-01-26 00:15:50.342303 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-26 00:16:02.937861 | controller | Output suppressed because no_log was given
2026-01-26 00:16:02.973890 | 
2026-01-26 00:16:02.974006 | TASK [include_role : prepare-workspace-openshift]
2026-01-26 00:16:02.998237 | controller | skipping: Conditional result was False
2026-01-26 00:16:03.020198 | 
2026-01-26 00:16:03.020276 | PLAY [all:!appliance]
2026-01-26 00:16:03.036525 | 
2026-01-26 00:16:03.036628 | TASK [Run add-build-sshkey role (RSA)]
2026-01-26 00:16:03.066475 | controller | ok
2026-01-26 00:16:03.080535 | 
2026-01-26 00:16:03.080625 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-26 00:16:03.349440 | controller -> localhost | ok
2026-01-26 00:16:03.356358 | 
2026-01-26 00:16:03.356463 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-26 00:16:03.389630 | controller | ok
2026-01-26 00:16:03.407705 | controller | included: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-26 00:16:03.413869 | 
2026-01-26 00:16:03.413936 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-26 00:16:04.090534 | controller -> localhost | Generating public/private rsa key pair.
2026-01-26 00:16:04.090713 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/87bca2e62b7d4ad99e7f7ad86cb2cd00_id_rsa.
2026-01-26 00:16:04.090767 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/87bca2e62b7d4ad99e7f7ad86cb2cd00_id_rsa.pub.
2026-01-26 00:16:04.090792 | controller -> localhost | The key fingerprint is:
2026-01-26 00:16:04.090812 | controller -> localhost | SHA256:Y9gykQzL/yxoj4ySR38KDbm1o6xXcL//FWz7xzB5x4s zuul-build-sshkey
2026-01-26 00:16:04.090830 | controller -> localhost | The key's randomart image is:
2026-01-26 00:16:04.090847 | controller -> localhost | +---[RSA 2048]----+
2026-01-26 00:16:04.090864 | controller -> localhost | |    .            |
2026-01-26 00:16:04.090882 | controller -> localhost | |   . + .         |
2026-01-26 00:16:04.090899 | controller -> localhost | |    o +          |
2026-01-26 00:16:04.090916 | controller -> localhost | |  .... +   .     |
2026-01-26 00:16:04.090932 | controller -> localhost | |  oo..= S   +  o |
2026-01-26 00:16:04.090959 | controller -> localhost | |  .=.o.* . . o+ +|
2026-01-26 00:16:04.090983 | controller -> localhost | | ooo* ..o   o .=o|
2026-01-26 00:16:04.091002 | controller -> localhost | |o.o*.+o.   . E .o|
2026-01-26 00:16:04.091020 | controller -> localhost | |.=+ +o.....   .. |
2026-01-26 00:16:04.091040 | controller -> localhost | +----[SHA256]-----+
2026-01-26 00:16:04.091080 | controller -> localhost | ok: Runtime: 0:00:00.229552
2026-01-26 00:16:04.097614 | 
2026-01-26 00:16:04.097681 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-26 00:16:04.121973 | controller | ok
2026-01-26 00:16:04.137030 | controller | included: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-26 00:16:04.151454 | 
2026-01-26 00:16:04.151583 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-26 00:16:04.177410 | controller | skipping: Conditional result was False
2026-01-26 00:16:04.183989 | 
2026-01-26 00:16:04.184078 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-26 00:16:04.654577 | controller | changed
2026-01-26 00:16:04.662464 | 
2026-01-26 00:16:04.662594 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-26 00:16:04.880624 | controller | ok
2026-01-26 00:16:04.888413 | 
2026-01-26 00:16:04.888521 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-26 00:16:05.523758 | controller | changed
2026-01-26 00:16:05.532312 | 
2026-01-26 00:16:05.532406 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-26 00:16:06.181576 | controller | changed
2026-01-26 00:16:06.190202 | 
2026-01-26 00:16:06.190341 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-26 00:16:06.216440 | controller | skipping: Conditional result was False
2026-01-26 00:16:06.225070 | 
2026-01-26 00:16:06.225196 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-26 00:16:06.647681 | controller -> localhost | changed
2026-01-26 00:16:06.659460 | 
2026-01-26 00:16:06.659564 | TASK [add-build-sshkey : Add back temp key]
2026-01-26 00:16:07.045275 | controller -> localhost | Identity added: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/87bca2e62b7d4ad99e7f7ad86cb2cd00_id_rsa (zuul-build-sshkey)
2026-01-26 00:16:07.045556 | controller -> localhost | ok: Runtime: 0:00:00.008104
2026-01-26 00:16:07.052207 | 
2026-01-26 00:16:07.052314 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-26 00:16:07.387586 | controller | ok
2026-01-26 00:16:07.393076 | 
2026-01-26 00:16:07.393140 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-26 00:16:07.428268 | controller | skipping: Conditional result was False
2026-01-26 00:16:07.440093 | 
2026-01-26 00:16:07.440207 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-26 00:16:07.471089 | controller | ok
2026-01-26 00:16:07.487400 | 
2026-01-26 00:16:07.487514 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-26 00:16:07.788690 | controller -> localhost | ok
2026-01-26 00:16:07.803320 | 
2026-01-26 00:16:07.803484 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-26 00:16:07.844822 | controller | ok
2026-01-26 00:16:07.866274 | controller | included: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-26 00:16:07.876247 | 
2026-01-26 00:16:07.876360 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-26 00:16:08.198028 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-26 00:16:08.198375 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/87bca2e62b7d4ad99e7f7ad86cb2cd00_id_ecdsa.
2026-01-26 00:16:08.198459 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/87bca2e62b7d4ad99e7f7ad86cb2cd00_id_ecdsa.pub.
2026-01-26 00:16:08.198541 | controller -> localhost | The key fingerprint is:
2026-01-26 00:16:08.198606 | controller -> localhost | SHA256:6qwruBTlxtWIVtBmFDiCqXe+dXsV0lelptiN18FYzrU zuul-build-sshkey
2026-01-26 00:16:08.198668 | controller -> localhost | The key's randomart image is:
2026-01-26 00:16:08.198785 | controller -> localhost | +---[ECDSA 521]---+
2026-01-26 00:16:08.198861 | controller -> localhost | |.. .=+.        .+|
2026-01-26 00:16:08.198919 | controller -> localhost | |o. oo+o       *.+|
2026-01-26 00:16:08.198973 | controller -> localhost | |. .++o .   . .oE |
2026-01-26 00:16:08.199025 | controller -> localhost | |. * o     .oo=...|
2026-01-26 00:16:08.199070 | controller -> localhost | | o *    S ..+oo .|
2026-01-26 00:16:08.199111 | controller -> localhost | |  o . ...   ..   |
2026-01-26 00:16:08.199152 | controller -> localhost | | o   o.. . .     |
2026-01-26 00:16:08.199193 | controller -> localhost | |o . .o  . .      |
2026-01-26 00:16:08.199233 | controller -> localhost | |.. .ooo  .       |
2026-01-26 00:16:08.199273 | controller -> localhost | +----[SHA256]-----+
2026-01-26 00:16:08.199365 | controller -> localhost | ok: Runtime: 0:00:00.007949
2026-01-26 00:16:08.214668 | 
2026-01-26 00:16:08.214933 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-26 00:16:08.255633 | controller | ok
2026-01-26 00:16:08.274978 | controller | included: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-26 00:16:08.289844 | 
2026-01-26 00:16:08.289978 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-26 00:16:08.305769 | controller | skipping: Conditional result was False
2026-01-26 00:16:08.317192 | 
2026-01-26 00:16:08.317331 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-26 00:16:08.616478 | controller | changed
2026-01-26 00:16:08.624203 | 
2026-01-26 00:16:08.624311 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-26 00:16:08.832478 | controller | ok
2026-01-26 00:16:08.841934 | 
2026-01-26 00:16:08.842095 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-26 00:16:09.389668 | controller | changed
2026-01-26 00:16:09.397424 | 
2026-01-26 00:16:09.397501 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-26 00:16:10.010320 | controller | changed
2026-01-26 00:16:10.017899 | 
2026-01-26 00:16:10.017984 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-26 00:16:10.043482 | controller | skipping: Conditional result was False
2026-01-26 00:16:10.052559 | 
2026-01-26 00:16:10.052657 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-26 00:16:10.282878 | controller -> localhost | changed
2026-01-26 00:16:10.325514 | 
2026-01-26 00:16:10.325630 | TASK [add-build-sshkey : Add back temp key]
2026-01-26 00:16:10.594411 | controller -> localhost | Identity added: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/87bca2e62b7d4ad99e7f7ad86cb2cd00_id_ecdsa (zuul-build-sshkey)
2026-01-26 00:16:10.594931 | controller -> localhost | ok: Runtime: 0:00:00.007196
2026-01-26 00:16:10.609498 | 
2026-01-26 00:16:10.609639 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-26 00:16:10.812876 | controller | ok
2026-01-26 00:16:10.826259 | 
2026-01-26 00:16:10.826481 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-26 00:16:10.855076 | controller | skipping: Conditional result was False
2026-01-26 00:16:10.867804 | 
2026-01-26 00:16:10.867942 | TASK [include_role : remove-zuul-sshkey]
2026-01-26 00:16:10.882180 | controller | skipping: Conditional result was False
2026-01-26 00:16:10.889471 | 
2026-01-26 00:16:10.889563 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-26 00:16:11.114968 | controller | ok: "logs"
2026-01-26 00:16:11.115206 | controller | ok: All items complete
2026-01-26 00:16:11.115235 | 
2026-01-26 00:16:11.301808 | controller | ok: "artifacts"
2026-01-26 00:16:11.486205 | controller | ok: "docs"
2026-01-26 00:16:11.503527 | 
2026-01-26 00:16:11.503646 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-26 00:16:11.716442 | controller | changed: "logs"
2026-01-26 00:16:11.920885 | controller | changed: "artifacts"
2026-01-26 00:16:12.128824 | controller | changed: "docs"
2026-01-26 00:16:12.158774 | 
2026-01-26 00:16:12.158878 | PLAY RECAP
2026-01-26 00:16:12.158922 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-26 00:16:12.158948 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 00:16:12.158966 | 
2026-01-26 00:16:12.264450 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-26 00:16:12.266230 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-26 00:16:12.866642 | 
2026-01-26 00:16:12.866769 | PLAY [all]
2026-01-26 00:16:12.889028 | 
2026-01-26 00:16:12.889146 | TASK [Install binary dependencies]
2026-01-26 00:16:12.969370 | controller | ok
2026-01-26 00:16:12.988651 | 
2026-01-26 00:16:12.988790 | TASK [bindep : Include find tasks]
2026-01-26 00:16:13.028600 | controller | ok
2026-01-26 00:16:13.036138 | controller | included: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-26 00:16:13.042647 | 
2026-01-26 00:16:13.042713 | TASK [bindep : Look for bindep.txt]
2026-01-26 00:16:13.423049 | controller | ok
2026-01-26 00:16:13.430982 | 
2026-01-26 00:16:13.431118 | TASK [bindep : Define bindep_file fact]
2026-01-26 00:16:13.456159 | controller | skipping: Conditional result was False
2026-01-26 00:16:13.462471 | 
2026-01-26 00:16:13.462571 | TASK [bindep : Look for other-requirements.txt]
2026-01-26 00:16:13.666130 | controller | ok
2026-01-26 00:16:13.676582 | 
2026-01-26 00:16:13.676718 | TASK [bindep : Define bindep_file fact]
2026-01-26 00:16:13.703558 | controller | skipping: Conditional result was False
2026-01-26 00:16:13.712380 | 
2026-01-26 00:16:13.712474 | TASK [bindep : Look for bindep fallback file]
2026-01-26 00:16:13.737515 | controller | skipping: Conditional result was False
2026-01-26 00:16:13.747487 | 
2026-01-26 00:16:13.747595 | TASK [bindep : Define bindep_file fact]
2026-01-26 00:16:13.773933 | controller | skipping: Conditional result was False
2026-01-26 00:16:13.782575 | 
2026-01-26 00:16:13.782666 | TASK [bindep : Include bindep tasks]
2026-01-26 00:16:13.807653 | controller | skipping: Conditional result was False
2026-01-26 00:16:13.816112 | 
2026-01-26 00:16:13.816211 | TASK [bindep : Include install tasks]
2026-01-26 00:16:13.841946 | controller | skipping: Conditional result was False
2026-01-26 00:16:13.856550 | 
2026-01-26 00:16:13.856706 | LOOP [bindep : Include package tasks]
2026-01-26 00:16:13.925051 | 
2026-01-26 00:16:13.925215 | TASK [Run test-setup role]
2026-01-26 00:16:13.947010 | controller | ok
2026-01-26 00:16:13.964499 | 
2026-01-26 00:16:13.964581 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-26 00:16:14.178148 | controller | ok
2026-01-26 00:16:14.185033 | 
2026-01-26 00:16:14.185133 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-26 00:16:14.718287 | controller | skipping: Conditional result was False
2026-01-26 00:16:14.749362 | 
2026-01-26 00:16:14.749515 | PLAY RECAP
2026-01-26 00:16:14.749560 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-26 00:16:14.749580 | 
2026-01-26 00:16:14.866994 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-26 00:16:14.867953 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-26 00:16:15.442417 | 
2026-01-26 00:16:15.442557 | PLAY [controller]
2026-01-26 00:16:15.463878 | 
2026-01-26 00:16:15.464013 | TASK [Create the /root directory]
2026-01-26 00:16:15.849035 | controller | ok
2026-01-26 00:16:15.861982 | 
2026-01-26 00:16:15.862148 | TASK [Install glibc-langpack-en]
2026-01-26 00:16:19.770465 | controller | ok: Nothing to do
2026-01-26 00:16:19.784328 | 
2026-01-26 00:16:19.784500 | TASK [Ensure controller directory exists]
2026-01-26 00:16:20.009772 | controller | changed
2026-01-26 00:16:20.017292 | 
2026-01-26 00:16:20.017533 | TASK [Install container runtime]
2026-01-26 00:16:20.080926 | controller | ok
2026-01-26 00:16:20.114945 | 
2026-01-26 00:16:20.115064 | LOOP [ensure-podman : Find distribution installation]
2026-01-26 00:16:20.137513 | controller | ok: "/var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-26 00:16:20.148802 | controller | included: /var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-26 00:16:20.159292 | 
2026-01-26 00:16:20.159437 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-26 00:17:26.402589 | controller | changed
2026-01-26 00:17:26.419875 | 
2026-01-26 00:17:26.420061 | TASK [ensure-podman : Fetch podman version]
2026-01-26 00:17:26.955204 | controller | Client:       Podman Engine
2026-01-26 00:17:26.981623 | controller | Version:      4.6.2
2026-01-26 00:17:26.981650 | controller | API Version:  4.6.2
2026-01-26 00:17:26.981659 | controller | Go Version:   go1.19.12
2026-01-26 00:17:26.981675 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-26 00:17:26.981683 | controller | OS/Arch:      linux/amd64
2026-01-26 00:17:27.474003 | controller | ok: Runtime: 0:00:00.181049
2026-01-26 00:17:27.487539 | 
2026-01-26 00:17:27.487683 | TASK [ensure-podman : Print podman version installed]
2026-01-26 00:17:27.529637 | Podman version: Client:       Podman Engine
2026-01-26 00:17:27.529963 | Version:      4.6.2
2026-01-26 00:17:27.530221 | API Version:  4.6.2
2026-01-26 00:17:27.530308 | Go Version:   go1.19.12
2026-01-26 00:17:27.530365 | Built:        Mon Aug 28 19:38:31 2023
2026-01-26 00:17:27.530407 | OS/Arch:      linux/amd64
2026-01-26 00:17:27.543690 | 
2026-01-26 00:17:27.543864 | TASK [ensure-podman : Validate podman engine]
2026-01-26 00:17:28.088564 | controller | skipping: Conditional result was False
2026-01-26 00:17:28.102361 | 
2026-01-26 00:17:28.102503 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-26 00:17:28.129145 | controller | skipping: Conditional result was False
2026-01-26 00:17:28.154188 | 
2026-01-26 00:17:28.154413 | TASK [Ensure python3.8 is present]
2026-01-26 00:17:28.181246 | controller | skipping: Conditional result was False
2026-01-26 00:17:28.194433 | 
2026-01-26 00:17:28.194569 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-26 00:17:28.225979 | controller | ok
2026-01-26 00:17:28.256294 | 
2026-01-26 00:17:28.256415 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-26 00:17:29.685419 | controller | ok: Nothing to do
2026-01-26 00:17:29.698560 | 
2026-01-26 00:17:29.698708 | TASK [our-ensure-python : Also install python3-devel]
2026-01-26 00:17:38.769014 | controller | changed
2026-01-26 00:17:38.793808 | 
2026-01-26 00:17:38.793994 | TASK [Run ensure-virtualenv role]
2026-01-26 00:17:38.822433 | controller | ok
2026-01-26 00:17:38.859306 | 
2026-01-26 00:17:38.859458 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-26 00:17:39.109732 | controller | /usr/bin/virtualenv
2026-01-26 00:17:39.419969 | controller | ok: Runtime: 0:00:00.004932
2026-01-26 00:17:39.426072 | 
2026-01-26 00:17:39.426149 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-26 00:17:39.460351 | controller | skipping: Conditional result was False
2026-01-26 00:17:39.460906 | controller | ok: All items complete
2026-01-26 00:17:39.460982 | 
2026-01-26 00:17:39.506860 | 
2026-01-26 00:17:39.507135 | TASK [Find the full path of the Python interpreter]
2026-01-26 00:17:39.737050 | controller | /usr/bin/python3
2026-01-26 00:17:40.058289 | controller | ok
2026-01-26 00:17:40.065164 | 
2026-01-26 00:17:40.065258 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-26 00:17:40.825679 | controller | created virtual environment CPython3.11.0.final.0-64 in 444ms
2026-01-26 00:17:40.842218 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-26 00:17:40.842255 | 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-26 00:17:40.842265 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-26 00:17:40.842280 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-26 00:17:41.100279 | controller | changed
2026-01-26 00:17:41.108657 | 
2026-01-26 00:17:41.108790 | TASK [Set selinux package]
2026-01-26 00:17:41.131551 | controller | ok
2026-01-26 00:17:41.138584 | 
2026-01-26 00:17:41.138668 | TASK [Set selinux package (Fedora)]
2026-01-26 00:17:41.182489 | controller | ok
2026-01-26 00:17:41.190043 | 
2026-01-26 00:17:41.190135 | TASK [Install selinux into virtualenv]
2026-01-26 00:18:06.687836 | controller | Collecting selinux-please-lie-to-me
2026-01-26 00:18:18.934689 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-26 00:18:19.238631 | controller | Collecting setuptools<50.0.0
2026-01-26 00:18:19.263977 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-26 00:18:19.317034 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.4 MB/s eta 0:00:00
2026-01-26 00:18:19.397796 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-26 00:18:19.397968 | controller |   Attempting uninstall: setuptools
2026-01-26 00:18:19.400534 | controller |     Found existing installation: setuptools 62.6.0
2026-01-26 00:18:19.460047 | controller |     Uninstalling setuptools-62.6.0:
2026-01-26 00:18:19.468275 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-26 00:18:19.817998 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-26 00:18:31.365566 | controller |
2026-01-26 00:18:31.449216 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-26 00:18:31.449278 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-26 00:18:31.766858 | controller | ok: Runtime: 0:00:50.038280
2026-01-26 00:18:31.780849 | 
2026-01-26 00:18:31.781006 | TASK [Install pytest-forked into virtualenv]
2026-01-26 00:18:42.663329 | controller | Collecting pytest-forked
2026-01-26 00:18:54.896932 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-26 00:18:54.946442 | controller | Collecting py
2026-01-26 00:18:54.977757 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-26 00:18:54.998968 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.7 MB/s eta 0:00:00
2026-01-26 00:18:55.105783 | controller | Collecting pytest>=3.10
2026-01-26 00:18:55.109740 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-26 00:18:55.122785 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 35.8 MB/s eta 0:00:00
2026-01-26 00:18:55.169995 | controller | Collecting iniconfig>=1.0.1
2026-01-26 00:18:55.186969 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-26 00:18:55.240097 | controller | Collecting packaging>=22
2026-01-26 00:18:55.245082 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-01-26 00:18:55.250961 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 19.6 MB/s eta 0:00:00
2026-01-26 00:18:55.298729 | controller | Collecting pluggy<2,>=1.5
2026-01-26 00:18:55.305850 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-26 00:18:55.378027 | controller | Collecting pygments>=2.7.2
2026-01-26 00:18:55.393912 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-26 00:18:55.416439 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 64.8 MB/s eta 0:00:00
2026-01-26 00:18:55.486361 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-26 00:18:56.539464 | 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-26 00:18:56.548422 | controller |
2026-01-26 00:18:56.616002 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-26 00:18:56.616042 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-26 00:18:56.843202 | controller | ok: Runtime: 0:00:24.585114
2026-01-26 00:18:56.855436 | 
2026-01-26 00:18:56.855580 | TASK [Update pip]
2026-01-26 00:18:57.362088 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-26 00:19:07.283790 | controller | Collecting pip
2026-01-26 00:19:19.594255 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-26 00:19:19.650442 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.2 MB/s eta 0:00:00
2026-01-26 00:19:19.713648 | controller | Installing collected packages: pip
2026-01-26 00:19:19.713878 | controller |   Attempting uninstall: pip
2026-01-26 00:19:19.716022 | controller |     Found existing installation: pip 22.2.2
2026-01-26 00:19:19.852657 | controller |     Uninstalling pip-22.2.2:
2026-01-26 00:19:19.867579 | controller |       Successfully uninstalled pip-22.2.2
2026-01-26 00:19:20.663050 | controller | Successfully installed pip-25.3
2026-01-26 00:19:20.924958 | controller | ok: Runtime: 0:00:23.664237
2026-01-26 00:19:20.938312 | 
2026-01-26 00:19:20.938467 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-26 00:19:21.169526 | controller | changed
2026-01-26 00:19:21.226981 | 
2026-01-26 00:19:21.227125 | TASK [Install ansible into virtualenv]
2026-01-26 00:19:21.714285 | controller | Processing ./src/github.com/ansible/ansible
2026-01-26 00:19:21.717643 | controller |   Installing build dependencies: started
2026-01-26 00:19:44.593325 | controller |   Installing build dependencies: finished with status 'done'
2026-01-26 00:19:44.595053 | controller |   Getting requirements to build wheel: started
2026-01-26 00:19:45.306509 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-26 00:19:45.307845 | controller |   Preparing metadata (pyproject.toml): started
2026-01-26 00:19:45.763166 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-26 00:19:45.766487 | 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-26 00:19:45.770082 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-26 00:19:46.272898 | controller | ERROR
2026-01-26 00:19:46.273251 | controller | {
2026-01-26 00:19:46.273316 | controller |   "delta": "0:00:24.393865",
2026-01-26 00:19:46.273360 | controller |   "end": "2026-01-26 00:19:45.828010",
2026-01-26 00:19:46.273400 | controller |   "msg": "non-zero return code",
2026-01-26 00:19:46.273460 | controller |   "rc": 1,
2026-01-26 00:19:46.273497 | controller |   "start": "2026-01-26 00:19:21.434145"
2026-01-26 00:19:46.273532 | controller | }
failure
2026-01-26 00:19:46.276557 | 
2026-01-26 00:19:46.276659 | PLAY RECAP
2026-01-26 00:19:46.276785 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-26 00:19:46.276839 | 
2026-01-26 00:19:46.404201 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-26 00:19:46.406236 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-26 00:19:47.485963 | 
2026-01-26 00:19:47.486067 | PLAY [all]
2026-01-26 00:19:47.533778 | 
2026-01-26 00:19:47.533913 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-26 00:19:47.828863 | controller | changed: non-zero return code
2026-01-26 00:19:47.841638 | 
2026-01-26 00:19:47.841875 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-26 00:19:47.869642 | controller | skipping: Conditional result was False
2026-01-26 00:19:47.884096 | 
2026-01-26 00:19:47.884259 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-26 00:19:47.929349 | 
2026-01-26 00:19:47.929633 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-26 00:19:47.971452 | 
2026-01-26 00:19:47.971764 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-26 00:19:47.999219 | controller | skipping: Conditional result was False
2026-01-26 00:19:48.014093 | 
2026-01-26 00:19:48.014242 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-26 00:19:48.044609 | 
2026-01-26 00:19:48.044967 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-26 00:19:48.072258 | controller | skipping: Conditional result was False
2026-01-26 00:19:48.085483 | 
2026-01-26 00:19:48.085658 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-26 00:19:48.102333 | controller | skipping: Conditional result was False
2026-01-26 00:19:48.115389 | 
2026-01-26 00:19:48.115543 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-26 00:19:48.131937 | controller | skipping: Conditional result was False
2026-01-26 00:19:48.179362 | 
2026-01-26 00:19:48.179473 | PLAY RECAP
2026-01-26 00:19:48.179530 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-26 00:19:48.179560 | 
2026-01-26 00:19:48.282120 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-26 00:19:48.283086 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-26 00:19:48.848180 | 
2026-01-26 00:19:48.848283 | PLAY [all:!appliance*]
2026-01-26 00:19:48.869536 | 
2026-01-26 00:19:48.869611 | TASK [unregister the node]
2026-01-26 00:19:49.401439 | controller | skipping: Conditional result was False
2026-01-26 00:19:49.415138 | 
2026-01-26 00:19:49.415355 | TASK [include_role : fetch-output]
2026-01-26 00:19:49.466716 | controller | ok
2026-01-26 00:19:49.508985 | 
2026-01-26 00:19:49.509116 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-26 00:19:49.585888 | controller | skipping: Conditional result was False
2026-01-26 00:19:49.599271 | 
2026-01-26 00:19:49.599434 | TASK [fetch-output : Set log path for single node]
2026-01-26 00:19:49.650512 | controller | ok
2026-01-26 00:19:49.663508 | 
2026-01-26 00:19:49.663663 | LOOP [fetch-output : Ensure local output dirs]
2026-01-26 00:19:50.109366 | controller -> localhost | ok: "/var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/logs"
2026-01-26 00:19:50.377708 | controller -> localhost | changed: "/var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/artifacts"
2026-01-26 00:19:50.615953 | controller -> localhost | changed: "/var/lib/zuul/builds/87bca2e62b7d4ad99e7f7ad86cb2cd00/work/docs"
2026-01-26 00:19:50.639855 | 
2026-01-26 00:19:50.640032 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-26 00:19:51.366546 | controller | changed:
2026-01-26 00:19:51.366791 | controller | .d..t...... ./
2026-01-26 00:19:51.366824 | controller | cd+++++++++ controller/
2026-01-26 00:19:51.366857 | controller | changed: All items complete
2026-01-26 00:19:51.366877 | 
2026-01-26 00:19:51.835424 | controller | changed: .d..t...... ./
2026-01-26 00:19:52.369325 | controller | changed: .d..t...... ./
2026-01-26 00:19:52.391997 | 
2026-01-26 00:19:52.392187 | TASK [include_role : fetch-output-openshift]
2026-01-26 00:19:52.408085 | controller | skipping: Conditional result was False
2026-01-26 00:19:52.417668 | 
2026-01-26 00:19:52.417808 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-26 00:19:52.445432 | controller | skipping: Conditional result was False
2026-01-26 00:19:52.454935 | controller | skipping: Conditional result was False
2026-01-26 00:19:52.501294 | 
2026-01-26 00:19:52.501426 | PLAY [localhost]
2026-01-26 00:19:52.517845 | 
2026-01-26 00:19:52.517945 | TASK [Run Zuul manifest role]
2026-01-26 00:19:52.539080 | localhost | ok
2026-01-26 00:19:52.558143 | 
2026-01-26 00:19:52.558248 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-26 00:19:52.947376 | localhost | changed
2026-01-26 00:19:52.952640 | 
2026-01-26 00:19:52.952718 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-26 00:19:52.981477 | localhost | ok
2026-01-26 00:19:52.990058 | 
2026-01-26 00:19:52.990122 | TASK [Set zuul-log-path fact]
2026-01-26 00:19:53.014689 | localhost | ok
2026-01-26 00:19:53.041078 | 
2026-01-26 00:19:53.041281 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 00:19:53.083323 | localhost | ok
2026-01-26 00:19:53.093704 | 
2026-01-26 00:19:53.093808 | LOOP [Run upload-logs-swift role]
2026-01-26 00:19:53.129027 | localhost | Output suppressed because no_log was given
2026-01-26 00:19:53.160493 | 
2026-01-26 00:19:53.160593 | TASK [Set zuul-log-path fact]
2026-01-26 00:19:53.186387 | localhost | skipping: Conditional result was False
2026-01-26 00:19:53.191499 | 
2026-01-26 00:19:53.191570 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-26 00:19:53.645062 | localhost -> localhost | ok: Runtime: 0:00:00.009857
2026-01-26 00:19:53.689746 | 
2026-01-26 00:19:53.689893 | TASK [upload-logs-swift : Upload logs to swift]