2026-01-30 00:14:24.565738 | Job console starting...
2026-01-30 00:14:24.578585 | Updating repositories
2026-01-30 00:14:24.737625 | Preparing job workspace
2026-01-30 00:14:28.605773 | Running Ansible setup...
2026-01-30 00:14:33.373200 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-30 00:14:33.932248 | 
2026-01-30 00:14:33.932381 | PLAY [localhost]
2026-01-30 00:14:33.940622 | 
2026-01-30 00:14:33.940690 | TASK [Gathering Facts]
2026-01-30 00:14:34.977959 | localhost | ok
2026-01-30 00:14:35.008692 | 
2026-01-30 00:14:35.008846 | TASK [Setup log path fact]
2026-01-30 00:14:35.035759 | localhost | ok
2026-01-30 00:14:35.061344 | 
2026-01-30 00:14:35.061454 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-30 00:14:35.092359 | localhost | ok
2026-01-30 00:14:35.103431 | 
2026-01-30 00:14:35.103522 | TASK [emit-job-header : Print job information]
2026-01-30 00:14:35.134677 | # Job Information
2026-01-30 00:14:35.134879 | Ansible Version: 2.15.12
2026-01-30 00:14:35.134925 | Job: ansible-test-sanity-docker-milestone
2026-01-30 00:14:35.134955 | Pipeline: periodic
2026-01-30 00:14:35.134981 | Executor: ze01.softwarefactory-project.io
2026-01-30 00:14:35.135006 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-30 00:14:35.135081 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/bbe/ansible/bbe571555f204e6db59d8d7718ff960d/
2026-01-30 00:14:35.135111 | Event ID: b7cd74837303434d8030351669e6bf4f
2026-01-30 00:14:35.140484 | 
2026-01-30 00:14:35.140572 | LOOP [emit-job-header : Print node information]
2026-01-30 00:14:35.241535 | localhost | ok:
2026-01-30 00:14:35.241700 | localhost | # Node Information
2026-01-30 00:14:35.241727 | localhost | Inventory Hostname: controller
2026-01-30 00:14:35.241746 | localhost | Hostname: np0005601751
2026-01-30 00:14:35.241765 | localhost | Username: zuul
2026-01-30 00:14:35.241787 | localhost | Distro: Fedora 37
2026-01-30 00:14:35.241805 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-30 00:14:35.241822 | localhost | Region: ca-ymq-1
2026-01-30 00:14:35.241838 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-30 00:14:35.241855 | localhost | Product Name: OpenStack Nova
2026-01-30 00:14:35.241871 | localhost | Interface IP: 162.253.55.49
2026-01-30 00:14:35.259554 | 
2026-01-30 00:14:35.259703 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-30 00:14:35.682392 | localhost -> localhost | changed
2026-01-30 00:14:35.688143 | 
2026-01-30 00:14:35.688211 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-30 00:14:36.609395 | localhost -> localhost | changed
2026-01-30 00:14:36.630785 | 
2026-01-30 00:14:36.630847 | PLAY [all:!appliance*]
2026-01-30 00:14:36.647084 | 
2026-01-30 00:14:36.647150 | TASK [include_role : start-zuul-console]
2026-01-30 00:14:36.684328 | controller | ok
2026-01-30 00:14:36.697897 | 
2026-01-30 00:14:36.697963 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-30 00:14:37.090029 | controller | ok
2026-01-30 00:14:37.104207 | 
2026-01-30 00:14:37.104289 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-30 00:14:38.273703 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-30 00:14:38.282517 | 
2026-01-30 00:14:38.282598 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-30 00:14:38.819455 | controller | skipping: Conditional result was False
2026-01-30 00:14:38.828902 | 
2026-01-30 00:14:38.828991 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-30 00:14:38.873904 | controller | skipping: Conditional result was False
2026-01-30 00:14:38.887787 | 
2026-01-30 00:14:38.887922 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-30 00:14:38.917240 | controller | skipping: Conditional result was False
2026-01-30 00:14:38.927348 | 
2026-01-30 00:14:38.927453 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-30 00:14:38.959256 | controller | skipping: Conditional result was False
2026-01-30 00:14:38.967692 | 
2026-01-30 00:14:38.967790 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-30 00:14:38.992325 | controller | skipping: Conditional result was False
2026-01-30 00:14:39.001853 | 
2026-01-30 00:14:39.001945 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-30 00:14:39.024335 | controller | skipping: Conditional result was False
2026-01-30 00:14:39.049078 | 
2026-01-30 00:14:39.049233 | TASK [Disable Fedora Modular]
2026-01-30 00:14:39.338654 | controller | changed
2026-01-30 00:14:39.350781 | 
2026-01-30 00:14:39.350882 | TASK [Enable EPEL]
2026-01-30 00:14:39.365271 | controller | skipping: Conditional result was False
2026-01-30 00:14:39.372756 | 
2026-01-30 00:14:39.372877 | TASK [Register the RHEL node]
2026-01-30 00:14:39.915086 | 
2026-01-30 00:14:39.915225 | TASK [Show the subscription-manager status]
2026-01-30 00:14:40.472519 | controller | skipping: Conditional result was False
2026-01-30 00:14:40.485747 | 
2026-01-30 00:14:40.485880 | TASK [Enable EPEL on RHEL]
2026-01-30 00:14:41.034731 | controller | skipping: Conditional result was False
2026-01-30 00:14:41.048419 | 
2026-01-30 00:14:41.048566 | TASK [Install git and tox]
2026-01-30 00:16:05.040898 | controller | changed
2026-01-30 00:16:05.049909 | 
2026-01-30 00:16:05.050004 | TASK [include_role : prepare-workspace]
2026-01-30 00:16:05.083357 | controller | ok
2026-01-30 00:16:05.111643 | 
2026-01-30 00:16:05.111723 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-30 00:16:05.377283 | controller | ok
2026-01-30 00:16:05.386350 | 
2026-01-30 00:16:05.386433 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-30 00:16:18.134402 | controller | Output suppressed because no_log was given
2026-01-30 00:16:18.149765 | 
2026-01-30 00:16:18.149827 | TASK [include_role : prepare-workspace-openshift]
2026-01-30 00:16:18.165260 | controller | skipping: Conditional result was False
2026-01-30 00:16:18.210971 | 
2026-01-30 00:16:18.211077 | PLAY [all:!appliance]
2026-01-30 00:16:18.225971 | 
2026-01-30 00:16:18.226039 | TASK [Run add-build-sshkey role (RSA)]
2026-01-30 00:16:18.245954 | controller | ok
2026-01-30 00:16:18.259953 | 
2026-01-30 00:16:18.260029 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-30 00:16:18.508160 | controller -> localhost | ok
2026-01-30 00:16:18.524297 | 
2026-01-30 00:16:18.524472 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-30 00:16:18.555538 | controller | ok
2026-01-30 00:16:18.581739 | controller | included: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-30 00:16:18.590718 | 
2026-01-30 00:16:18.590818 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-30 00:16:19.042729 | controller -> localhost | Generating public/private rsa key pair.
2026-01-30 00:16:19.042899 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/bbe571555f204e6db59d8d7718ff960d_id_rsa.
2026-01-30 00:16:19.042926 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/bbe571555f204e6db59d8d7718ff960d_id_rsa.pub.
2026-01-30 00:16:19.042947 | controller -> localhost | The key fingerprint is:
2026-01-30 00:16:19.042965 | controller -> localhost | SHA256:Tzxi8lOPAdyvCid07/PiSor1lkAOnafTQKP33eIUYoQ zuul-build-sshkey
2026-01-30 00:16:19.042984 | controller -> localhost | The key's randomart image is:
2026-01-30 00:16:19.043002 | controller -> localhost | +---[RSA 2048]----+
2026-01-30 00:16:19.043042 | controller -> localhost | |       .         |
2026-01-30 00:16:19.043063 | controller -> localhost | |      E...       |
2026-01-30 00:16:19.043080 | controller -> localhost | |     + +o .      |
2026-01-30 00:16:19.043097 | controller -> localhost | |    o * +o..     |
2026-01-30 00:16:19.043114 | controller -> localhost | |     =oBSo*o.    |
2026-01-30 00:16:19.043138 | controller -> localhost | |     .==o*+*.    |
2026-01-30 00:16:19.043159 | controller -> localhost | |      +o=+=..    |
2026-01-30 00:16:19.043180 | controller -> localhost | |     o Bo++      |
2026-01-30 00:16:19.043198 | controller -> localhost | |    . ..+oo+.    |
2026-01-30 00:16:19.043218 | controller -> localhost | +----[SHA256]-----+
2026-01-30 00:16:19.043263 | controller -> localhost | ok: Runtime: 0:00:00.099837
2026-01-30 00:16:19.049990 | 
2026-01-30 00:16:19.050073 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-30 00:16:19.080139 | controller | ok
2026-01-30 00:16:19.089915 | controller | included: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-30 00:16:19.099368 | 
2026-01-30 00:16:19.099433 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-30 00:16:19.123219 | controller | skipping: Conditional result was False
2026-01-30 00:16:19.129631 | 
2026-01-30 00:16:19.129694 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-30 00:16:19.574905 | controller | changed
2026-01-30 00:16:19.580538 | 
2026-01-30 00:16:19.580603 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-30 00:16:19.798962 | controller | ok
2026-01-30 00:16:19.809367 | 
2026-01-30 00:16:19.809551 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-30 00:16:20.466728 | controller | changed
2026-01-30 00:16:20.472674 | 
2026-01-30 00:16:20.472735 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-30 00:16:21.072352 | controller | changed
2026-01-30 00:16:21.081466 | 
2026-01-30 00:16:21.081596 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-30 00:16:21.106209 | controller | skipping: Conditional result was False
2026-01-30 00:16:21.113135 | 
2026-01-30 00:16:21.113202 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-30 00:16:21.544116 | controller -> localhost | changed
2026-01-30 00:16:21.571391 | 
2026-01-30 00:16:21.571566 | TASK [add-build-sshkey : Add back temp key]
2026-01-30 00:16:21.904783 | controller -> localhost | Identity added: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/bbe571555f204e6db59d8d7718ff960d_id_rsa (zuul-build-sshkey)
2026-01-30 00:16:21.905152 | controller -> localhost | ok: Runtime: 0:00:00.013972
2026-01-30 00:16:21.914988 | 
2026-01-30 00:16:21.915131 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-30 00:16:22.246732 | controller | ok
2026-01-30 00:16:22.252253 | 
2026-01-30 00:16:22.252332 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-30 00:16:22.287586 | controller | skipping: Conditional result was False
2026-01-30 00:16:22.299453 | 
2026-01-30 00:16:22.299520 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-30 00:16:22.336489 | controller | ok
2026-01-30 00:16:22.364569 | 
2026-01-30 00:16:22.364661 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-30 00:16:22.634317 | controller -> localhost | ok
2026-01-30 00:16:22.642853 | 
2026-01-30 00:16:22.642957 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-30 00:16:22.685181 | controller | ok
2026-01-30 00:16:22.699557 | controller | included: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-30 00:16:22.707857 | 
2026-01-30 00:16:22.707942 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-30 00:16:22.955937 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-30 00:16:22.956109 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/bbe571555f204e6db59d8d7718ff960d_id_ecdsa.
2026-01-30 00:16:22.956137 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/bbe571555f204e6db59d8d7718ff960d_id_ecdsa.pub.
2026-01-30 00:16:22.956164 | controller -> localhost | The key fingerprint is:
2026-01-30 00:16:22.956184 | controller -> localhost | SHA256:+32dc7WdoLxnaYZTD+/DyYnPcpQn67N38FOQZIz8m0Y zuul-build-sshkey
2026-01-30 00:16:22.956203 | controller -> localhost | The key's randomart image is:
2026-01-30 00:16:22.956222 | controller -> localhost | +---[ECDSA 521]---+
2026-01-30 00:16:22.956240 | controller -> localhost | |           . o   |
2026-01-30 00:16:22.956257 | controller -> localhost | |            o +  |
2026-01-30 00:16:22.956274 | controller -> localhost | |             + . |
2026-01-30 00:16:22.956291 | controller -> localhost | |              E  |
2026-01-30 00:16:22.956309 | controller -> localhost | |        S    . +.|
2026-01-30 00:16:22.956325 | controller -> localhost | |         .   +*o+|
2026-01-30 00:16:22.956342 | controller -> localhost | |        . . +.@*@|
2026-01-30 00:16:22.956359 | controller -> localhost | |         . * O=/B|
2026-01-30 00:16:22.956375 | controller -> localhost | |          ..OoBB*|
2026-01-30 00:16:22.956392 | controller -> localhost | +----[SHA256]-----+
2026-01-30 00:16:22.956437 | controller -> localhost | ok: Runtime: 0:00:00.008061
2026-01-30 00:16:22.963582 | 
2026-01-30 00:16:22.963642 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-30 00:16:22.983474 | controller | ok
2026-01-30 00:16:22.990483 | controller | included: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-30 00:16:22.998865 | 
2026-01-30 00:16:22.998926 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-30 00:16:23.012516 | controller | skipping: Conditional result was False
2026-01-30 00:16:23.019286 | 
2026-01-30 00:16:23.019347 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-30 00:16:23.289383 | controller | changed
2026-01-30 00:16:23.304130 | 
2026-01-30 00:16:23.304265 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-30 00:16:23.545882 | controller | ok
2026-01-30 00:16:23.554338 | 
2026-01-30 00:16:23.554420 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-30 00:16:24.241287 | controller | changed
2026-01-30 00:16:24.253674 | 
2026-01-30 00:16:24.253829 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-30 00:16:24.879889 | controller | changed
2026-01-30 00:16:24.885907 | 
2026-01-30 00:16:24.885976 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-30 00:16:24.920539 | controller | skipping: Conditional result was False
2026-01-30 00:16:24.934526 | 
2026-01-30 00:16:24.934711 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-30 00:16:25.205587 | controller -> localhost | changed
2026-01-30 00:16:25.230620 | 
2026-01-30 00:16:25.230782 | TASK [add-build-sshkey : Add back temp key]
2026-01-30 00:16:25.573268 | controller -> localhost | Identity added: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/bbe571555f204e6db59d8d7718ff960d_id_ecdsa (zuul-build-sshkey)
2026-01-30 00:16:25.573474 | controller -> localhost | ok: Runtime: 0:00:00.007130
2026-01-30 00:16:25.606412 | 
2026-01-30 00:16:25.606531 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-30 00:16:25.815207 | controller | ok
2026-01-30 00:16:25.827804 | 
2026-01-30 00:16:25.827956 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-30 00:16:25.873341 | controller | skipping: Conditional result was False
2026-01-30 00:16:25.884828 | 
2026-01-30 00:16:25.884888 | TASK [include_role : remove-zuul-sshkey]
2026-01-30 00:16:25.908179 | controller | skipping: Conditional result was False
2026-01-30 00:16:25.915127 | 
2026-01-30 00:16:25.915191 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-30 00:16:26.161501 | controller | ok: "logs"
2026-01-30 00:16:26.162356 | controller | ok: All items complete
2026-01-30 00:16:26.162454 | 
2026-01-30 00:16:26.338601 | controller | ok: "artifacts"
2026-01-30 00:16:26.525980 | controller | ok: "docs"
2026-01-30 00:16:26.543145 | 
2026-01-30 00:16:26.543265 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-30 00:16:26.788762 | controller | changed: "logs"
2026-01-30 00:16:26.987262 | controller | changed: "artifacts"
2026-01-30 00:16:27.178833 | controller | changed: "docs"
2026-01-30 00:16:27.230771 | 
2026-01-30 00:16:27.230893 | PLAY RECAP
2026-01-30 00:16:27.230955 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-30 00:16:27.231005 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-30 00:16:27.231065 | 
2026-01-30 00:16:27.346089 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-30 00:16:27.346956 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-30 00:16:27.884888 | 
2026-01-30 00:16:27.884991 | PLAY [all]
2026-01-30 00:16:27.906466 | 
2026-01-30 00:16:27.906540 | TASK [Install binary dependencies]
2026-01-30 00:16:27.983805 | controller | ok
2026-01-30 00:16:28.007771 | 
2026-01-30 00:16:28.007850 | TASK [bindep : Include find tasks]
2026-01-30 00:16:28.048795 | controller | ok
2026-01-30 00:16:28.059218 | controller | included: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-30 00:16:28.069250 | 
2026-01-30 00:16:28.069402 | TASK [bindep : Look for bindep.txt]
2026-01-30 00:16:28.428273 | controller | ok
2026-01-30 00:16:28.436158 | 
2026-01-30 00:16:28.436247 | TASK [bindep : Define bindep_file fact]
2026-01-30 00:16:28.461760 | controller | skipping: Conditional result was False
2026-01-30 00:16:28.470070 | 
2026-01-30 00:16:28.470161 | TASK [bindep : Look for other-requirements.txt]
2026-01-30 00:16:28.686945 | controller | ok
2026-01-30 00:16:28.704078 | 
2026-01-30 00:16:28.704280 | TASK [bindep : Define bindep_file fact]
2026-01-30 00:16:28.741621 | controller | skipping: Conditional result was False
2026-01-30 00:16:28.756361 | 
2026-01-30 00:16:28.756501 | TASK [bindep : Look for bindep fallback file]
2026-01-30 00:16:28.781719 | controller | skipping: Conditional result was False
2026-01-30 00:16:28.792327 | 
2026-01-30 00:16:28.792423 | TASK [bindep : Define bindep_file fact]
2026-01-30 00:16:28.827196 | controller | skipping: Conditional result was False
2026-01-30 00:16:28.836202 | 
2026-01-30 00:16:28.836311 | TASK [bindep : Include bindep tasks]
2026-01-30 00:16:28.871066 | controller | skipping: Conditional result was False
2026-01-30 00:16:28.879666 | 
2026-01-30 00:16:28.879752 | TASK [bindep : Include install tasks]
2026-01-30 00:16:28.915340 | controller | skipping: Conditional result was False
2026-01-30 00:16:28.928551 | 
2026-01-30 00:16:28.928682 | LOOP [bindep : Include package tasks]
2026-01-30 00:16:28.998334 | 
2026-01-30 00:16:28.998499 | TASK [Run test-setup role]
2026-01-30 00:16:29.022357 | controller | ok
2026-01-30 00:16:29.045121 | 
2026-01-30 00:16:29.045209 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-30 00:16:29.237471 | controller | ok
2026-01-30 00:16:29.243386 | 
2026-01-30 00:16:29.243445 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-30 00:16:29.787155 | controller | skipping: Conditional result was False
2026-01-30 00:16:29.846057 | 
2026-01-30 00:16:29.846156 | PLAY RECAP
2026-01-30 00:16:29.846209 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-30 00:16:29.846237 | 
2026-01-30 00:16:29.939559 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-30 00:16:29.941821 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-30 00:16:30.572010 | 
2026-01-30 00:16:30.572207 | PLAY [controller]
2026-01-30 00:16:30.594649 | 
2026-01-30 00:16:30.594733 | TASK [Create the /root directory]
2026-01-30 00:16:30.988932 | controller | ok
2026-01-30 00:16:31.001438 | 
2026-01-30 00:16:31.001589 | TASK [Install glibc-langpack-en]
2026-01-30 00:16:34.815828 | controller | ok: Nothing to do
2026-01-30 00:16:34.831510 | 
2026-01-30 00:16:34.831705 | TASK [Ensure controller directory exists]
2026-01-30 00:16:35.452300 | controller | changed
2026-01-30 00:16:35.464385 | 
2026-01-30 00:16:35.464524 | TASK [Install container runtime]
2026-01-30 00:16:35.543344 | controller | ok
2026-01-30 00:16:35.599622 | 
2026-01-30 00:16:35.599761 | LOOP [ensure-podman : Find distribution installation]
2026-01-30 00:16:35.642671 | controller | ok: "/var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-30 00:16:35.659149 | controller | included: /var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-30 00:16:35.673544 | 
2026-01-30 00:16:35.673708 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-30 00:17:44.146366 | controller | changed
2026-01-30 00:17:44.159174 | 
2026-01-30 00:17:44.159238 | TASK [ensure-podman : Fetch podman version]
2026-01-30 00:17:44.686127 | controller | Client:       Podman Engine
2026-01-30 00:17:44.721200 | controller | Version:      4.6.2
2026-01-30 00:17:44.721264 | controller | API Version:  4.6.2
2026-01-30 00:17:44.721367 | controller | Go Version:   go1.19.12
2026-01-30 00:17:44.721396 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-30 00:17:44.721409 | controller | OS/Arch:      linux/amd64
2026-01-30 00:17:45.191773 | controller | ok: Runtime: 0:00:00.186956
2026-01-30 00:17:45.208925 | 
2026-01-30 00:17:45.209113 | TASK [ensure-podman : Print podman version installed]
2026-01-30 00:17:45.243925 | Podman version: Client:       Podman Engine
2026-01-30 00:17:45.244115 | Version:      4.6.2
2026-01-30 00:17:45.244172 | API Version:  4.6.2
2026-01-30 00:17:45.244203 | Go Version:   go1.19.12
2026-01-30 00:17:45.244230 | Built:        Mon Aug 28 19:38:31 2023
2026-01-30 00:17:45.244256 | OS/Arch:      linux/amd64
2026-01-30 00:17:45.252133 | 
2026-01-30 00:17:45.252235 | TASK [ensure-podman : Validate podman engine]
2026-01-30 00:17:45.790524 | controller | skipping: Conditional result was False
2026-01-30 00:17:45.803995 | 
2026-01-30 00:17:45.804168 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-30 00:17:45.820653 | controller | skipping: Conditional result was False
2026-01-30 00:17:45.845060 | 
2026-01-30 00:17:45.845194 | TASK [Ensure python3.8 is present]
2026-01-30 00:17:45.861636 | controller | skipping: Conditional result was False
2026-01-30 00:17:45.874952 | 
2026-01-30 00:17:45.875137 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-30 00:17:45.902975 | controller | ok
2026-01-30 00:17:45.935673 | 
2026-01-30 00:17:45.935801 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-30 00:17:47.391636 | controller | ok: Nothing to do
2026-01-30 00:17:47.404847 | 
2026-01-30 00:17:47.404981 | TASK [our-ensure-python : Also install python3-devel]
2026-01-30 00:18:03.200319 | controller | changed
2026-01-30 00:18:03.224178 | 
2026-01-30 00:18:03.224306 | TASK [Run ensure-virtualenv role]
2026-01-30 00:18:03.248976 | controller | ok
2026-01-30 00:18:03.278581 | 
2026-01-30 00:18:03.278686 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-30 00:18:03.512418 | controller | /usr/bin/virtualenv
2026-01-30 00:18:03.814768 | controller | ok: Runtime: 0:00:00.005164
2026-01-30 00:18:03.821185 | 
2026-01-30 00:18:03.821252 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-30 00:18:03.856369 | controller | skipping: Conditional result was False
2026-01-30 00:18:03.856632 | controller | ok: All items complete
2026-01-30 00:18:03.856658 | 
2026-01-30 00:18:03.868991 | 
2026-01-30 00:18:03.869092 | TASK [Find the full path of the Python interpreter]
2026-01-30 00:18:04.143464 | controller | /usr/bin/python3
2026-01-30 00:18:04.435366 | controller | ok
2026-01-30 00:18:04.448778 | 
2026-01-30 00:18:04.448921 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-30 00:18:05.543756 | controller | created virtual environment CPython3.11.0.final.0-64 in 599ms
2026-01-30 00:18:05.582069 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-30 00:18:05.582098 | 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-30 00:18:05.582111 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-30 00:18:05.582124 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-30 00:18:06.005806 | controller | changed
2026-01-30 00:18:06.018575 | 
2026-01-30 00:18:06.018724 | TASK [Set selinux package]
2026-01-30 00:18:06.059171 | controller | ok
2026-01-30 00:18:06.070448 | 
2026-01-30 00:18:06.070577 | TASK [Set selinux package (Fedora)]
2026-01-30 00:18:06.131395 | controller | ok
2026-01-30 00:18:06.142621 | 
2026-01-30 00:18:06.142758 | TASK [Install selinux into virtualenv]
2026-01-30 00:18:31.659691 | controller | Collecting selinux-please-lie-to-me
2026-01-30 00:19:07.806458 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-30 00:19:08.131024 | controller | Collecting setuptools<50.0.0
2026-01-30 00:19:08.143027 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-30 00:19:08.180261 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.9 MB/s eta 0:00:00
2026-01-30 00:19:08.261138 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-30 00:19:08.261359 | controller |   Attempting uninstall: setuptools
2026-01-30 00:19:08.263787 | controller |     Found existing installation: setuptools 62.6.0
2026-01-30 00:19:08.323454 | controller |     Uninstalling setuptools-62.6.0:
2026-01-30 00:19:08.333379 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-30 00:19:08.694299 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-30 00:19:28.858832 | controller |
2026-01-30 00:19:28.938394 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-30 00:19:28.938447 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-30 00:19:29.224707 | controller | ok: Runtime: 0:01:22.550696
2026-01-30 00:19:29.237868 | 
2026-01-30 00:19:29.238005 | TASK [Install pytest-forked into virtualenv]
2026-01-30 00:20:18.995198 | controller | Collecting pytest-forked
2026-01-30 00:20:31.312048 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-30 00:20:31.372207 | controller | Collecting py
2026-01-30 00:20:31.377283 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-30 00:20:31.401814 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.5 MB/s eta 0:00:00
2026-01-30 00:20:31.510062 | controller | Collecting pytest>=3.10
2026-01-30 00:20:31.514883 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-30 00:20:31.533837 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 22.9 MB/s eta 0:00:00
2026-01-30 00:20:31.576990 | controller | Collecting iniconfig>=1.0.1
2026-01-30 00:20:31.580055 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-30 00:20:31.630499 | controller | Collecting packaging>=22
2026-01-30 00:20:31.633537 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-01-30 00:20:31.642688 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 12.0 MB/s eta 0:00:00
2026-01-30 00:20:31.679104 | controller | Collecting pluggy<2,>=1.5
2026-01-30 00:20:31.682303 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-30 00:20:31.734462 | controller | Collecting pygments>=2.7.2
2026-01-30 00:20:31.742837 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-30 00:20:31.763569 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 68.7 MB/s eta 0:00:00
2026-01-30 00:20:31.830504 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-30 00:20:32.871516 | 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-30 00:20:32.881262 | controller |
2026-01-30 00:20:32.959144 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-30 00:20:32.959183 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-30 00:20:33.336598 | controller | ok: Runtime: 0:01:03.484767
2026-01-30 00:20:33.344985 | 
2026-01-30 00:20:33.345089 | TASK [Update pip]
2026-01-30 00:20:33.839244 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-30 00:20:43.688188 | controller | Collecting pip
2026-01-30 00:20:55.887396 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-30 00:20:55.941315 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 36.4 MB/s eta 0:00:00
2026-01-30 00:20:56.006637 | controller | Installing collected packages: pip
2026-01-30 00:20:56.006791 | controller |   Attempting uninstall: pip
2026-01-30 00:20:56.008976 | controller |     Found existing installation: pip 22.2.2
2026-01-30 00:20:56.144978 | controller |     Uninstalling pip-22.2.2:
2026-01-30 00:20:56.161058 | controller |       Successfully uninstalled pip-22.2.2
2026-01-30 00:20:56.949242 | controller | Successfully installed pip-25.3
2026-01-30 00:20:57.398200 | controller | ok: Runtime: 0:00:23.474928
2026-01-30 00:20:57.410461 | 
2026-01-30 00:20:57.410592 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-30 00:20:57.636369 | controller | changed
2026-01-30 00:20:57.649648 | 
2026-01-30 00:20:57.649797 | TASK [Install ansible into virtualenv]
2026-01-30 00:20:58.171687 | controller | Processing ./src/github.com/ansible/ansible
2026-01-30 00:20:58.174973 | controller |   Installing build dependencies: started
2026-01-30 00:21:20.854933 | controller |   Installing build dependencies: finished with status 'done'
2026-01-30 00:21:20.856022 | controller |   Getting requirements to build wheel: started
2026-01-30 00:21:21.587083 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-30 00:21:21.588137 | controller |   Preparing metadata (pyproject.toml): started
2026-01-30 00:21:22.050196 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-30 00:21:22.055846 | 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-30 00:21:22.060923 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-30 00:21:22.239792 | controller | ERROR
2026-01-30 00:21:22.240005 | controller | {
2026-01-30 00:21:22.240126 | controller |   "delta": "0:00:24.231430",
2026-01-30 00:21:22.240172 | controller |   "end": "2026-01-30 00:21:22.124603",
2026-01-30 00:21:22.240210 | controller |   "msg": "non-zero return code",
2026-01-30 00:21:22.240262 | controller |   "rc": 1,
2026-01-30 00:21:22.240300 | controller |   "start": "2026-01-30 00:20:57.893173"
2026-01-30 00:21:22.240335 | controller | }
failure
2026-01-30 00:21:22.243076 | 
2026-01-30 00:21:22.243208 | PLAY RECAP
2026-01-30 00:21:22.243306 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-30 00:21:22.243354 | 
2026-01-30 00:21:22.368471 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-30 00:21:22.370377 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-30 00:21:23.002181 | 
2026-01-30 00:21:23.002286 | PLAY [all]
2026-01-30 00:21:23.023226 | 
2026-01-30 00:21:23.023317 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-30 00:21:23.286354 | controller | changed: non-zero return code
2026-01-30 00:21:23.299791 | 
2026-01-30 00:21:23.299962 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-30 00:21:23.317860 | controller | skipping: Conditional result was False
2026-01-30 00:21:23.332498 | 
2026-01-30 00:21:23.332659 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-30 00:21:23.365307 | 
2026-01-30 00:21:23.365568 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-30 00:21:23.396320 | 
2026-01-30 00:21:23.396571 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-30 00:21:23.413889 | controller | skipping: Conditional result was False
2026-01-30 00:21:23.430630 | 
2026-01-30 00:21:23.430782 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-30 00:21:23.466283 | 
2026-01-30 00:21:23.466473 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-30 00:21:23.491312 | controller | skipping: Conditional result was False
2026-01-30 00:21:23.500118 | 
2026-01-30 00:21:23.500211 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-30 00:21:23.525342 | controller | skipping: Conditional result was False
2026-01-30 00:21:23.533664 | 
2026-01-30 00:21:23.533755 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-30 00:21:23.558877 | controller | skipping: Conditional result was False
2026-01-30 00:21:23.595338 | 
2026-01-30 00:21:23.595420 | PLAY RECAP
2026-01-30 00:21:23.595470 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-30 00:21:23.595497 | 
2026-01-30 00:21:23.710239 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-30 00:21:23.711080 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-30 00:21:24.292430 | 
2026-01-30 00:21:24.292532 | PLAY [all:!appliance*]
2026-01-30 00:21:24.324644 | 
2026-01-30 00:21:24.324738 | TASK [unregister the node]
2026-01-30 00:21:24.855148 | controller | skipping: Conditional result was False
2026-01-30 00:21:24.867540 | 
2026-01-30 00:21:24.867705 | TASK [include_role : fetch-output]
2026-01-30 00:21:24.917674 | controller | ok
2026-01-30 00:21:24.950607 | 
2026-01-30 00:21:24.950713 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-30 00:21:25.026186 | controller | skipping: Conditional result was False
2026-01-30 00:21:25.040663 | 
2026-01-30 00:21:25.040821 | TASK [fetch-output : Set log path for single node]
2026-01-30 00:21:25.097466 | controller | ok
2026-01-30 00:21:25.109930 | 
2026-01-30 00:21:25.110117 | LOOP [fetch-output : Ensure local output dirs]
2026-01-30 00:21:25.490202 | controller -> localhost | ok: "/var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/logs"
2026-01-30 00:21:25.707747 | controller -> localhost | changed: "/var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/artifacts"
2026-01-30 00:21:25.922853 | controller -> localhost | changed: "/var/lib/zuul/builds/bbe571555f204e6db59d8d7718ff960d/work/docs"
2026-01-30 00:21:25.946128 | 
2026-01-30 00:21:25.946239 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-30 00:21:26.575229 | controller | changed:
2026-01-30 00:21:26.575577 | controller | .d..t...... ./
2026-01-30 00:21:26.575638 | controller | cd+++++++++ controller/
2026-01-30 00:21:26.575710 | controller | changed: All items complete
2026-01-30 00:21:26.575756 | 
2026-01-30 00:21:27.070778 | controller | changed: .d..t...... ./
2026-01-30 00:21:27.575952 | controller | changed: .d..t...... ./
2026-01-30 00:21:27.590354 | 
2026-01-30 00:21:27.590475 | TASK [include_role : fetch-output-openshift]
2026-01-30 00:21:27.604605 | controller | skipping: Conditional result was False
2026-01-30 00:21:27.612390 | 
2026-01-30 00:21:27.612467 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-30 00:21:27.636242 | controller | skipping: Conditional result was False
2026-01-30 00:21:27.643726 | controller | skipping: Conditional result was False
2026-01-30 00:21:27.674997 | 
2026-01-30 00:21:27.675126 | PLAY [localhost]
2026-01-30 00:21:27.687140 | 
2026-01-30 00:21:27.687210 | TASK [Run Zuul manifest role]
2026-01-30 00:21:27.705272 | localhost | ok
2026-01-30 00:21:27.720199 | 
2026-01-30 00:21:27.720317 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-30 00:21:28.074160 | localhost | changed
2026-01-30 00:21:28.079124 | 
2026-01-30 00:21:28.079200 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-30 00:21:28.107620 | localhost | ok
2026-01-30 00:21:28.115543 | 
2026-01-30 00:21:28.115602 | TASK [Set zuul-log-path fact]
2026-01-30 00:21:28.133079 | localhost | ok
2026-01-30 00:21:28.146926 | 
2026-01-30 00:21:28.146992 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-30 00:21:28.176936 | localhost | ok
2026-01-30 00:21:28.184747 | 
2026-01-30 00:21:28.184809 | LOOP [Run upload-logs-swift role]
2026-01-30 00:21:28.209256 | localhost | Output suppressed because no_log was given
2026-01-30 00:21:28.238322 | 
2026-01-30 00:21:28.238451 | TASK [Set zuul-log-path fact]
2026-01-30 00:21:28.262596 | localhost | skipping: Conditional result was False
2026-01-30 00:21:28.267850 | 
2026-01-30 00:21:28.267928 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-30 00:21:28.668590 | localhost -> localhost | ok: Runtime: 0:00:00.008955
2026-01-30 00:21:28.675174 | 
2026-01-30 00:21:28.675306 | TASK [upload-logs-swift : Upload logs to swift]