2025-12-22 00:14:07.931952 | Job console starting...
2025-12-22 00:14:07.948060 | Updating repositories
2025-12-22 00:14:08.062122 | Preparing job workspace
2025-12-22 00:14:11.752963 | Running Ansible setup...
2025-12-22 00:14:16.803272 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-22 00:14:17.414850 | 
2025-12-22 00:14:17.414975 | PLAY [localhost]
2025-12-22 00:14:17.424063 | 
2025-12-22 00:14:17.424137 | TASK [Gathering Facts]
2025-12-22 00:14:18.439306 | localhost | ok
2025-12-22 00:14:18.454818 | 
2025-12-22 00:14:18.454939 | TASK [Setup log path fact]
2025-12-22 00:14:18.474800 | localhost | ok
2025-12-22 00:14:18.488478 | 
2025-12-22 00:14:18.488598 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-22 00:14:18.518128 | localhost | ok
2025-12-22 00:14:18.525871 | 
2025-12-22 00:14:18.525947 | TASK [emit-job-header : Print job information]
2025-12-22 00:14:18.564616 | # Job Information
2025-12-22 00:14:18.564787 | Ansible Version: 2.15.12
2025-12-22 00:14:18.564821 | Job: ansible-test-sanity-docker-milestone
2025-12-22 00:14:18.564841 | Pipeline: periodic
2025-12-22 00:14:18.564859 | Executor: ze01.softwarefactory-project.io
2025-12-22 00:14:18.564876 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-22 00:14:18.564897 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/d77/ansible/d7727d750c4742238d62746b5dc1d541/
2025-12-22 00:14:18.564915 | Event ID: 7f35c592378340c19748c21b5a64baf3
2025-12-22 00:14:18.568789 | 
2025-12-22 00:14:18.568855 | LOOP [emit-job-header : Print node information]
2025-12-22 00:14:18.681139 | localhost | ok:
2025-12-22 00:14:18.681337 | localhost | # Node Information
2025-12-22 00:14:18.681375 | localhost | Inventory Hostname: controller
2025-12-22 00:14:18.681404 | localhost | Hostname: np0005568480
2025-12-22 00:14:18.681432 | localhost | Username: zuul
2025-12-22 00:14:18.681462 | localhost | Distro: Fedora 37
2025-12-22 00:14:18.681488 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-22 00:14:18.681513 | localhost | Region: ca-ymq-1
2025-12-22 00:14:18.681537 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-22 00:14:18.681560 | localhost | Product Name: OpenStack Nova
2025-12-22 00:14:18.681584 | localhost | Interface IP: 162.253.55.187
2025-12-22 00:14:18.691568 | 
2025-12-22 00:14:18.691688 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-22 00:14:19.094918 | localhost -> localhost | changed
2025-12-22 00:14:19.102758 | 
2025-12-22 00:14:19.102861 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-22 00:14:20.140592 | localhost -> localhost | changed
2025-12-22 00:14:20.163639 | 
2025-12-22 00:14:20.163739 | PLAY [all:!appliance*]
2025-12-22 00:14:20.192818 | 
2025-12-22 00:14:20.192949 | TASK [include_role : start-zuul-console]
2025-12-22 00:14:20.215447 | controller | ok
2025-12-22 00:14:20.243101 | 
2025-12-22 00:14:20.243218 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-22 00:14:20.767662 | controller | ok
2025-12-22 00:14:20.783863 | 
2025-12-22 00:14:20.783985 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-22 00:14:21.728206 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-22 00:14:21.734574 | 
2025-12-22 00:14:21.734674 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-22 00:14:22.280182 | controller | skipping: Conditional result was False
2025-12-22 00:14:22.294324 | 
2025-12-22 00:14:22.294488 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-22 00:14:22.311769 | controller | skipping: Conditional result was False
2025-12-22 00:14:22.337446 | 
2025-12-22 00:14:22.337637 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-22 00:14:22.354065 | controller | skipping: Conditional result was False
2025-12-22 00:14:22.372217 | 
2025-12-22 00:14:22.372340 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-22 00:14:22.387559 | controller | skipping: Conditional result was False
2025-12-22 00:14:22.397237 | 
2025-12-22 00:14:22.397349 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-22 00:14:22.422440 | controller | skipping: Conditional result was False
2025-12-22 00:14:22.432612 | 
2025-12-22 00:14:22.432747 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-22 00:14:22.458275 | controller | skipping: Conditional result was False
2025-12-22 00:14:22.475136 | 
2025-12-22 00:14:22.475260 | TASK [Disable Fedora Modular]
2025-12-22 00:14:22.738533 | controller | changed
2025-12-22 00:14:22.748308 | 
2025-12-22 00:14:22.748435 | TASK [Enable EPEL]
2025-12-22 00:14:22.773663 | controller | skipping: Conditional result was False
2025-12-22 00:14:22.780388 | 
2025-12-22 00:14:22.780457 | TASK [Register the RHEL node]
2025-12-22 00:14:23.336931 | 
2025-12-22 00:14:23.337136 | TASK [Show the subscription-manager status]
2025-12-22 00:14:23.923753 | controller | skipping: Conditional result was False
2025-12-22 00:14:23.935373 | 
2025-12-22 00:14:23.935520 | TASK [Enable EPEL on RHEL]
2025-12-22 00:14:24.483572 | controller | skipping: Conditional result was False
2025-12-22 00:14:24.489920 | 
2025-12-22 00:14:24.489990 | TASK [Install git and tox]
2025-12-22 00:15:47.783536 | controller | changed
2025-12-22 00:15:47.792134 | 
2025-12-22 00:15:47.792221 | TASK [include_role : prepare-workspace]
2025-12-22 00:15:47.822330 | controller | ok
2025-12-22 00:15:47.853150 | 
2025-12-22 00:15:47.853260 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-22 00:15:48.097509 | controller | ok
2025-12-22 00:15:48.104464 | 
2025-12-22 00:15:48.104550 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-22 00:16:01.078689 | controller | Output suppressed because no_log was given
2025-12-22 00:16:01.145068 | 
2025-12-22 00:16:01.145258 | TASK [include_role : prepare-workspace-openshift]
2025-12-22 00:16:01.174285 | controller | skipping: Conditional result was False
2025-12-22 00:16:01.198603 | 
2025-12-22 00:16:01.198765 | PLAY [all:!appliance]
2025-12-22 00:16:01.218485 | 
2025-12-22 00:16:01.218690 | TASK [Run add-build-sshkey role (RSA)]
2025-12-22 00:16:01.251401 | controller | ok
2025-12-22 00:16:01.268787 | 
2025-12-22 00:16:01.268964 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-22 00:16:01.524148 | controller -> localhost | ok
2025-12-22 00:16:01.534139 | 
2025-12-22 00:16:01.534357 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-22 00:16:01.574295 | controller | ok
2025-12-22 00:16:01.595308 | controller | included: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-22 00:16:01.602349 | 
2025-12-22 00:16:01.602427 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-22 00:16:02.176967 | controller -> localhost | Generating public/private rsa key pair.
2025-12-22 00:16:02.177330 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/d7727d750c4742238d62746b5dc1d541_id_rsa.
2025-12-22 00:16:02.177410 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/d7727d750c4742238d62746b5dc1d541_id_rsa.pub.
2025-12-22 00:16:02.177471 | controller -> localhost | The key fingerprint is:
2025-12-22 00:16:02.177526 | controller -> localhost | SHA256:/VRW5EkDF2jIhXhCQbHkt9X2XskzeNk7kTwj78+0Vos zuul-build-sshkey
2025-12-22 00:16:02.177582 | controller -> localhost | The key's randomart image is:
2025-12-22 00:16:02.177636 | controller -> localhost | +---[RSA 2048]----+
2025-12-22 00:16:02.177692 | controller -> localhost | |        o*= +oo*+|
2025-12-22 00:16:02.177753 | controller -> localhost | |        oo.= o+oo|
2025-12-22 00:16:02.177808 | controller -> localhost | |         oo...o+.|
2025-12-22 00:16:02.177861 | controller -> localhost | |         .. oo= *|
2025-12-22 00:16:02.177914 | controller -> localhost | |        S ...o &+|
2025-12-22 00:16:02.177983 | controller -> localhost | |           o  +.X|
2025-12-22 00:16:02.178087 | controller -> localhost | |            . .+=|
2025-12-22 00:16:02.178149 | controller -> localhost | |             E.=o|
2025-12-22 00:16:02.178201 | controller -> localhost | |              .o+|
2025-12-22 00:16:02.178254 | controller -> localhost | +----[SHA256]-----+
2025-12-22 00:16:02.178349 | controller -> localhost | ok: Runtime: 0:00:00.137412
2025-12-22 00:16:02.194536 | 
2025-12-22 00:16:02.194687 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-22 00:16:02.236705 | controller | ok
2025-12-22 00:16:02.256610 | controller | included: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-22 00:16:02.270457 | 
2025-12-22 00:16:02.270578 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-22 00:16:02.285727 | controller | skipping: Conditional result was False
2025-12-22 00:16:02.295632 | 
2025-12-22 00:16:02.295773 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-22 00:16:02.820081 | controller | changed
2025-12-22 00:16:02.838854 | 
2025-12-22 00:16:02.839142 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-22 00:16:03.108569 | controller | ok
2025-12-22 00:16:03.116756 | 
2025-12-22 00:16:03.116846 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-22 00:16:03.831648 | controller | changed
2025-12-22 00:16:03.847239 | 
2025-12-22 00:16:03.847390 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-22 00:16:04.550375 | controller | changed
2025-12-22 00:16:04.564172 | 
2025-12-22 00:16:04.564322 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-22 00:16:04.591824 | controller | skipping: Conditional result was False
2025-12-22 00:16:04.606058 | 
2025-12-22 00:16:04.606202 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-22 00:16:05.021314 | controller -> localhost | changed
2025-12-22 00:16:05.034207 | 
2025-12-22 00:16:05.034313 | TASK [add-build-sshkey : Add back temp key]
2025-12-22 00:16:05.363868 | controller -> localhost | Identity added: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/d7727d750c4742238d62746b5dc1d541_id_rsa (zuul-build-sshkey)
2025-12-22 00:16:05.364104 | controller -> localhost | ok: Runtime: 0:00:00.009844
2025-12-22 00:16:05.370489 | 
2025-12-22 00:16:05.370561 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-22 00:16:05.763401 | controller | ok
2025-12-22 00:16:05.776139 | 
2025-12-22 00:16:05.776333 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-22 00:16:05.813770 | controller | skipping: Conditional result was False
2025-12-22 00:16:05.844904 | 
2025-12-22 00:16:05.845179 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-22 00:16:05.882576 | controller | ok
2025-12-22 00:16:05.908366 | 
2025-12-22 00:16:05.908527 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-22 00:16:06.231436 | controller -> localhost | ok
2025-12-22 00:16:06.242317 | 
2025-12-22 00:16:06.242422 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-22 00:16:06.277909 | controller | ok
2025-12-22 00:16:06.294135 | controller | included: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-22 00:16:06.303463 | 
2025-12-22 00:16:06.303565 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-22 00:16:06.604637 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-22 00:16:06.604832 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/d7727d750c4742238d62746b5dc1d541_id_ecdsa.
2025-12-22 00:16:06.604863 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/d7727d750c4742238d62746b5dc1d541_id_ecdsa.pub.
2025-12-22 00:16:06.604896 | controller -> localhost | The key fingerprint is:
2025-12-22 00:16:06.604917 | controller -> localhost | SHA256:XA7pBy3D0cKD71a7c5ZKxCgI6wN+K/PgQJo+UhhR6yo zuul-build-sshkey
2025-12-22 00:16:06.604938 | controller -> localhost | The key's randomart image is:
2025-12-22 00:16:06.604957 | controller -> localhost | +---[ECDSA 521]---+
2025-12-22 00:16:06.604975 | controller -> localhost | | ..    o..       |
2025-12-22 00:16:06.604993 | controller -> localhost | |.  .  ..++.      |
2025-12-22 00:16:06.605011 | controller -> localhost | | .o    .Boo      |
2025-12-22 00:16:06.605053 | controller -> localhost | |.. o . o.X.      |
2025-12-22 00:16:06.605072 | controller -> localhost | |.+o . ..S.=.     |
2025-12-22 00:16:06.605091 | controller -> localhost | |==.    .oo.      |
2025-12-22 00:16:06.605109 | controller -> localhost | |E+o.   .  .. .   |
2025-12-22 00:16:06.605128 | controller -> localhost | |*+o..    .o +    |
2025-12-22 00:16:06.605145 | controller -> localhost | |.o=o      .=     |
2025-12-22 00:16:06.605165 | controller -> localhost | +----[SHA256]-----+
2025-12-22 00:16:06.605216 | controller -> localhost | ok: Runtime: 0:00:00.014409
2025-12-22 00:16:06.612167 | 
2025-12-22 00:16:06.612251 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-22 00:16:06.632037 | controller | ok
2025-12-22 00:16:06.639850 | controller | included: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-22 00:16:06.651698 | 
2025-12-22 00:16:06.651806 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-22 00:16:06.666537 | controller | skipping: Conditional result was False
2025-12-22 00:16:06.676254 | 
2025-12-22 00:16:06.676370 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-22 00:16:06.954718 | controller | changed
2025-12-22 00:16:06.962932 | 
2025-12-22 00:16:06.963045 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-22 00:16:07.200384 | controller | ok
2025-12-22 00:16:07.210299 | 
2025-12-22 00:16:07.210409 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-22 00:16:07.912463 | controller | changed
2025-12-22 00:16:07.927949 | 
2025-12-22 00:16:07.928193 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-22 00:16:08.613619 | controller | changed
2025-12-22 00:16:08.632938 | 
2025-12-22 00:16:08.633189 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-22 00:16:08.652623 | controller | skipping: Conditional result was False
2025-12-22 00:16:08.718574 | 
2025-12-22 00:16:08.718769 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-22 00:16:09.008703 | controller -> localhost | changed
2025-12-22 00:16:09.023599 | 
2025-12-22 00:16:09.023731 | TASK [add-build-sshkey : Add back temp key]
2025-12-22 00:16:09.365809 | controller -> localhost | Identity added: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/d7727d750c4742238d62746b5dc1d541_id_ecdsa (zuul-build-sshkey)
2025-12-22 00:16:09.366126 | controller -> localhost | ok: Runtime: 0:00:00.018009
2025-12-22 00:16:09.373318 | 
2025-12-22 00:16:09.373387 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-22 00:16:09.595700 | controller | ok
2025-12-22 00:16:09.610651 | 
2025-12-22 00:16:09.610818 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-22 00:16:09.648353 | controller | skipping: Conditional result was False
2025-12-22 00:16:09.673991 | 
2025-12-22 00:16:09.674191 | TASK [include_role : remove-zuul-sshkey]
2025-12-22 00:16:09.701068 | controller | skipping: Conditional result was False
2025-12-22 00:16:09.710871 | 
2025-12-22 00:16:09.710982 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-22 00:16:09.949671 | controller | ok: "logs"
2025-12-22 00:16:09.949951 | controller | ok: All items complete
2025-12-22 00:16:09.949989 | 
2025-12-22 00:16:10.160591 | controller | ok: "artifacts"
2025-12-22 00:16:10.369424 | controller | ok: "docs"
2025-12-22 00:16:10.386313 | 
2025-12-22 00:16:10.386520 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-22 00:16:10.629662 | controller | changed: "logs"
2025-12-22 00:16:10.831314 | controller | changed: "artifacts"
2025-12-22 00:16:11.026821 | controller | changed: "docs"
2025-12-22 00:16:11.090823 | 
2025-12-22 00:16:11.090959 | PLAY RECAP
2025-12-22 00:16:11.091073 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-22 00:16:11.091149 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-22 00:16:11.091193 | 
2025-12-22 00:16:11.224343 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-22 00:16:11.226101 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-22 00:16:11.819527 | 
2025-12-22 00:16:11.819661 | PLAY [all]
2025-12-22 00:16:11.842512 | 
2025-12-22 00:16:11.842635 | TASK [Install binary dependencies]
2025-12-22 00:16:11.915942 | controller | ok
2025-12-22 00:16:11.944224 | 
2025-12-22 00:16:11.944412 | TASK [bindep : Include find tasks]
2025-12-22 00:16:11.981421 | controller | ok
2025-12-22 00:16:11.996970 | controller | included: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-22 00:16:12.009811 | 
2025-12-22 00:16:12.009937 | TASK [bindep : Look for bindep.txt]
2025-12-22 00:16:12.409363 | controller | ok
2025-12-22 00:16:12.424926 | 
2025-12-22 00:16:12.425180 | TASK [bindep : Define bindep_file fact]
2025-12-22 00:16:12.454679 | controller | skipping: Conditional result was False
2025-12-22 00:16:12.469378 | 
2025-12-22 00:16:12.469554 | TASK [bindep : Look for other-requirements.txt]
2025-12-22 00:16:12.706605 | controller | ok
2025-12-22 00:16:12.719929 | 
2025-12-22 00:16:12.720134 | TASK [bindep : Define bindep_file fact]
2025-12-22 00:16:12.748549 | controller | skipping: Conditional result was False
2025-12-22 00:16:12.762530 | 
2025-12-22 00:16:12.762672 | TASK [bindep : Look for bindep fallback file]
2025-12-22 00:16:12.790367 | controller | skipping: Conditional result was False
2025-12-22 00:16:12.806467 | 
2025-12-22 00:16:12.806633 | TASK [bindep : Define bindep_file fact]
2025-12-22 00:16:12.834337 | controller | skipping: Conditional result was False
2025-12-22 00:16:12.848512 | 
2025-12-22 00:16:12.848655 | TASK [bindep : Include bindep tasks]
2025-12-22 00:16:12.877164 | controller | skipping: Conditional result was False
2025-12-22 00:16:12.892528 | 
2025-12-22 00:16:12.892717 | TASK [bindep : Include install tasks]
2025-12-22 00:16:12.920609 | controller | skipping: Conditional result was False
2025-12-22 00:16:12.936229 | 
2025-12-22 00:16:12.936413 | LOOP [bindep : Include package tasks]
2025-12-22 00:16:13.021613 | 
2025-12-22 00:16:13.021822 | TASK [Run test-setup role]
2025-12-22 00:16:13.049708 | controller | ok
2025-12-22 00:16:13.081327 | 
2025-12-22 00:16:13.081634 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-22 00:16:13.289800 | controller | ok
2025-12-22 00:16:13.299553 | 
2025-12-22 00:16:13.299709 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-22 00:16:13.848007 | controller | skipping: Conditional result was False
2025-12-22 00:16:13.877407 | 
2025-12-22 00:16:13.877515 | PLAY RECAP
2025-12-22 00:16:13.877563 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-22 00:16:13.877589 | 
2025-12-22 00:16:14.005428 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-22 00:16:14.006336 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-22 00:16:14.666469 | 
2025-12-22 00:16:14.666594 | PLAY [controller]
2025-12-22 00:16:14.686363 | 
2025-12-22 00:16:14.686483 | TASK [Create the /root directory]
2025-12-22 00:16:15.091897 | controller | ok
2025-12-22 00:16:15.097806 | 
2025-12-22 00:16:15.097877 | TASK [Install glibc-langpack-en]
2025-12-22 00:16:19.006002 | controller | ok: Nothing to do
2025-12-22 00:16:19.011926 | 
2025-12-22 00:16:19.011989 | TASK [Ensure controller directory exists]
2025-12-22 00:16:19.237541 | controller | changed
2025-12-22 00:16:19.246008 | 
2025-12-22 00:16:19.246131 | TASK [Install container runtime]
2025-12-22 00:16:19.327481 | controller | ok
2025-12-22 00:16:19.387532 | 
2025-12-22 00:16:19.387671 | LOOP [ensure-podman : Find distribution installation]
2025-12-22 00:16:19.431293 | controller | ok: "/var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-22 00:16:19.444321 | controller | included: /var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-22 00:16:19.453428 | 
2025-12-22 00:16:19.453520 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-22 00:17:27.097205 | controller | changed
2025-12-22 00:17:27.106336 | 
2025-12-22 00:17:27.106470 | TASK [ensure-podman : Fetch podman version]
2025-12-22 00:17:27.683995 | controller | Client:       Podman Engine
2025-12-22 00:17:27.717848 | controller | Version:      4.6.2
2025-12-22 00:17:27.717887 | controller | API Version:  4.6.2
2025-12-22 00:17:27.717900 | controller | Go Version:   go1.19.12
2025-12-22 00:17:27.717925 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-22 00:17:27.718064 | controller | OS/Arch:      linux/amd64
2025-12-22 00:17:28.152366 | controller | ok: Runtime: 0:00:00.206852
2025-12-22 00:17:28.168270 | 
2025-12-22 00:17:28.168501 | TASK [ensure-podman : Print podman version installed]
2025-12-22 00:17:28.209843 | Podman version: Client:       Podman Engine
2025-12-22 00:17:28.210156 | Version:      4.6.2
2025-12-22 00:17:28.210218 | API Version:  4.6.2
2025-12-22 00:17:28.210263 | Go Version:   go1.19.12
2025-12-22 00:17:28.210310 | Built:        Mon Aug 28 19:38:31 2023
2025-12-22 00:17:28.210370 | OS/Arch:      linux/amd64
2025-12-22 00:17:28.226402 | 
2025-12-22 00:17:28.226667 | TASK [ensure-podman : Validate podman engine]
2025-12-22 00:17:28.773048 | controller | skipping: Conditional result was False
2025-12-22 00:17:28.787771 | 
2025-12-22 00:17:28.787954 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-22 00:17:28.814409 | controller | skipping: Conditional result was False
2025-12-22 00:17:28.830246 | 
2025-12-22 00:17:28.830333 | TASK [Ensure python3.8 is present]
2025-12-22 00:17:28.854587 | controller | skipping: Conditional result was False
2025-12-22 00:17:28.860839 | 
2025-12-22 00:17:28.860903 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-22 00:17:28.880157 | controller | ok
2025-12-22 00:17:28.899802 | 
2025-12-22 00:17:28.899878 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-22 00:17:30.354234 | controller | ok: Nothing to do
2025-12-22 00:17:30.366642 | 
2025-12-22 00:17:30.366773 | TASK [our-ensure-python : Also install python3-devel]
2025-12-22 00:17:39.759062 | controller | changed
2025-12-22 00:17:39.769475 | 
2025-12-22 00:17:39.769538 | TASK [Run ensure-virtualenv role]
2025-12-22 00:17:39.787696 | controller | ok
2025-12-22 00:17:39.807982 | 
2025-12-22 00:17:39.808066 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-22 00:17:40.017881 | controller | /usr/bin/virtualenv
2025-12-22 00:17:40.337155 | controller | ok: Runtime: 0:00:00.005057
2025-12-22 00:17:40.344979 | 
2025-12-22 00:17:40.345098 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-22 00:17:40.379563 | controller | skipping: Conditional result was False
2025-12-22 00:17:40.380146 | controller | ok: All items complete
2025-12-22 00:17:40.380230 | 
2025-12-22 00:17:40.401094 | 
2025-12-22 00:17:40.401230 | TASK [Find the full path of the Python interpreter]
2025-12-22 00:17:40.619372 | controller | /usr/bin/python3
2025-12-22 00:17:40.934487 | controller | ok
2025-12-22 00:17:40.947235 | 
2025-12-22 00:17:40.947449 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-22 00:17:41.915536 | controller | created virtual environment CPython3.11.0.final.0-64 in 462ms
2025-12-22 00:17:41.939105 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-22 00:17:41.939130 | 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-22 00:17:41.939140 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-22 00:17:41.939153 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-22 00:17:42.014760 | controller | changed
2025-12-22 00:17:42.027659 | 
2025-12-22 00:17:42.027794 | TASK [Set selinux package]
2025-12-22 00:17:42.067789 | controller | ok
2025-12-22 00:17:42.079068 | 
2025-12-22 00:17:42.079230 | TASK [Set selinux package (Fedora)]
2025-12-22 00:17:42.138838 | controller | ok
2025-12-22 00:17:42.150301 | 
2025-12-22 00:17:42.150437 | TASK [Install selinux into virtualenv]
2025-12-22 00:18:19.753122 | controller | Collecting selinux-please-lie-to-me
2025-12-22 00:18:31.922087 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-22 00:18:32.231983 | controller | Collecting setuptools<50.0.0
2025-12-22 00:18:32.237183 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-22 00:18:32.271190 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 28.1 MB/s eta 0:00:00
2025-12-22 00:18:32.350890 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-22 00:18:32.351114 | controller |   Attempting uninstall: setuptools
2025-12-22 00:18:32.353511 | controller |     Found existing installation: setuptools 62.6.0
2025-12-22 00:18:32.413209 | controller |     Uninstalling setuptools-62.6.0:
2025-12-22 00:18:32.423518 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-22 00:18:32.775344 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-22 00:18:44.293216 | controller |
2025-12-22 00:18:44.396984 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-22 00:18:44.397138 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-22 00:18:44.733932 | controller | ok: Runtime: 0:01:01.987652
2025-12-22 00:18:44.746988 | 
2025-12-22 00:18:44.747201 | TASK [Install pytest-forked into virtualenv]
2025-12-22 00:18:56.569856 | controller | Collecting pytest-forked
2025-12-22 00:19:08.918189 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-22 00:19:08.964975 | controller | Collecting py
2025-12-22 00:19:08.968346 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-22 00:19:08.991546 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00
2025-12-22 00:19:09.099399 | controller | Collecting pytest>=3.10
2025-12-22 00:19:09.104640 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-22 00:19:09.120392 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 29.8 MB/s eta 0:00:00
2025-12-22 00:19:09.155020 | controller | Collecting iniconfig>=1.0.1
2025-12-22 00:19:09.158653 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-22 00:19:09.199119 | controller | Collecting packaging>=22
2025-12-22 00:19:09.202596 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-22 00:19:09.208424 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 18.3 MB/s eta 0:00:00
2025-12-22 00:19:09.238808 | controller | Collecting pluggy<2,>=1.5
2025-12-22 00:19:09.242360 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-22 00:19:09.288965 | controller | Collecting pygments>=2.7.2
2025-12-22 00:19:09.292586 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-22 00:19:09.316444 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 59.3 MB/s eta 0:00:00
2025-12-22 00:19:09.385356 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-22 00:19:10.510773 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2025-12-22 00:19:10.526666 | controller |
2025-12-22 00:19:10.639072 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-22 00:19:10.639104 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-22 00:19:10.818882 | controller | ok: Runtime: 0:00:25.655575
2025-12-22 00:19:10.828533 | 
2025-12-22 00:19:10.828693 | TASK [Update pip]
2025-12-22 00:19:11.432412 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-22 00:19:21.829717 | controller | Collecting pip
2025-12-22 00:19:46.099583 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-22 00:19:46.159118 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.8 MB/s eta 0:00:00
2025-12-22 00:19:46.225704 | controller | Installing collected packages: pip
2025-12-22 00:19:46.225940 | controller |   Attempting uninstall: pip
2025-12-22 00:19:46.228122 | controller |     Found existing installation: pip 22.2.2
2025-12-22 00:19:46.369597 | controller |     Uninstalling pip-22.2.2:
2025-12-22 00:19:46.386193 | controller |       Successfully uninstalled pip-22.2.2
2025-12-22 00:19:47.226156 | controller | Successfully installed pip-25.3
2025-12-22 00:19:47.445317 | controller | ok: Runtime: 0:00:36.216419
2025-12-22 00:19:47.454904 | 
2025-12-22 00:19:47.455008 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-22 00:19:47.737863 | controller | changed
2025-12-22 00:19:47.750540 | 
2025-12-22 00:19:47.751233 | TASK [Install ansible into virtualenv]
2025-12-22 00:19:48.337477 | controller | Processing ./src/github.com/ansible/ansible
2025-12-22 00:19:48.341154 | controller |   Installing build dependencies: started
2025-12-22 00:20:11.102469 | controller |   Installing build dependencies: finished with status 'done'
2025-12-22 00:20:11.105462 | controller |   Getting requirements to build wheel: started
2025-12-22 00:20:11.827793 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-22 00:20:11.829348 | controller |   Preparing metadata (pyproject.toml): started
2025-12-22 00:20:12.298693 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-22 00:20:12.304586 | 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-22 00:20:12.308924 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-22 00:20:12.814363 | controller | ERROR
2025-12-22 00:20:12.814623 | controller | {
2025-12-22 00:20:12.814657 | controller |   "delta": "0:00:24.364814",
2025-12-22 00:20:12.814678 | controller |   "end": "2025-12-22 00:20:12.384900",
2025-12-22 00:20:12.814696 | controller |   "msg": "non-zero return code",
2025-12-22 00:20:12.814730 | controller |   "rc": 1,
2025-12-22 00:20:12.814747 | controller |   "start": "2025-12-22 00:19:48.020086"
2025-12-22 00:20:12.814763 | controller | }
failure
2025-12-22 00:20:12.816522 | 
2025-12-22 00:20:12.816582 | PLAY RECAP
2025-12-22 00:20:12.816631 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-22 00:20:12.816657 | 
2025-12-22 00:20:12.956044 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-22 00:20:12.957372 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-22 00:20:13.586267 | 
2025-12-22 00:20:13.586396 | PLAY [all]
2025-12-22 00:20:13.609050 | 
2025-12-22 00:20:13.609165 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-22 00:20:13.881512 | controller | changed: non-zero return code
2025-12-22 00:20:13.893089 | 
2025-12-22 00:20:13.893190 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-22 00:20:13.907711 | controller | skipping: Conditional result was False
2025-12-22 00:20:13.916473 | 
2025-12-22 00:20:13.916586 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-22 00:20:13.942334 | 
2025-12-22 00:20:13.942548 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-22 00:20:13.965872 | 
2025-12-22 00:20:13.966053 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-22 00:20:13.980705 | controller | skipping: Conditional result was False
2025-12-22 00:20:13.991062 | 
2025-12-22 00:20:13.991163 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-22 00:20:14.025951 | 
2025-12-22 00:20:14.026147 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-22 00:20:14.041815 | controller | skipping: Conditional result was False
2025-12-22 00:20:14.050377 | 
2025-12-22 00:20:14.050468 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-22 00:20:14.065720 | controller | skipping: Conditional result was False
2025-12-22 00:20:14.076751 | 
2025-12-22 00:20:14.076843 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-22 00:20:14.092001 | controller | skipping: Conditional result was False
2025-12-22 00:20:14.129261 | 
2025-12-22 00:20:14.129360 | PLAY RECAP
2025-12-22 00:20:14.129404 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-22 00:20:14.129424 | 
2025-12-22 00:20:14.223539 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-22 00:20:14.224761 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-22 00:20:14.810851 | 
2025-12-22 00:20:14.810992 | PLAY [all:!appliance*]
2025-12-22 00:20:14.834503 | 
2025-12-22 00:20:14.834621 | TASK [unregister the node]
2025-12-22 00:20:15.367111 | controller | skipping: Conditional result was False
2025-12-22 00:20:15.376804 | 
2025-12-22 00:20:15.377063 | TASK [include_role : fetch-output]
2025-12-22 00:20:15.419741 | controller | ok
2025-12-22 00:20:15.449738 | 
2025-12-22 00:20:15.449862 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-22 00:20:15.517250 | controller | skipping: Conditional result was False
2025-12-22 00:20:15.531414 | 
2025-12-22 00:20:15.531623 | TASK [fetch-output : Set log path for single node]
2025-12-22 00:20:15.581514 | controller | ok
2025-12-22 00:20:15.588922 | 
2025-12-22 00:20:15.589042 | LOOP [fetch-output : Ensure local output dirs]
2025-12-22 00:20:15.971683 | controller -> localhost | ok: "/var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/logs"
2025-12-22 00:20:16.238686 | controller -> localhost | changed: "/var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/artifacts"
2025-12-22 00:20:16.455162 | controller -> localhost | changed: "/var/lib/zuul/builds/d7727d750c4742238d62746b5dc1d541/work/docs"
2025-12-22 00:20:16.473085 | 
2025-12-22 00:20:16.473244 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-22 00:20:17.110964 | controller | changed:
2025-12-22 00:20:17.111220 | controller | .d..t...... ./
2025-12-22 00:20:17.111261 | controller | cd+++++++++ controller/
2025-12-22 00:20:17.111308 | controller | changed: All items complete
2025-12-22 00:20:17.111337 | 
2025-12-22 00:20:17.632062 | controller | changed: .d..t...... ./
2025-12-22 00:20:18.120349 | controller | changed: .d..t...... ./
2025-12-22 00:20:18.145249 | 
2025-12-22 00:20:18.145370 | TASK [include_role : fetch-output-openshift]
2025-12-22 00:20:18.160347 | controller | skipping: Conditional result was False
2025-12-22 00:20:18.167506 | 
2025-12-22 00:20:18.167586 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-22 00:20:18.216898 | controller | skipping: Conditional result was False
2025-12-22 00:20:18.231427 | controller | skipping: Conditional result was False
2025-12-22 00:20:18.269415 | 
2025-12-22 00:20:18.269515 | PLAY [localhost]
2025-12-22 00:20:18.283430 | 
2025-12-22 00:20:18.283537 | TASK [Run Zuul manifest role]
2025-12-22 00:20:18.322642 | localhost | ok
2025-12-22 00:20:18.338164 | 
2025-12-22 00:20:18.338277 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-22 00:20:18.708055 | localhost | changed
2025-12-22 00:20:18.715181 | 
2025-12-22 00:20:18.715271 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-22 00:20:18.749703 | localhost | ok
2025-12-22 00:20:18.769615 | 
2025-12-22 00:20:18.769750 | TASK [Set zuul-log-path fact]
2025-12-22 00:20:18.792401 | localhost | ok
2025-12-22 00:20:18.811626 | 
2025-12-22 00:20:18.811892 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-22 00:20:18.844241 | localhost | ok
2025-12-22 00:20:18.856139 | 
2025-12-22 00:20:18.856214 | LOOP [Run upload-logs-swift role]
2025-12-22 00:20:18.882663 | localhost | Output suppressed because no_log was given
2025-12-22 00:20:18.909441 | 
2025-12-22 00:20:18.909535 | TASK [Set zuul-log-path fact]
2025-12-22 00:20:18.933692 | localhost | skipping: Conditional result was False
2025-12-22 00:20:18.938778 | 
2025-12-22 00:20:18.938847 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-22 00:20:19.363266 | localhost -> localhost | ok: Runtime: 0:00:00.005646
2025-12-22 00:20:19.370710 | 
2025-12-22 00:20:19.370832 | TASK [upload-logs-swift : Upload logs to swift]