2026-01-29 00:14:31.335973 | Job console starting...
2026-01-29 00:14:31.347423 | Updating repositories
2026-01-29 00:14:31.565963 | Preparing job workspace
2026-01-29 00:14:35.498736 | Running Ansible setup...
2026-01-29 00:14:40.687341 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-29 00:14:41.458242 | 
2026-01-29 00:14:41.458406 | PLAY [localhost]
2026-01-29 00:14:41.479792 | 
2026-01-29 00:14:41.479990 | TASK [Gathering Facts]
2026-01-29 00:14:42.572542 | localhost | ok
2026-01-29 00:14:42.593298 | 
2026-01-29 00:14:42.593461 | TASK [Setup log path fact]
2026-01-29 00:14:42.622697 | localhost | ok
2026-01-29 00:14:42.639762 | 
2026-01-29 00:14:42.639869 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-29 00:14:42.668838 | localhost | ok
2026-01-29 00:14:42.684682 | 
2026-01-29 00:14:42.684839 | TASK [emit-job-header : Print job information]
2026-01-29 00:14:42.724037 | # Job Information
2026-01-29 00:14:42.724236 | Ansible Version: 2.15.12
2026-01-29 00:14:42.724271 | Job: ansible-test-sanity-docker-devel
2026-01-29 00:14:42.724292 | Pipeline: periodic
2026-01-29 00:14:42.724311 | Executor: ze01.softwarefactory-project.io
2026-01-29 00:14:42.724328 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-29 00:14:42.724348 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/3d9/ansible/3d91dfe457e344528289a550491f02ff/
2026-01-29 00:14:42.724366 | Event ID: 63a452e1270c4d7f9ec25834a1d9f0b9
2026-01-29 00:14:42.729705 | 
2026-01-29 00:14:42.729784 | LOOP [emit-job-header : Print node information]
2026-01-29 00:14:42.853504 | localhost | ok:
2026-01-29 00:14:42.853692 | localhost | # Node Information
2026-01-29 00:14:42.853719 | localhost | Inventory Hostname: controller
2026-01-29 00:14:42.853739 | localhost | Hostname: np0005599972
2026-01-29 00:14:42.853758 | localhost | Username: zuul
2026-01-29 00:14:42.853780 | localhost | Distro: Fedora 37
2026-01-29 00:14:42.853798 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-29 00:14:42.853816 | localhost | Region: ca-ymq-1
2026-01-29 00:14:42.853832 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-29 00:14:42.853848 | localhost | Product Name: OpenStack Nova
2026-01-29 00:14:42.853865 | localhost | Interface IP: 162.253.55.250
2026-01-29 00:14:42.871742 | 
2026-01-29 00:14:42.871947 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-29 00:14:43.306664 | localhost -> localhost | changed
2026-01-29 00:14:43.313175 | 
2026-01-29 00:14:43.313255 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-29 00:14:44.404587 | localhost -> localhost | changed
2026-01-29 00:14:44.443470 | 
2026-01-29 00:14:44.443585 | PLAY [all:!appliance*]
2026-01-29 00:14:44.472701 | 
2026-01-29 00:14:44.472869 | TASK [include_role : start-zuul-console]
2026-01-29 00:14:44.494453 | controller | ok
2026-01-29 00:14:44.508769 | 
2026-01-29 00:14:44.508887 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-29 00:14:44.888454 | controller | ok
2026-01-29 00:14:44.912525 | 
2026-01-29 00:14:44.912806 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-29 00:14:45.961946 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-29 00:14:45.970651 | 
2026-01-29 00:14:45.970760 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-29 00:14:46.555370 | controller | skipping: Conditional result was False
2026-01-29 00:14:46.562244 | 
2026-01-29 00:14:46.562336 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-29 00:14:46.587612 | controller | skipping: Conditional result was False
2026-01-29 00:14:46.595534 | 
2026-01-29 00:14:46.595657 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-29 00:14:46.627532 | controller | skipping: Conditional result was False
2026-01-29 00:14:46.634658 | 
2026-01-29 00:14:46.634772 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-29 00:14:46.659889 | controller | skipping: Conditional result was False
2026-01-29 00:14:46.667137 | 
2026-01-29 00:14:46.667245 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-29 00:14:46.692259 | controller | skipping: Conditional result was False
2026-01-29 00:14:46.700196 | 
2026-01-29 00:14:46.700306 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-29 00:14:46.725234 | controller | skipping: Conditional result was False
2026-01-29 00:14:46.738656 | 
2026-01-29 00:14:46.738827 | TASK [Disable Fedora Modular]
2026-01-29 00:14:47.021330 | controller | changed
2026-01-29 00:14:47.027754 | 
2026-01-29 00:14:47.027852 | TASK [Enable EPEL]
2026-01-29 00:14:47.075177 | controller | skipping: Conditional result was False
2026-01-29 00:14:47.082954 | 
2026-01-29 00:14:47.083099 | TASK [Register the RHEL node]
2026-01-29 00:14:47.650503 | 
2026-01-29 00:14:47.650782 | TASK [Show the subscription-manager status]
2026-01-29 00:14:48.259062 | controller | skipping: Conditional result was False
2026-01-29 00:14:48.266247 | 
2026-01-29 00:14:48.266324 | TASK [Enable EPEL on RHEL]
2026-01-29 00:14:48.830125 | controller | skipping: Conditional result was False
2026-01-29 00:14:48.836946 | 
2026-01-29 00:14:48.837051 | TASK [Install git and tox]
2026-01-29 00:16:10.945399 | controller | changed
2026-01-29 00:16:10.958956 | 
2026-01-29 00:16:10.959117 | TASK [include_role : prepare-workspace]
2026-01-29 00:16:10.987171 | controller | ok
2026-01-29 00:16:11.019575 | 
2026-01-29 00:16:11.019751 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-29 00:16:11.263964 | controller | ok
2026-01-29 00:16:11.279715 | 
2026-01-29 00:16:11.279898 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-29 00:16:26.599165 | controller | Output suppressed because no_log was given
2026-01-29 00:16:26.628995 | 
2026-01-29 00:16:26.629139 | TASK [include_role : prepare-workspace-openshift]
2026-01-29 00:16:26.653600 | controller | skipping: Conditional result was False
2026-01-29 00:16:26.739363 | 
2026-01-29 00:16:26.739479 | PLAY [all:!appliance]
2026-01-29 00:16:26.755487 | 
2026-01-29 00:16:26.755556 | TASK [Run add-build-sshkey role (RSA)]
2026-01-29 00:16:26.816405 | controller | ok
2026-01-29 00:16:26.854270 | 
2026-01-29 00:16:26.854372 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-29 00:16:27.194333 | controller -> localhost | ok
2026-01-29 00:16:27.202479 | 
2026-01-29 00:16:27.202548 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-29 00:16:27.233388 | controller | ok
2026-01-29 00:16:27.249878 | controller | included: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-29 00:16:27.256694 | 
2026-01-29 00:16:27.256759 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-29 00:16:27.712962 | controller -> localhost | Generating public/private rsa key pair.
2026-01-29 00:16:27.713192 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/3d91dfe457e344528289a550491f02ff_id_rsa.
2026-01-29 00:16:27.713233 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/3d91dfe457e344528289a550491f02ff_id_rsa.pub.
2026-01-29 00:16:27.713254 | controller -> localhost | The key fingerprint is:
2026-01-29 00:16:27.713273 | controller -> localhost | SHA256:Xz5VsYzXwdVBoHvhjG3G7sFoPMuCh5BW+30jYoU+0To zuul-build-sshkey
2026-01-29 00:16:27.713293 | controller -> localhost | The key's randomart image is:
2026-01-29 00:16:27.713311 | controller -> localhost | +---[RSA 2048]----+
2026-01-29 00:16:27.713328 | controller -> localhost | |             .+==|
2026-01-29 00:16:27.713346 | controller -> localhost | |            . o.*|
2026-01-29 00:16:27.713375 | controller -> localhost | |           . o +o|
2026-01-29 00:16:27.713395 | controller -> localhost | |       .    B o. |
2026-01-29 00:16:27.713412 | controller -> localhost | |      o S oo.O.  |
2026-01-29 00:16:27.713442 | controller -> localhost | |     + . +.=B.   |
2026-01-29 00:16:27.713467 | controller -> localhost | |    . . = *=o+   |
2026-01-29 00:16:27.713487 | controller -> localhost | |       o Eoo++.  |
2026-01-29 00:16:27.713505 | controller -> localhost | |        o =oo..  |
2026-01-29 00:16:27.713525 | controller -> localhost | +----[SHA256]-----+
2026-01-29 00:16:27.713577 | controller -> localhost | ok: Runtime: 0:00:00.028521
2026-01-29 00:16:27.722196 | 
2026-01-29 00:16:27.722343 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-29 00:16:27.754579 | controller | ok
2026-01-29 00:16:27.776933 | controller | included: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-29 00:16:27.800397 | 
2026-01-29 00:16:27.800480 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-29 00:16:27.828199 | controller | skipping: Conditional result was False
2026-01-29 00:16:27.836923 | 
2026-01-29 00:16:27.837008 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-29 00:16:28.282131 | controller | changed
2026-01-29 00:16:28.291276 | 
2026-01-29 00:16:28.291472 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-29 00:16:28.530157 | controller | ok
2026-01-29 00:16:28.554148 | 
2026-01-29 00:16:28.554407 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-29 00:16:29.242413 | controller | changed
2026-01-29 00:16:29.251806 | 
2026-01-29 00:16:29.252076 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-29 00:16:29.870781 | controller | changed
2026-01-29 00:16:29.877982 | 
2026-01-29 00:16:29.878095 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-29 00:16:29.903529 | controller | skipping: Conditional result was False
2026-01-29 00:16:29.912085 | 
2026-01-29 00:16:29.912197 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-29 00:16:30.463231 | controller -> localhost | changed
2026-01-29 00:16:30.486425 | 
2026-01-29 00:16:30.486587 | TASK [add-build-sshkey : Add back temp key]
2026-01-29 00:16:30.876487 | controller -> localhost | Identity added: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/3d91dfe457e344528289a550491f02ff_id_rsa (zuul-build-sshkey)
2026-01-29 00:16:30.876825 | controller -> localhost | ok: Runtime: 0:00:00.009044
2026-01-29 00:16:30.884976 | 
2026-01-29 00:16:30.885151 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-29 00:16:31.391702 | controller | ok
2026-01-29 00:16:31.400648 | 
2026-01-29 00:16:31.401076 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-29 00:16:31.443370 | controller | skipping: Conditional result was False
2026-01-29 00:16:31.470174 | 
2026-01-29 00:16:31.470348 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-29 00:16:31.517849 | controller | ok
2026-01-29 00:16:31.540407 | 
2026-01-29 00:16:31.540588 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-29 00:16:31.854655 | controller -> localhost | ok
2026-01-29 00:16:31.862836 | 
2026-01-29 00:16:31.862915 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-29 00:16:31.895234 | controller | ok
2026-01-29 00:16:31.912423 | controller | included: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-29 00:16:31.921389 | 
2026-01-29 00:16:31.921466 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-29 00:16:32.274793 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-29 00:16:32.275000 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/3d91dfe457e344528289a550491f02ff_id_ecdsa.
2026-01-29 00:16:32.275047 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/3d91dfe457e344528289a550491f02ff_id_ecdsa.pub.
2026-01-29 00:16:32.275076 | controller -> localhost | The key fingerprint is:
2026-01-29 00:16:32.275096 | controller -> localhost | SHA256:AHzQ5Nte6cAFSJ4ftJ65E+TgNkAMV8PprH7cHvj7qmI zuul-build-sshkey
2026-01-29 00:16:32.275115 | controller -> localhost | The key's randomart image is:
2026-01-29 00:16:32.275134 | controller -> localhost | +---[ECDSA 521]---+
2026-01-29 00:16:32.275151 | controller -> localhost | |  .+=B=oo        |
2026-01-29 00:16:32.275168 | controller -> localhost | |   oo+*+ o       |
2026-01-29 00:16:32.275185 | controller -> localhost | |    .+* + .      |
2026-01-29 00:16:32.275202 | controller -> localhost | |     oo@ = .     |
2026-01-29 00:16:32.275219 | controller -> localhost | |     .= S o      |
2026-01-29 00:16:32.275235 | controller -> localhost | |    .. + *       |
2026-01-29 00:16:32.275252 | controller -> localhost | |   . ...= .      |
2026-01-29 00:16:32.275269 | controller -> localhost | |    E o..o       |
2026-01-29 00:16:32.275286 | controller -> localhost | |   . o.o=+.      |
2026-01-29 00:16:32.275302 | controller -> localhost | +----[SHA256]-----+
2026-01-29 00:16:32.275349 | controller -> localhost | ok: Runtime: 0:00:00.016562
2026-01-29 00:16:32.283643 | 
2026-01-29 00:16:32.283710 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-29 00:16:32.313510 | controller | ok
2026-01-29 00:16:32.321363 | controller | included: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-29 00:16:32.330405 | 
2026-01-29 00:16:32.330499 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-29 00:16:32.355812 | controller | skipping: Conditional result was False
2026-01-29 00:16:32.366773 | 
2026-01-29 00:16:32.366900 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-29 00:16:32.651333 | controller | changed
2026-01-29 00:16:32.666612 | 
2026-01-29 00:16:32.667745 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-29 00:16:32.915653 | controller | ok
2026-01-29 00:16:32.921688 | 
2026-01-29 00:16:32.921768 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-29 00:16:33.515668 | controller | changed
2026-01-29 00:16:33.521857 | 
2026-01-29 00:16:33.521926 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-29 00:16:34.166949 | controller | changed
2026-01-29 00:16:34.175302 | 
2026-01-29 00:16:34.175392 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-29 00:16:34.201570 | controller | skipping: Conditional result was False
2026-01-29 00:16:34.209174 | 
2026-01-29 00:16:34.209319 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-29 00:16:34.479237 | controller -> localhost | changed
2026-01-29 00:16:34.561941 | 
2026-01-29 00:16:34.562108 | TASK [add-build-sshkey : Add back temp key]
2026-01-29 00:16:34.854534 | controller -> localhost | Identity added: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/3d91dfe457e344528289a550491f02ff_id_ecdsa (zuul-build-sshkey)
2026-01-29 00:16:34.854896 | controller -> localhost | ok: Runtime: 0:00:00.016996
2026-01-29 00:16:34.865480 | 
2026-01-29 00:16:34.865593 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-29 00:16:35.072147 | controller | ok
2026-01-29 00:16:35.081878 | 
2026-01-29 00:16:35.081976 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-29 00:16:35.130837 | controller | skipping: Conditional result was False
2026-01-29 00:16:35.150081 | 
2026-01-29 00:16:35.150795 | TASK [include_role : remove-zuul-sshkey]
2026-01-29 00:16:35.200526 | controller | skipping: Conditional result was False
2026-01-29 00:16:35.209050 | 
2026-01-29 00:16:35.209163 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-29 00:16:35.482980 | controller | ok: "logs"
2026-01-29 00:16:35.485592 | controller | ok: All items complete
2026-01-29 00:16:35.485704 | 
2026-01-29 00:16:35.674447 | controller | ok: "artifacts"
2026-01-29 00:16:35.849277 | controller | ok: "docs"
2026-01-29 00:16:35.865600 | 
2026-01-29 00:16:35.865779 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-29 00:16:36.109883 | controller | changed: "logs"
2026-01-29 00:16:36.300835 | controller | changed: "artifacts"
2026-01-29 00:16:36.498852 | controller | changed: "docs"
2026-01-29 00:16:36.555201 | 
2026-01-29 00:16:36.555326 | PLAY RECAP
2026-01-29 00:16:36.555390 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-29 00:16:36.555426 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-29 00:16:36.555451 | 
2026-01-29 00:16:36.697455 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-29 00:16:36.704343 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-29 00:16:37.468599 | 
2026-01-29 00:16:37.468721 | PLAY [all]
2026-01-29 00:16:37.491772 | 
2026-01-29 00:16:37.491904 | TASK [Install binary dependencies]
2026-01-29 00:16:37.552697 | controller | ok
2026-01-29 00:16:37.575471 | 
2026-01-29 00:16:37.575605 | TASK [bindep : Include find tasks]
2026-01-29 00:16:37.605620 | controller | ok
2026-01-29 00:16:37.613861 | controller | included: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-29 00:16:37.620575 | 
2026-01-29 00:16:37.620645 | TASK [bindep : Look for bindep.txt]
2026-01-29 00:16:37.966899 | controller | ok
2026-01-29 00:16:37.976848 | 
2026-01-29 00:16:37.978995 | TASK [bindep : Define bindep_file fact]
2026-01-29 00:16:37.993293 | controller | skipping: Conditional result was False
2026-01-29 00:16:38.000679 | 
2026-01-29 00:16:38.000783 | TASK [bindep : Look for other-requirements.txt]
2026-01-29 00:16:38.204828 | controller | ok
2026-01-29 00:16:38.214988 | 
2026-01-29 00:16:38.215208 | TASK [bindep : Define bindep_file fact]
2026-01-29 00:16:38.263158 | controller | skipping: Conditional result was False
2026-01-29 00:16:38.274939 | 
2026-01-29 00:16:38.275076 | TASK [bindep : Look for bindep fallback file]
2026-01-29 00:16:38.327877 | controller | skipping: Conditional result was False
2026-01-29 00:16:38.337429 | 
2026-01-29 00:16:38.337518 | TASK [bindep : Define bindep_file fact]
2026-01-29 00:16:38.361876 | controller | skipping: Conditional result was False
2026-01-29 00:16:38.368655 | 
2026-01-29 00:16:38.368725 | TASK [bindep : Include bindep tasks]
2026-01-29 00:16:38.393031 | controller | skipping: Conditional result was False
2026-01-29 00:16:38.400751 | 
2026-01-29 00:16:38.400837 | TASK [bindep : Include install tasks]
2026-01-29 00:16:38.427591 | controller | skipping: Conditional result was False
2026-01-29 00:16:38.443727 | 
2026-01-29 00:16:38.443931 | LOOP [bindep : Include package tasks]
2026-01-29 00:16:38.563249 | 
2026-01-29 00:16:38.563734 | TASK [Run test-setup role]
2026-01-29 00:16:38.613609 | controller | ok
2026-01-29 00:16:38.647167 | 
2026-01-29 00:16:38.647419 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-29 00:16:38.871913 | controller | ok
2026-01-29 00:16:38.886138 | 
2026-01-29 00:16:38.886471 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-29 00:16:39.448284 | controller | skipping: Conditional result was False
2026-01-29 00:16:39.487202 | 
2026-01-29 00:16:39.487324 | PLAY RECAP
2026-01-29 00:16:39.487368 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-29 00:16:39.487388 | 
2026-01-29 00:16:41.326707 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-29 00:16:41.328282 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-29 00:16:42.036741 | 
2026-01-29 00:16:42.036926 | PLAY [controller]
2026-01-29 00:16:42.060791 | 
2026-01-29 00:16:42.060936 | TASK [Create the /root directory]
2026-01-29 00:16:42.438577 | controller | ok
2026-01-29 00:16:42.445032 | 
2026-01-29 00:16:42.445130 | TASK [Install glibc-langpack-en]
2026-01-29 00:16:46.260224 | controller | ok: Nothing to do
2026-01-29 00:16:46.285891 | 
2026-01-29 00:16:46.286088 | TASK [Ensure controller directory exists]
2026-01-29 00:16:46.511939 | controller | changed
2026-01-29 00:16:46.525599 | 
2026-01-29 00:16:46.525758 | TASK [Install container runtime]
2026-01-29 00:16:46.590988 | controller | ok
2026-01-29 00:16:46.636896 | 
2026-01-29 00:16:46.637074 | LOOP [ensure-podman : Find distribution installation]
2026-01-29 00:16:46.675324 | controller | ok: "/var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-29 00:16:46.691964 | controller | included: /var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-29 00:16:46.699476 | 
2026-01-29 00:16:46.699576 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-29 00:17:51.837960 | controller | changed
2026-01-29 00:17:51.847872 | 
2026-01-29 00:17:51.847975 | TASK [ensure-podman : Fetch podman version]
2026-01-29 00:17:52.483284 | controller | Client:       Podman Engine
2026-01-29 00:17:52.483377 | controller | Version:      4.6.2
2026-01-29 00:17:52.483410 | controller | API Version:  4.6.2
2026-01-29 00:17:52.483440 | controller | Go Version:   go1.19.12
2026-01-29 00:17:52.483480 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-29 00:17:52.483511 | controller | OS/Arch:      linux/amd64
2026-01-29 00:17:52.901521 | controller | ok: Runtime: 0:00:00.225646
2026-01-29 00:17:52.923430 | 
2026-01-29 00:17:52.923662 | TASK [ensure-podman : Print podman version installed]
2026-01-29 00:17:52.983873 | Podman version: Client:       Podman Engine
2026-01-29 00:17:52.984119 | Version:      4.6.2
2026-01-29 00:17:52.984164 | API Version:  4.6.2
2026-01-29 00:17:52.984197 | Go Version:   go1.19.12
2026-01-29 00:17:52.984225 | Built:        Mon Aug 28 19:38:31 2023
2026-01-29 00:17:52.984256 | OS/Arch:      linux/amd64
2026-01-29 00:17:52.993972 | 
2026-01-29 00:17:52.994154 | TASK [ensure-podman : Validate podman engine]
2026-01-29 00:17:53.530710 | controller | skipping: Conditional result was False
2026-01-29 00:17:53.544930 | 
2026-01-29 00:17:53.545199 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-29 00:17:53.574785 | controller | skipping: Conditional result was False
2026-01-29 00:17:53.615632 | 
2026-01-29 00:17:53.615782 | TASK [Ensure python3.8 is present]
2026-01-29 00:17:53.643974 | controller | skipping: Conditional result was False
2026-01-29 00:17:53.654430 | 
2026-01-29 00:17:53.654589 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-29 00:17:53.679920 | controller | ok
2026-01-29 00:17:53.713000 | 
2026-01-29 00:17:53.713203 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-29 00:17:55.506938 | controller | ok: Nothing to do
2026-01-29 00:17:55.520342 | 
2026-01-29 00:17:55.520706 | TASK [our-ensure-python : Also install python3-devel]
2026-01-29 00:18:04.879682 | controller | changed
2026-01-29 00:18:04.903178 | 
2026-01-29 00:18:04.903349 | TASK [Run ensure-virtualenv role]
2026-01-29 00:18:04.931899 | controller | ok
2026-01-29 00:18:04.967877 | 
2026-01-29 00:18:04.968045 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-29 00:18:05.237898 | controller | /usr/bin/virtualenv
2026-01-29 00:18:05.555151 | controller | ok: Runtime: 0:00:00.006270
2026-01-29 00:18:05.569981 | 
2026-01-29 00:18:05.570185 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-29 00:18:05.615877 | controller | skipping: Conditional result was False
2026-01-29 00:18:05.616176 | controller | ok: All items complete
2026-01-29 00:18:05.616207 | 
2026-01-29 00:18:05.642427 | 
2026-01-29 00:18:05.642640 | TASK [Find the full path of the Python interpreter]
2026-01-29 00:18:05.864409 | controller | /usr/bin/python3
2026-01-29 00:18:06.187248 | controller | ok
2026-01-29 00:18:06.204558 | 
2026-01-29 00:18:06.204731 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-29 00:18:07.243283 | controller | created virtual environment CPython3.11.0.final.0-64 in 555ms
2026-01-29 00:18:07.274331 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-29 00:18:07.274693 | 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-29 00:18:07.274828 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-29 00:18:07.274845 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-29 00:18:07.763886 | controller | changed
2026-01-29 00:18:07.772077 | 
2026-01-29 00:18:07.772178 | TASK [Set selinux package]
2026-01-29 00:18:07.794254 | controller | ok
2026-01-29 00:18:07.799759 | 
2026-01-29 00:18:07.799828 | TASK [Set selinux package (Fedora)]
2026-01-29 00:18:07.834353 | controller | ok
2026-01-29 00:18:07.839836 | 
2026-01-29 00:18:07.839910 | TASK [Install selinux into virtualenv]
2026-01-29 00:18:33.345450 | controller | Collecting selinux-please-lie-to-me
2026-01-29 00:18:45.598967 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-29 00:18:45.917224 | controller | Collecting setuptools<50.0.0
2026-01-29 00:18:45.925005 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-29 00:18:45.965414 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.8 MB/s eta 0:00:00
2026-01-29 00:18:46.044879 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-29 00:18:46.045112 | controller |   Attempting uninstall: setuptools
2026-01-29 00:18:46.047479 | controller |     Found existing installation: setuptools 62.6.0
2026-01-29 00:18:46.106885 | controller |     Uninstalling setuptools-62.6.0:
2026-01-29 00:18:46.115434 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-29 00:18:46.449891 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-29 00:18:57.972952 | controller |
2026-01-29 00:18:58.054388 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-29 00:18:58.054433 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-29 00:18:58.422302 | controller | ok: Runtime: 0:00:49.999651
2026-01-29 00:18:58.439291 | 
2026-01-29 00:18:58.439454 | TASK [Install pytest-forked into virtualenv]
2026-01-29 00:19:10.218447 | controller | Collecting pytest-forked
2026-01-29 00:19:20.413526 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-29 00:19:20.457791 | controller | Collecting py
2026-01-29 00:19:20.461400 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-29 00:19:20.482746 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.4 MB/s eta 0:00:00
2026-01-29 00:19:20.584835 | controller | Collecting pytest>=3.10
2026-01-29 00:19:20.588066 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-29 00:19:20.602311 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 32.9 MB/s eta 0:00:00
2026-01-29 00:19:20.638700 | controller | Collecting iniconfig>=1.0.1
2026-01-29 00:19:20.642653 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-29 00:19:20.683736 | controller | Collecting packaging>=22
2026-01-29 00:19:20.687081 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-01-29 00:19:20.692561 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 22.6 MB/s eta 0:00:00
2026-01-29 00:19:20.790514 | controller | Collecting pluggy<2,>=1.5
2026-01-29 00:19:20.793458 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-29 00:19:20.855518 | controller | Collecting pygments>=2.7.2
2026-01-29 00:19:20.859497 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-29 00:19:20.881208 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 70.6 MB/s eta 0:00:00
2026-01-29 00:19:20.952601 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-29 00:19:22.035690 | 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-29 00:19:22.045154 | controller |
2026-01-29 00:19:22.126854 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-29 00:19:22.126886 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-29 00:19:22.512565 | controller | ok: Runtime: 0:00:23.422162
2026-01-29 00:19:22.527575 | 
2026-01-29 00:19:22.527722 | TASK [Update pip]
2026-01-29 00:19:23.132084 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-29 00:19:35.549579 | controller | Collecting pip
2026-01-29 00:19:48.897437 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-29 00:19:49.189468 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 6.2 MB/s eta 0:00:00
2026-01-29 00:19:49.255911 | controller | Installing collected packages: pip
2026-01-29 00:19:49.256053 | controller |   Attempting uninstall: pip
2026-01-29 00:19:49.258822 | controller |     Found existing installation: pip 22.2.2
2026-01-29 00:19:49.412114 | controller |     Uninstalling pip-22.2.2:
2026-01-29 00:19:49.429719 | controller |       Successfully uninstalled pip-22.2.2
2026-01-29 00:19:50.257757 | controller | Successfully installed pip-25.3
2026-01-29 00:19:50.610327 | controller | ok: Runtime: 0:00:27.566474
2026-01-29 00:19:50.624552 | 
2026-01-29 00:19:50.624714 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-29 00:19:50.870563 | controller | changed
2026-01-29 00:19:50.884245 | 
2026-01-29 00:19:50.884404 | TASK [Install ansible into virtualenv]
2026-01-29 00:19:51.469829 | controller | Processing ./src/github.com/ansible/ansible
2026-01-29 00:19:51.473364 | controller |   Installing build dependencies: started
2026-01-29 00:20:16.713171 | controller |   Installing build dependencies: finished with status 'done'
2026-01-29 00:20:16.713876 | controller |   Getting requirements to build wheel: started
2026-01-29 00:20:17.476422 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-29 00:20:17.477337 | controller |   Preparing metadata (pyproject.toml): started
2026-01-29 00:20:17.937748 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-29 00:20:17.943640 | 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-29 00:20:17.947288 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-29 00:20:18.488982 | controller | ERROR
2026-01-29 00:20:18.489553 | controller | {
2026-01-29 00:20:18.489649 | controller |   "delta": "0:00:26.843415",
2026-01-29 00:20:18.489732 | controller |   "end": "2026-01-29 00:20:18.011453",
2026-01-29 00:20:18.489792 | controller |   "msg": "non-zero return code",
2026-01-29 00:20:18.489871 | controller |   "rc": 1,
2026-01-29 00:20:18.489924 | controller |   "start": "2026-01-29 00:19:51.168038"
2026-01-29 00:20:18.489972 | controller | }
failure
2026-01-29 00:20:18.495385 | 
2026-01-29 00:20:18.495521 | PLAY RECAP
2026-01-29 00:20:18.495651 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-29 00:20:18.495775 | 
2026-01-29 00:20:18.673669 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-29 00:20:18.675131 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-29 00:20:19.306428 | 
2026-01-29 00:20:19.306573 | PLAY [all]
2026-01-29 00:20:19.330193 | 
2026-01-29 00:20:19.330349 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-29 00:20:19.604621 | controller | changed: non-zero return code
2026-01-29 00:20:19.617979 | 
2026-01-29 00:20:19.618233 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-29 00:20:19.634821 | controller | skipping: Conditional result was False
2026-01-29 00:20:19.641479 | 
2026-01-29 00:20:19.641555 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-29 00:20:19.663688 | 
2026-01-29 00:20:19.663861 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-29 00:20:19.684213 | 
2026-01-29 00:20:19.684392 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-29 00:20:19.708069 | controller | skipping: Conditional result was False
2026-01-29 00:20:19.717175 | 
2026-01-29 00:20:19.717259 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-29 00:20:19.759010 | 
2026-01-29 00:20:19.759193 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-29 00:20:19.783500 | controller | skipping: Conditional result was False
2026-01-29 00:20:19.790331 | 
2026-01-29 00:20:19.790404 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-29 00:20:19.815132 | controller | skipping: Conditional result was False
2026-01-29 00:20:19.822241 | 
2026-01-29 00:20:19.822315 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-29 00:20:19.846992 | controller | skipping: Conditional result was False
2026-01-29 00:20:19.873732 | 
2026-01-29 00:20:19.873800 | PLAY RECAP
2026-01-29 00:20:19.873845 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-29 00:20:19.873870 | 
2026-01-29 00:20:19.987761 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-29 00:20:19.988968 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-29 00:20:20.653459 | 
2026-01-29 00:20:20.653594 | PLAY [all:!appliance*]
2026-01-29 00:20:20.677728 | 
2026-01-29 00:20:20.677883 | TASK [unregister the node]
2026-01-29 00:20:21.211833 | controller | skipping: Conditional result was False
2026-01-29 00:20:21.228708 | 
2026-01-29 00:20:21.228934 | TASK [include_role : fetch-output]
2026-01-29 00:20:21.267126 | controller | ok
2026-01-29 00:20:21.299654 | 
2026-01-29 00:20:21.299827 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-29 00:20:21.368303 | controller | skipping: Conditional result was False
2026-01-29 00:20:21.379398 | 
2026-01-29 00:20:21.379567 | TASK [fetch-output : Set log path for single node]
2026-01-29 00:20:21.434905 | controller | ok
2026-01-29 00:20:21.443130 | 
2026-01-29 00:20:21.443239 | LOOP [fetch-output : Ensure local output dirs]
2026-01-29 00:20:21.980246 | controller -> localhost | ok: "/var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/logs"
2026-01-29 00:20:22.257461 | controller -> localhost | changed: "/var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/artifacts"
2026-01-29 00:20:22.501839 | controller -> localhost | changed: "/var/lib/zuul/builds/3d91dfe457e344528289a550491f02ff/work/docs"
2026-01-29 00:20:22.515054 | 
2026-01-29 00:20:22.515210 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-29 00:20:23.269760 | controller | changed:
2026-01-29 00:20:23.270135 | controller | .d..t...... ./
2026-01-29 00:20:23.270168 | controller | cd+++++++++ controller/
2026-01-29 00:20:23.270205 | controller | changed: All items complete
2026-01-29 00:20:23.270225 | 
2026-01-29 00:20:23.803609 | controller | changed: .d..t...... ./
2026-01-29 00:20:24.340056 | controller | changed: .d..t...... ./
2026-01-29 00:20:24.376880 | 
2026-01-29 00:20:24.377143 | TASK [include_role : fetch-output-openshift]
2026-01-29 00:20:24.404799 | controller | skipping: Conditional result was False
2026-01-29 00:20:24.412353 | 
2026-01-29 00:20:24.412459 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-29 00:20:24.458322 | controller | skipping: Conditional result was False
2026-01-29 00:20:24.475244 | controller | skipping: Conditional result was False
2026-01-29 00:20:24.521555 | 
2026-01-29 00:20:24.521748 | PLAY [localhost]
2026-01-29 00:20:24.534569 | 
2026-01-29 00:20:24.534670 | TASK [Run Zuul manifest role]
2026-01-29 00:20:24.568893 | localhost | ok
2026-01-29 00:20:24.593494 | 
2026-01-29 00:20:24.593721 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-29 00:20:25.031285 | localhost | changed
2026-01-29 00:20:25.044226 | 
2026-01-29 00:20:25.045083 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-29 00:20:25.082414 | localhost | ok
2026-01-29 00:20:25.096809 | 
2026-01-29 00:20:25.097047 | TASK [Set zuul-log-path fact]
2026-01-29 00:20:25.120885 | localhost | ok
2026-01-29 00:20:25.146176 | 
2026-01-29 00:20:25.146384 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-29 00:20:25.189326 | localhost | ok
2026-01-29 00:20:25.200118 | 
2026-01-29 00:20:25.200229 | LOOP [Run upload-logs-swift role]
2026-01-29 00:20:25.251292 | localhost | Output suppressed because no_log was given
2026-01-29 00:20:25.295580 | 
2026-01-29 00:20:25.295877 | TASK [Set zuul-log-path fact]
2026-01-29 00:20:25.321619 | localhost | skipping: Conditional result was False
2026-01-29 00:20:25.327910 | 
2026-01-29 00:20:25.327996 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-29 00:20:25.796683 | localhost -> localhost | ok: Runtime: 0:00:00.008406
2026-01-29 00:20:25.864878 | 
2026-01-29 00:20:25.865392 | TASK [upload-logs-swift : Upload logs to swift]