2026-01-21 00:06:31.188121 | Job console starting...
2026-01-21 00:06:31.195139 | Updating repositories
2026-01-21 00:06:31.330884 | Preparing job workspace
2026-01-21 00:06:43.781807 | Running Ansible setup...
2026-01-21 00:06:49.000317 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:06:49.690781 | 
2026-01-21 00:06:49.690899 | PLAY [localhost]
2026-01-21 00:06:49.698961 | 
2026-01-21 00:06:49.699038 | TASK [Gathering Facts]
2026-01-21 00:06:50.761157 | localhost | ok
2026-01-21 00:06:50.774257 | 
2026-01-21 00:06:50.774368 | TASK [Setup log path fact]
2026-01-21 00:06:50.791223 | localhost | ok
2026-01-21 00:06:50.805060 | 
2026-01-21 00:06:50.805179 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:06:50.832293 | localhost | ok
2026-01-21 00:06:50.840961 | 
2026-01-21 00:06:50.841102 | TASK [emit-job-header : Print job information]
2026-01-21 00:06:50.878702 | # Job Information
2026-01-21 00:06:50.878854 | Ansible Version: 2.15.12
2026-01-21 00:06:50.878893 | Job: ansible-test-sanity-docker-milestone
2026-01-21 00:06:50.878915 | Pipeline: periodic
2026-01-21 00:06:50.878935 | Executor: ze04.softwarefactory-project.io
2026-01-21 00:06:50.878954 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-21 00:06:50.878975 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/2be/ansible/2be7e86594d3471a8a0f8d8b36142b91/
2026-01-21 00:06:50.878995 | Event ID: 08cfdb9560914df89453f509f8798614
2026-01-21 00:06:50.882694 | 
2026-01-21 00:06:50.882756 | LOOP [emit-job-header : Print node information]
2026-01-21 00:06:51.004020 | localhost | ok:
2026-01-21 00:06:51.004241 | localhost | # Node Information
2026-01-21 00:06:51.004270 | localhost | Inventory Hostname: controller
2026-01-21 00:06:51.004289 | localhost | Hostname: np0005589719
2026-01-21 00:06:51.004308 | localhost | Username: zuul
2026-01-21 00:06:51.004329 | localhost | Distro: Fedora 37
2026-01-21 00:06:51.004347 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-21 00:06:51.004364 | localhost | Region: ca-ymq-1
2026-01-21 00:06:51.004380 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-21 00:06:51.004397 | localhost | Product Name: OpenStack Nova
2026-01-21 00:06:51.004414 | localhost | Interface IP: 162.253.55.74
2026-01-21 00:06:51.026177 | 
2026-01-21 00:06:51.026317 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-21 00:06:51.395450 | localhost -> localhost | changed
2026-01-21 00:06:51.405100 | 
2026-01-21 00:06:51.405234 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-21 00:06:52.446073 | localhost -> localhost | changed
2026-01-21 00:06:52.491095 | 
2026-01-21 00:06:52.491334 | PLAY [all:!appliance*]
2026-01-21 00:06:52.518087 | 
2026-01-21 00:06:52.518227 | TASK [include_role : start-zuul-console]
2026-01-21 00:06:52.551093 | controller | ok
2026-01-21 00:06:52.580649 | 
2026-01-21 00:06:52.580784 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-21 00:06:52.953450 | controller | ok
2026-01-21 00:06:52.975156 | 
2026-01-21 00:06:52.975275 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-21 00:07:16.754406 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-21 00:07:16.763280 | 
2026-01-21 00:07:16.763366 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-21 00:07:17.305236 | controller | skipping: Conditional result was False
2026-01-21 00:07:17.321200 | 
2026-01-21 00:07:17.321364 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-21 00:07:17.349033 | controller | skipping: Conditional result was False
2026-01-21 00:07:17.365533 | 
2026-01-21 00:07:17.365791 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-21 00:07:17.392498 | controller | skipping: Conditional result was False
2026-01-21 00:07:17.411465 | 
2026-01-21 00:07:17.411882 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-21 00:07:17.462643 | controller | skipping: Conditional result was False
2026-01-21 00:07:17.480302 | 
2026-01-21 00:07:17.480446 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-21 00:07:17.505964 | controller | skipping: Conditional result was False
2026-01-21 00:07:17.515189 | 
2026-01-21 00:07:17.515300 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-21 00:07:17.540418 | controller | skipping: Conditional result was False
2026-01-21 00:07:17.554101 | 
2026-01-21 00:07:17.554216 | TASK [Disable Fedora Modular]
2026-01-21 00:07:17.916146 | controller | changed
2026-01-21 00:07:17.930978 | 
2026-01-21 00:07:17.931107 | TASK [Enable EPEL]
2026-01-21 00:07:17.966042 | controller | skipping: Conditional result was False
2026-01-21 00:07:17.977236 | 
2026-01-21 00:07:17.977417 | TASK [Register the RHEL node]
2026-01-21 00:07:18.532494 | 
2026-01-21 00:07:18.532741 | TASK [Show the subscription-manager status]
2026-01-21 00:07:19.085407 | controller | skipping: Conditional result was False
2026-01-21 00:07:19.094630 | 
2026-01-21 00:07:19.094764 | TASK [Enable EPEL on RHEL]
2026-01-21 00:07:19.658563 | controller | skipping: Conditional result was False
2026-01-21 00:07:19.665656 | 
2026-01-21 00:07:19.665768 | TASK [Install git and tox]
2026-01-21 00:08:19.626274 | controller | changed
2026-01-21 00:08:19.640941 | 
2026-01-21 00:08:19.641083 | TASK [include_role : prepare-workspace]
2026-01-21 00:08:19.670603 | controller | ok
2026-01-21 00:08:19.751624 | 
2026-01-21 00:08:19.751805 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-21 00:08:20.005408 | controller | ok
2026-01-21 00:08:20.043037 | 
2026-01-21 00:08:20.043335 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-21 00:08:33.528202 | controller | Output suppressed because no_log was given
2026-01-21 00:08:33.541153 | 
2026-01-21 00:08:33.541262 | TASK [include_role : prepare-workspace-openshift]
2026-01-21 00:08:33.587484 | controller | skipping: Conditional result was False
2026-01-21 00:08:33.614977 | 
2026-01-21 00:08:33.615090 | PLAY [all:!appliance]
2026-01-21 00:08:33.636219 | 
2026-01-21 00:08:33.636341 | TASK [Run add-build-sshkey role (RSA)]
2026-01-21 00:08:33.680965 | controller | ok
2026-01-21 00:08:33.707079 | 
2026-01-21 00:08:33.707243 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:08:34.011660 | controller -> localhost | ok
2026-01-21 00:08:34.021355 | 
2026-01-21 00:08:34.021510 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:08:34.054283 | controller | ok
2026-01-21 00:08:34.073894 | controller | included: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:08:34.101162 | 
2026-01-21 00:08:34.101755 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:08:34.861371 | controller -> localhost | Generating public/private rsa key pair.
2026-01-21 00:08:34.861602 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/2be7e86594d3471a8a0f8d8b36142b91_id_rsa.
2026-01-21 00:08:34.861639 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/2be7e86594d3471a8a0f8d8b36142b91_id_rsa.pub.
2026-01-21 00:08:34.861669 | controller -> localhost | The key fingerprint is:
2026-01-21 00:08:34.861721 | controller -> localhost | SHA256:GpPSFWkG1Ww2C5T1tvOODfuV1Kpd5Z4mR37703GEigc zuul-build-sshkey
2026-01-21 00:08:34.861749 | controller -> localhost | The key's randomart image is:
2026-01-21 00:08:34.861776 | controller -> localhost | +---[RSA 2048]----+
2026-01-21 00:08:34.861800 | controller -> localhost | |      .++*.      |
2026-01-21 00:08:34.861826 | controller -> localhost | |        *.*.     |
2026-01-21 00:08:34.861849 | controller -> localhost | |       o.+ oo  . |
2026-01-21 00:08:34.861873 | controller -> localhost | |     . o  E. .. o|
2026-01-21 00:08:34.861910 | controller -> localhost | |    . = S  oo. oo|
2026-01-21 00:08:34.861941 | controller -> localhost | |     . +  . oo.=+|
2026-01-21 00:08:34.861978 | controller -> localhost | |      .    .. =.B|
2026-01-21 00:08:34.862003 | controller -> localhost | |             X O+|
2026-01-21 00:08:34.862025 | controller -> localhost | |            +.OoB|
2026-01-21 00:08:34.862050 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:08:34.862111 | controller -> localhost | ok: Runtime: 0:00:00.049541
2026-01-21 00:08:34.875043 | 
2026-01-21 00:08:34.875209 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:08:34.917926 | controller | ok
2026-01-21 00:08:34.930294 | controller | included: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:08:34.941724 | 
2026-01-21 00:08:34.941856 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:08:34.987575 | controller | skipping: Conditional result was False
2026-01-21 00:08:34.998364 | 
2026-01-21 00:08:34.998493 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:08:35.536164 | controller | changed
2026-01-21 00:08:35.543943 | 
2026-01-21 00:08:35.544038 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:08:35.778412 | controller | ok
2026-01-21 00:08:35.821206 | 
2026-01-21 00:08:35.821321 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:08:36.487633 | controller | changed
2026-01-21 00:08:36.496773 | 
2026-01-21 00:08:36.496881 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:08:37.114121 | controller | changed
2026-01-21 00:08:37.130563 | 
2026-01-21 00:08:37.130869 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:08:37.158231 | controller | skipping: Conditional result was False
2026-01-21 00:08:37.166218 | 
2026-01-21 00:08:37.166340 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:08:37.580937 | controller -> localhost | changed
2026-01-21 00:08:37.598477 | 
2026-01-21 00:08:37.598582 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:08:37.909849 | controller -> localhost | Identity added: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/2be7e86594d3471a8a0f8d8b36142b91_id_rsa (zuul-build-sshkey)
2026-01-21 00:08:37.910096 | controller -> localhost | ok: Runtime: 0:00:00.008339
2026-01-21 00:08:37.922946 | 
2026-01-21 00:08:37.923072 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:08:38.257670 | controller | ok
2026-01-21 00:08:38.263438 | 
2026-01-21 00:08:38.263510 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:08:38.289629 | controller | skipping: Conditional result was False
2026-01-21 00:08:38.319671 | 
2026-01-21 00:08:38.319819 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-21 00:08:38.354274 | controller | ok
2026-01-21 00:08:38.373956 | 
2026-01-21 00:08:38.374068 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-21 00:08:38.667797 | controller -> localhost | ok
2026-01-21 00:08:38.675102 | 
2026-01-21 00:08:38.675252 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-21 00:08:38.723374 | controller | ok
2026-01-21 00:08:38.740947 | controller | included: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-21 00:08:38.752854 | 
2026-01-21 00:08:38.753004 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-21 00:08:39.098708 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-21 00:08:39.098972 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/2be7e86594d3471a8a0f8d8b36142b91_id_ecdsa.
2026-01-21 00:08:39.099005 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/2be7e86594d3471a8a0f8d8b36142b91_id_ecdsa.pub.
2026-01-21 00:08:39.099053 | controller -> localhost | The key fingerprint is:
2026-01-21 00:08:39.099077 | controller -> localhost | SHA256:97/HcTLIlUNL+nLvx8Lh5wVSkVZ0GTN85ZLuX5jWjvY zuul-build-sshkey
2026-01-21 00:08:39.099099 | controller -> localhost | The key's randomart image is:
2026-01-21 00:08:39.099118 | controller -> localhost | +---[ECDSA 521]---+
2026-01-21 00:08:39.099136 | controller -> localhost | |              oBO|
2026-01-21 00:08:39.099155 | controller -> localhost | |              =*=|
2026-01-21 00:08:39.099172 | controller -> localhost | |             =+oo|
2026-01-21 00:08:39.099191 | controller -> localhost | |            .o=. |
2026-01-21 00:08:39.099209 | controller -> localhost | |        S ...+o. |
2026-01-21 00:08:39.099229 | controller -> localhost | |         . .+o**.|
2026-01-21 00:08:39.099248 | controller -> localhost | |            .==B*|
2026-01-21 00:08:39.099267 | controller -> localhost | |             o=+X|
2026-01-21 00:08:39.099287 | controller -> localhost | |             .+OE|
2026-01-21 00:08:39.099306 | controller -> localhost | +----[SHA256]-----+
2026-01-21 00:08:39.099362 | controller -> localhost | ok: Runtime: 0:00:00.012907
2026-01-21 00:08:39.107394 | 
2026-01-21 00:08:39.107509 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-21 00:08:39.139434 | controller | ok
2026-01-21 00:08:39.148514 | controller | included: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-21 00:08:39.159059 | 
2026-01-21 00:08:39.159179 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-21 00:08:39.184270 | controller | skipping: Conditional result was False
2026-01-21 00:08:39.191066 | 
2026-01-21 00:08:39.191140 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-21 00:08:39.462708 | controller | changed
2026-01-21 00:08:39.472047 | 
2026-01-21 00:08:39.472154 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-21 00:08:39.680285 | controller | ok
2026-01-21 00:08:39.689900 | 
2026-01-21 00:08:39.690059 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-21 00:08:40.265238 | controller | changed
2026-01-21 00:08:40.273135 | 
2026-01-21 00:08:40.273279 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-21 00:08:40.871075 | controller | changed
2026-01-21 00:08:40.879881 | 
2026-01-21 00:08:40.880030 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-21 00:08:40.897417 | controller | skipping: Conditional result was False
2026-01-21 00:08:40.908829 | 
2026-01-21 00:08:40.908988 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-21 00:08:41.171662 | controller -> localhost | changed
2026-01-21 00:08:41.186118 | 
2026-01-21 00:08:41.186233 | TASK [add-build-sshkey : Add back temp key]
2026-01-21 00:08:41.467499 | controller -> localhost | Identity added: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/2be7e86594d3471a8a0f8d8b36142b91_id_ecdsa (zuul-build-sshkey)
2026-01-21 00:08:41.467736 | controller -> localhost | ok: Runtime: 0:00:00.010077
2026-01-21 00:08:41.476361 | 
2026-01-21 00:08:41.476478 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-21 00:08:41.685599 | controller | ok
2026-01-21 00:08:41.694193 | 
2026-01-21 00:08:41.694318 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-21 00:08:41.731107 | controller | skipping: Conditional result was False
2026-01-21 00:08:41.746183 | 
2026-01-21 00:08:41.746295 | TASK [include_role : remove-zuul-sshkey]
2026-01-21 00:08:41.771549 | controller | skipping: Conditional result was False
2026-01-21 00:08:41.778537 | 
2026-01-21 00:08:41.778625 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-21 00:08:42.008456 | controller | ok: "logs"
2026-01-21 00:08:42.009081 | controller | ok: All items complete
2026-01-21 00:08:42.009155 | 
2026-01-21 00:08:42.188520 | controller | ok: "artifacts"
2026-01-21 00:08:42.375367 | controller | ok: "docs"
2026-01-21 00:08:42.385352 | 
2026-01-21 00:08:42.385504 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-21 00:08:42.624356 | controller | changed: "logs"
2026-01-21 00:08:42.806095 | controller | changed: "artifacts"
2026-01-21 00:08:42.989249 | controller | changed: "docs"
2026-01-21 00:08:43.031411 | 
2026-01-21 00:08:43.031523 | PLAY RECAP
2026-01-21 00:08:43.031568 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-21 00:08:43.031594 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-21 00:08:43.031612 | 
2026-01-21 00:08:43.158087 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-21 00:08:43.291379 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:08:44.155469 | 
2026-01-21 00:08:44.155624 | PLAY [all]
2026-01-21 00:08:44.191821 | 
2026-01-21 00:08:44.191996 | TASK [Install binary dependencies]
2026-01-21 00:08:44.254846 | controller | ok
2026-01-21 00:08:44.279019 | 
2026-01-21 00:08:44.279185 | TASK [bindep : Include find tasks]
2026-01-21 00:08:44.311084 | controller | ok
2026-01-21 00:08:44.319848 | controller | included: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-21 00:08:44.326894 | 
2026-01-21 00:08:44.327006 | TASK [bindep : Look for bindep.txt]
2026-01-21 00:08:44.741842 | controller | ok
2026-01-21 00:08:44.758458 | 
2026-01-21 00:08:44.758580 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:08:44.787443 | controller | skipping: Conditional result was False
2026-01-21 00:08:44.796407 | 
2026-01-21 00:08:44.796528 | TASK [bindep : Look for other-requirements.txt]
2026-01-21 00:08:45.046121 | controller | ok
2026-01-21 00:08:45.054453 | 
2026-01-21 00:08:45.054581 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:08:45.079635 | controller | skipping: Conditional result was False
2026-01-21 00:08:45.088373 | 
2026-01-21 00:08:45.088505 | TASK [bindep : Look for bindep fallback file]
2026-01-21 00:08:45.127878 | controller | skipping: Conditional result was False
2026-01-21 00:08:45.137129 | 
2026-01-21 00:08:45.137262 | TASK [bindep : Define bindep_file fact]
2026-01-21 00:08:45.175243 | controller | skipping: Conditional result was False
2026-01-21 00:08:45.183281 | 
2026-01-21 00:08:45.183402 | TASK [bindep : Include bindep tasks]
2026-01-21 00:08:45.212901 | controller | skipping: Conditional result was False
2026-01-21 00:08:45.225729 | 
2026-01-21 00:08:45.225946 | TASK [bindep : Include install tasks]
2026-01-21 00:08:45.293262 | controller | skipping: Conditional result was False
2026-01-21 00:08:45.305086 | 
2026-01-21 00:08:45.305233 | LOOP [bindep : Include package tasks]
2026-01-21 00:08:45.408628 | 
2026-01-21 00:08:45.408825 | TASK [Run test-setup role]
2026-01-21 00:08:45.457523 | controller | ok
2026-01-21 00:08:45.502545 | 
2026-01-21 00:08:45.502693 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-21 00:08:45.716344 | controller | ok
2026-01-21 00:08:45.742445 | 
2026-01-21 00:08:45.742567 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-21 00:08:46.312339 | controller | skipping: Conditional result was False
2026-01-21 00:08:46.353718 | 
2026-01-21 00:08:46.353884 | PLAY RECAP
2026-01-21 00:08:46.353943 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:08:46.353965 | 
2026-01-21 00:08:46.535705 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-21 00:08:46.536879 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:08:47.419531 | 
2026-01-21 00:08:47.419710 | PLAY [controller]
2026-01-21 00:08:47.444952 | 
2026-01-21 00:08:47.445151 | TASK [Create the /root directory]
2026-01-21 00:08:47.901311 | controller | ok
2026-01-21 00:08:47.926100 | 
2026-01-21 00:08:47.926311 | TASK [Install glibc-langpack-en]
2026-01-21 00:08:52.023786 | controller | ok: Nothing to do
2026-01-21 00:08:52.031191 | 
2026-01-21 00:08:52.031307 | TASK [Ensure controller directory exists]
2026-01-21 00:08:52.293941 | controller | changed
2026-01-21 00:08:52.299445 | 
2026-01-21 00:08:52.299510 | TASK [Install container runtime]
2026-01-21 00:08:52.425274 | controller | ok
2026-01-21 00:08:52.540638 | 
2026-01-21 00:08:52.540833 | LOOP [ensure-podman : Find distribution installation]
2026-01-21 00:08:52.597503 | controller | ok: "/var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-21 00:08:52.610132 | controller | included: /var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-21 00:08:52.629031 | 
2026-01-21 00:08:52.629495 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-21 00:09:58.813512 | controller | changed
2026-01-21 00:09:58.823319 | 
2026-01-21 00:09:58.823462 | TASK [ensure-podman : Fetch podman version]
2026-01-21 00:09:59.356679 | controller | Client:       Podman Engine
2026-01-21 00:09:59.386532 | controller | Version:      4.6.2
2026-01-21 00:09:59.386583 | controller | API Version:  4.6.2
2026-01-21 00:09:59.386597 | controller | Go Version:   go1.19.12
2026-01-21 00:09:59.386621 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:09:59.386634 | controller | OS/Arch:      linux/amd64
2026-01-21 00:09:59.866513 | controller | ok: Runtime: 0:00:00.196326
2026-01-21 00:09:59.876168 | 
2026-01-21 00:09:59.876326 | TASK [ensure-podman : Print podman version installed]
2026-01-21 00:09:59.910659 | Podman version: Client:       Podman Engine
2026-01-21 00:09:59.910913 | Version:      4.6.2
2026-01-21 00:09:59.910948 | API Version:  4.6.2
2026-01-21 00:09:59.910969 | Go Version:   go1.19.12
2026-01-21 00:09:59.910988 | Built:        Mon Aug 28 19:38:31 2023
2026-01-21 00:09:59.911007 | OS/Arch:      linux/amd64
2026-01-21 00:09:59.917536 | 
2026-01-21 00:09:59.917620 | TASK [ensure-podman : Validate podman engine]
2026-01-21 00:10:00.460592 | controller | skipping: Conditional result was False
2026-01-21 00:10:00.471175 | 
2026-01-21 00:10:00.471281 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-21 00:10:00.487477 | controller | skipping: Conditional result was False
2026-01-21 00:10:00.506064 | 
2026-01-21 00:10:00.506201 | TASK [Ensure python3.8 is present]
2026-01-21 00:10:00.522738 | controller | skipping: Conditional result was False
2026-01-21 00:10:00.532611 | 
2026-01-21 00:10:00.532730 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-21 00:10:00.555379 | controller | ok
2026-01-21 00:10:00.581425 | 
2026-01-21 00:10:00.581531 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-21 00:10:01.973651 | controller | ok: Nothing to do
2026-01-21 00:10:01.982739 | 
2026-01-21 00:10:01.982994 | TASK [our-ensure-python : Also install python3-devel]
2026-01-21 00:10:12.482489 | controller | changed
2026-01-21 00:10:12.499787 | 
2026-01-21 00:10:12.499899 | TASK [Run ensure-virtualenv role]
2026-01-21 00:10:12.532496 | controller | ok
2026-01-21 00:10:12.579429 | 
2026-01-21 00:10:12.579567 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-21 00:10:12.844033 | controller | /usr/bin/virtualenv
2026-01-21 00:10:13.149916 | controller | ok: Runtime: 0:00:00.005441
2026-01-21 00:10:13.155979 | 
2026-01-21 00:10:13.156042 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-21 00:10:13.175768 | controller | skipping: Conditional result was False
2026-01-21 00:10:13.176020 | controller | ok: All items complete
2026-01-21 00:10:13.176048 | 
2026-01-21 00:10:13.196296 | 
2026-01-21 00:10:13.196423 | TASK [Find the full path of the Python interpreter]
2026-01-21 00:10:13.467118 | controller | /usr/bin/python3
2026-01-21 00:10:13.761247 | controller | ok
2026-01-21 00:10:13.768044 | 
2026-01-21 00:10:13.768173 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-21 00:10:14.543452 | controller | created virtual environment CPython3.11.0.final.0-64 in 463ms
2026-01-21 00:10:14.559997 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-21 00:10:14.560031 | 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-21 00:10:14.560040 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-21 00:10:14.560082 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-21 00:10:14.809191 | controller | changed
2026-01-21 00:10:14.816492 | 
2026-01-21 00:10:14.816592 | TASK [Set selinux package]
2026-01-21 00:10:14.838325 | controller | ok
2026-01-21 00:10:14.844906 | 
2026-01-21 00:10:14.845032 | TASK [Set selinux package (Fedora)]
2026-01-21 00:10:14.882436 | controller | ok
2026-01-21 00:10:14.890052 | 
2026-01-21 00:10:14.890185 | TASK [Install selinux into virtualenv]
2026-01-21 00:10:26.390710 | controller | Collecting selinux-please-lie-to-me
2026-01-21 00:10:38.650739 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-21 00:10:38.955821 | controller | Collecting setuptools<50.0.0
2026-01-21 00:10:38.964574 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-21 00:10:39.016336 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.3 MB/s eta 0:00:00
2026-01-21 00:10:39.099058 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-21 00:10:39.099285 | controller |   Attempting uninstall: setuptools
2026-01-21 00:10:39.101634 | controller |     Found existing installation: setuptools 62.6.0
2026-01-21 00:10:39.160789 | controller |     Uninstalling setuptools-62.6.0:
2026-01-21 00:10:39.168426 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-21 00:10:39.507520 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-21 00:10:51.018140 | controller |
2026-01-21 00:10:51.096962 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:10:51.097137 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:10:51.440232 | controller | ok: Runtime: 0:00:35.978446
2026-01-21 00:10:51.453313 | 
2026-01-21 00:10:51.453434 | TASK [Install pytest-forked into virtualenv]
2026-01-21 00:11:03.267358 | controller | Collecting pytest-forked
2026-01-21 00:11:15.517375 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-21 00:11:15.562769 | controller | Collecting py
2026-01-21 00:11:15.573342 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-21 00:11:15.595298 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.2 MB/s eta 0:00:00
2026-01-21 00:11:15.703281 | controller | Collecting pytest>=3.10
2026-01-21 00:11:15.717800 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-21 00:11:15.750475 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 12.5 MB/s eta 0:00:00
2026-01-21 00:11:15.788873 | controller | Collecting iniconfig>=1.0.1
2026-01-21 00:11:15.793691 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-21 00:11:15.835978 | controller | Collecting packaging>=22
2026-01-21 00:11:15.841815 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-21 00:11:15.847569 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 20.0 MB/s eta 0:00:00
2026-01-21 00:11:15.887231 | controller | Collecting pluggy<2,>=1.5
2026-01-21 00:11:15.894650 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-21 00:11:15.941291 | controller | Collecting pygments>=2.7.2
2026-01-21 00:11:15.949548 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-21 00:11:15.993074 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 31.0 MB/s eta 0:00:00
2026-01-21 00:11:16.062313 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-21 00:11:17.160097 | 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
2026-01-21 00:11:17.169150 | controller |
2026-01-21 00:11:17.247928 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-21 00:11:17.247973 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-21 00:11:17.510977 | controller | ok: Runtime: 0:00:25.577332
2026-01-21 00:11:17.518645 | 
2026-01-21 00:11:17.518857 | TASK [Update pip]
2026-01-21 00:11:18.029850 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-21 00:11:25.342954 | controller | Collecting pip
2026-01-21 00:11:37.530326 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-21 00:11:37.604699 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 25.6 MB/s eta 0:00:00
2026-01-21 00:11:37.667322 | controller | Installing collected packages: pip
2026-01-21 00:11:37.667470 | controller |   Attempting uninstall: pip
2026-01-21 00:11:37.669587 | controller |     Found existing installation: pip 22.2.2
2026-01-21 00:11:37.803997 | controller |     Uninstalling pip-22.2.2:
2026-01-21 00:11:37.818546 | controller |       Successfully uninstalled pip-22.2.2
2026-01-21 00:11:38.621671 | controller | Successfully installed pip-25.3
2026-01-21 00:11:39.080213 | controller | ok: Runtime: 0:00:20.960989
2026-01-21 00:11:39.087258 | 
2026-01-21 00:11:39.087333 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-21 00:11:39.290079 | controller | changed
2026-01-21 00:11:39.296096 | 
2026-01-21 00:11:39.296188 | TASK [Install ansible into virtualenv]
2026-01-21 00:11:39.778561 | controller | Processing ./src/github.com/ansible/ansible
2026-01-21 00:11:39.781942 | controller |   Installing build dependencies: started
2026-01-21 00:12:02.474717 | controller |   Installing build dependencies: finished with status 'done'
2026-01-21 00:12:02.475294 | controller |   Getting requirements to build wheel: started
2026-01-21 00:12:03.197533 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-21 00:12:03.198405 | controller |   Preparing metadata (pyproject.toml): started
2026-01-21 00:12:03.651129 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-21 00:12:03.655887 | 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-21 00:12:03.659373 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-21 00:12:03.839358 | controller | ERROR
2026-01-21 00:12:03.839592 | controller | {
2026-01-21 00:12:03.839633 | controller |   "delta": "0:00:24.230488",
2026-01-21 00:12:03.839656 | controller |   "end": "2026-01-21 00:12:03.730629",
2026-01-21 00:12:03.839674 | controller |   "msg": "non-zero return code",
2026-01-21 00:12:03.839752 | controller |   "rc": 1,
2026-01-21 00:12:03.839772 | controller |   "start": "2026-01-21 00:11:39.500141"
2026-01-21 00:12:03.839789 | controller | }
failure
2026-01-21 00:12:03.841394 | 
2026-01-21 00:12:03.841443 | PLAY RECAP
2026-01-21 00:12:03.841486 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-21 00:12:03.841507 | 
2026-01-21 00:12:03.958189 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-21 00:12:03.959363 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:12:04.600040 | 
2026-01-21 00:12:04.600195 | PLAY [all]
2026-01-21 00:12:04.624361 | 
2026-01-21 00:12:04.624504 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-21 00:12:04.894998 | controller | changed: non-zero return code
2026-01-21 00:12:04.902670 | 
2026-01-21 00:12:04.902852 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-21 00:12:04.917689 | controller | skipping: Conditional result was False
2026-01-21 00:12:04.926293 | 
2026-01-21 00:12:04.926407 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-21 00:12:04.961578 | 
2026-01-21 00:12:04.961811 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-21 00:12:04.992624 | 
2026-01-21 00:12:04.992823 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-21 00:12:05.007785 | controller | skipping: Conditional result was False
2026-01-21 00:12:05.015789 | 
2026-01-21 00:12:05.015886 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-21 00:12:05.037857 | 
2026-01-21 00:12:05.038082 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-21 00:12:05.052864 | controller | skipping: Conditional result was False
2026-01-21 00:12:05.060097 | 
2026-01-21 00:12:05.060180 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-21 00:12:05.074212 | controller | skipping: Conditional result was False
2026-01-21 00:12:05.082738 | 
2026-01-21 00:12:05.082866 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-21 00:12:05.098475 | controller | skipping: Conditional result was False
2026-01-21 00:12:05.126342 | 
2026-01-21 00:12:05.126443 | PLAY RECAP
2026-01-21 00:12:05.126486 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-21 00:12:05.126507 | 
2026-01-21 00:12:05.242380 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-21 00:12:05.243357 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-21 00:12:05.883817 | 
2026-01-21 00:12:05.883932 | PLAY [all:!appliance*]
2026-01-21 00:12:05.905989 | 
2026-01-21 00:12:05.906105 | TASK [unregister the node]
2026-01-21 00:12:06.437141 | controller | skipping: Conditional result was False
2026-01-21 00:12:06.443827 | 
2026-01-21 00:12:06.443934 | TASK [include_role : fetch-output]
2026-01-21 00:12:06.474402 | controller | ok
2026-01-21 00:12:06.496297 | 
2026-01-21 00:12:06.496411 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-21 00:12:06.540877 | controller | skipping: Conditional result was False
2026-01-21 00:12:06.550655 | 
2026-01-21 00:12:06.550811 | TASK [fetch-output : Set log path for single node]
2026-01-21 00:12:06.583986 | controller | ok
2026-01-21 00:12:06.592164 | 
2026-01-21 00:12:06.592284 | LOOP [fetch-output : Ensure local output dirs]
2026-01-21 00:12:07.024496 | controller -> localhost | ok: "/var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/logs"
2026-01-21 00:12:07.319287 | controller -> localhost | changed: "/var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/artifacts"
2026-01-21 00:12:07.554971 | controller -> localhost | changed: "/var/lib/zuul/builds/2be7e86594d3471a8a0f8d8b36142b91/work/docs"
2026-01-21 00:12:07.582482 | 
2026-01-21 00:12:07.582833 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-21 00:12:08.277891 | controller | changed:
2026-01-21 00:12:08.278190 | controller | .d..t...... ./
2026-01-21 00:12:08.278240 | controller | cd+++++++++ controller/
2026-01-21 00:12:08.278314 | controller | changed: All items complete
2026-01-21 00:12:08.278358 | 
2026-01-21 00:12:08.852747 | controller | changed: .d..t...... ./
2026-01-21 00:12:09.289754 | controller | changed: .d..t...... ./
2026-01-21 00:12:09.312526 | 
2026-01-21 00:12:09.312703 | TASK [include_role : fetch-output-openshift]
2026-01-21 00:12:09.338773 | controller | skipping: Conditional result was False
2026-01-21 00:12:09.351590 | 
2026-01-21 00:12:09.351720 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-21 00:12:09.403970 | controller | skipping: Conditional result was False
2026-01-21 00:12:09.416219 | controller | skipping: Conditional result was False
2026-01-21 00:12:09.460528 | 
2026-01-21 00:12:09.460671 | PLAY [localhost]
2026-01-21 00:12:09.488410 | 
2026-01-21 00:12:09.488562 | TASK [Run Zuul manifest role]
2026-01-21 00:12:09.508896 | localhost | ok
2026-01-21 00:12:09.530263 | 
2026-01-21 00:12:09.530341 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-21 00:12:09.948223 | localhost | changed
2026-01-21 00:12:09.960588 | 
2026-01-21 00:12:09.960756 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-21 00:12:09.989858 | localhost | ok
2026-01-21 00:12:09.998931 | 
2026-01-21 00:12:09.999006 | TASK [Set zuul-log-path fact]
2026-01-21 00:12:10.023109 | localhost | ok
2026-01-21 00:12:10.046587 | 
2026-01-21 00:12:10.046732 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-21 00:12:10.075514 | localhost | ok
2026-01-21 00:12:10.084118 | 
2026-01-21 00:12:10.084223 | LOOP [Run upload-logs-swift role]
2026-01-21 00:12:10.130695 | localhost | Output suppressed because no_log was given
2026-01-21 00:12:10.173093 | 
2026-01-21 00:12:10.173218 | TASK [Set zuul-log-path fact]
2026-01-21 00:12:10.199086 | localhost | skipping: Conditional result was False
2026-01-21 00:12:10.206550 | 
2026-01-21 00:12:10.206632 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-21 00:12:10.612757 | localhost -> localhost | ok: Runtime: 0:00:00.005270
2026-01-21 00:12:10.625858 | 
2026-01-21 00:12:10.626043 | TASK [upload-logs-swift : Upload logs to swift]