2026-01-03 00:13:48.316554 | Job console starting...
2026-01-03 00:13:48.326870 | Updating repositories
2026-01-03 00:13:48.439241 | Preparing job workspace
2026-01-03 00:13:53.267542 | Running Ansible setup...
2026-01-03 00:13:57.824050 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-03 00:13:58.422115 | 
2026-01-03 00:13:58.422277 | PLAY [localhost]
2026-01-03 00:13:58.432274 | 
2026-01-03 00:13:58.432378 | TASK [Gathering Facts]
2026-01-03 00:13:59.474356 | localhost | ok
2026-01-03 00:13:59.493604 | 
2026-01-03 00:13:59.493779 | TASK [Setup log path fact]
2026-01-03 00:13:59.524317 | localhost | ok
2026-01-03 00:13:59.538060 | 
2026-01-03 00:13:59.538234 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-03 00:13:59.568819 | localhost | ok
2026-01-03 00:13:59.578232 | 
2026-01-03 00:13:59.578326 | TASK [emit-job-header : Print job information]
2026-01-03 00:13:59.621546 | # Job Information
2026-01-03 00:13:59.621854 | Ansible Version: 2.15.12
2026-01-03 00:13:59.621902 | Job: ansible-test-sanity-docker-devel
2026-01-03 00:13:59.621933 | Pipeline: periodic
2026-01-03 00:13:59.621971 | Executor: ze01.softwarefactory-project.io
2026-01-03 00:13:59.622007 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-03 00:13:59.622071 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/d68/ansible/d6841790dd4e4c68a4b18665e05a1d7c/
2026-01-03 00:13:59.622100 | Event ID: 84f60a54a6bb4d9ab16f9cfd1e63d8f4
2026-01-03 00:13:59.628133 | 
2026-01-03 00:13:59.628237 | LOOP [emit-job-header : Print node information]
2026-01-03 00:13:59.746925 | localhost | ok:
2026-01-03 00:13:59.747166 | localhost | # Node Information
2026-01-03 00:13:59.747193 | localhost | Inventory Hostname: controller
2026-01-03 00:13:59.747213 | localhost | Hostname: np0005573533
2026-01-03 00:13:59.747232 | localhost | Username: zuul
2026-01-03 00:13:59.747256 | localhost | Distro: Fedora 37
2026-01-03 00:13:59.747275 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-03 00:13:59.747293 | localhost | Region: ca-ymq-1
2026-01-03 00:13:59.747309 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-03 00:13:59.747325 | localhost | Product Name: OpenStack Nova
2026-01-03 00:13:59.747342 | localhost | Interface IP: 162.253.55.204
2026-01-03 00:13:59.776166 | 
2026-01-03 00:13:59.776532 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-03 00:14:00.193255 | localhost -> localhost | changed
2026-01-03 00:14:00.200371 | 
2026-01-03 00:14:00.200469 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-03 00:14:01.063397 | localhost -> localhost | changed
2026-01-03 00:14:01.108450 | 
2026-01-03 00:14:01.108541 | PLAY [all:!appliance*]
2026-01-03 00:14:01.132631 | 
2026-01-03 00:14:01.132752 | TASK [include_role : start-zuul-console]
2026-01-03 00:14:01.156514 | controller | ok
2026-01-03 00:14:01.177309 | 
2026-01-03 00:14:01.177436 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-03 00:14:01.561164 | controller | ok
2026-01-03 00:14:01.577275 | 
2026-01-03 00:14:01.577393 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-03 00:14:21.531695 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-03 00:14:21.541409 | 
2026-01-03 00:14:21.541499 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-03 00:14:22.090010 | controller | skipping: Conditional result was False
2026-01-03 00:14:22.100811 | 
2026-01-03 00:14:22.100927 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-03 00:14:22.127569 | controller | skipping: Conditional result was False
2026-01-03 00:14:22.135299 | 
2026-01-03 00:14:22.135389 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-03 00:14:22.160173 | controller | skipping: Conditional result was False
2026-01-03 00:14:22.169875 | 
2026-01-03 00:14:22.170001 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-03 00:14:22.195279 | controller | skipping: Conditional result was False
2026-01-03 00:14:22.204882 | 
2026-01-03 00:14:22.205056 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-03 00:14:22.230393 | controller | skipping: Conditional result was False
2026-01-03 00:14:22.237055 | 
2026-01-03 00:14:22.237140 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-03 00:14:22.260813 | controller | skipping: Conditional result was False
2026-01-03 00:14:22.274555 | 
2026-01-03 00:14:22.274633 | TASK [Disable Fedora Modular]
2026-01-03 00:14:22.659502 | controller | changed
2026-01-03 00:14:22.669639 | 
2026-01-03 00:14:22.669746 | TASK [Enable EPEL]
2026-01-03 00:14:22.695755 | controller | skipping: Conditional result was False
2026-01-03 00:14:22.705668 | 
2026-01-03 00:14:22.705778 | TASK [Register the RHEL node]
2026-01-03 00:14:23.262771 | 
2026-01-03 00:14:23.262980 | TASK [Show the subscription-manager status]
2026-01-03 00:14:23.805028 | controller | skipping: Conditional result was False
2026-01-03 00:14:23.812909 | 
2026-01-03 00:14:23.813183 | TASK [Enable EPEL on RHEL]
2026-01-03 00:14:24.364894 | controller | skipping: Conditional result was False
2026-01-03 00:14:24.371996 | 
2026-01-03 00:14:24.372123 | TASK [Install git and tox]
2026-01-03 00:15:15.761424 | controller | changed
2026-01-03 00:15:15.781135 | 
2026-01-03 00:15:15.781375 | TASK [include_role : prepare-workspace]
2026-01-03 00:15:15.820597 | controller | ok
2026-01-03 00:15:15.853950 | 
2026-01-03 00:15:15.854186 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-03 00:15:16.186979 | controller | ok
2026-01-03 00:15:16.196596 | 
2026-01-03 00:15:16.196700 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-03 00:15:35.830499 | controller | Output suppressed because no_log was given
2026-01-03 00:15:35.848810 | 
2026-01-03 00:15:35.848914 | TASK [include_role : prepare-workspace-openshift]
2026-01-03 00:15:35.873005 | controller | skipping: Conditional result was False
2026-01-03 00:15:35.915774 | 
2026-01-03 00:15:35.915862 | PLAY [all:!appliance]
2026-01-03 00:15:35.942011 | 
2026-01-03 00:15:35.942141 | TASK [Run add-build-sshkey role (RSA)]
2026-01-03 00:15:35.993953 | controller | ok
2026-01-03 00:15:36.021217 | 
2026-01-03 00:15:36.021339 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-03 00:15:36.518593 | controller -> localhost | ok
2026-01-03 00:15:36.526488 | 
2026-01-03 00:15:36.526613 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-03 00:15:36.559404 | controller | ok
2026-01-03 00:15:36.580532 | controller | included: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-03 00:15:36.586766 | 
2026-01-03 00:15:36.586835 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-03 00:15:37.096377 | controller -> localhost | Generating public/private rsa key pair.
2026-01-03 00:15:37.096626 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/d6841790dd4e4c68a4b18665e05a1d7c_id_rsa.
2026-01-03 00:15:37.096668 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/d6841790dd4e4c68a4b18665e05a1d7c_id_rsa.pub.
2026-01-03 00:15:37.096697 | controller -> localhost | The key fingerprint is:
2026-01-03 00:15:37.096740 | controller -> localhost | SHA256:u9KPBLK1opsE07U6bK1vsfwZ0ctCho+JO6ao747S8+s zuul-build-sshkey
2026-01-03 00:15:37.096761 | controller -> localhost | The key's randomart image is:
2026-01-03 00:15:37.096780 | controller -> localhost | +---[RSA 2048]----+
2026-01-03 00:15:37.096797 | controller -> localhost | |                 |
2026-01-03 00:15:37.096816 | controller -> localhost | |                 |
2026-01-03 00:15:37.096832 | controller -> localhost | |    .            |
2026-01-03 00:15:37.096850 | controller -> localhost | | . . o .         |
2026-01-03 00:15:37.096868 | controller -> localhost | |o . + * S        |
2026-01-03 00:15:37.096901 | controller -> localhost | | + +.X = o       |
2026-01-03 00:15:37.096923 | controller -> localhost | | .B.*o=.=        |
2026-01-03 00:15:37.096944 | controller -> localhost | |o+=*+..=.o       |
2026-01-03 00:15:37.096962 | controller -> localhost | |B*XOEoo.o..      |
2026-01-03 00:15:37.096983 | controller -> localhost | +----[SHA256]-----+
2026-01-03 00:15:37.097239 | controller -> localhost | ok: Runtime: 0:00:00.061042
2026-01-03 00:15:37.114565 | 
2026-01-03 00:15:37.114735 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-03 00:15:37.177516 | controller | ok
2026-01-03 00:15:37.187784 | controller | included: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-03 00:15:37.196986 | 
2026-01-03 00:15:37.197093 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-03 00:15:37.221138 | controller | skipping: Conditional result was False
2026-01-03 00:15:37.228135 | 
2026-01-03 00:15:37.228240 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-03 00:15:37.645981 | controller | changed
2026-01-03 00:15:37.658244 | 
2026-01-03 00:15:37.658404 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-03 00:15:37.888728 | controller | ok
2026-01-03 00:15:37.898033 | 
2026-01-03 00:15:37.898147 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-03 00:15:38.509519 | controller | changed
2026-01-03 00:15:38.515593 | 
2026-01-03 00:15:38.515669 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-03 00:15:39.106183 | controller | changed
2026-01-03 00:15:39.112415 | 
2026-01-03 00:15:39.112483 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-03 00:15:39.126362 | controller | skipping: Conditional result was False
2026-01-03 00:15:39.136075 | 
2026-01-03 00:15:39.136184 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-03 00:15:39.539216 | controller -> localhost | changed
2026-01-03 00:15:39.569323 | 
2026-01-03 00:15:39.569525 | TASK [add-build-sshkey : Add back temp key]
2026-01-03 00:15:39.840841 | controller -> localhost | Identity added: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/d6841790dd4e4c68a4b18665e05a1d7c_id_rsa (zuul-build-sshkey)
2026-01-03 00:15:39.841099 | controller -> localhost | ok: Runtime: 0:00:00.013504
2026-01-03 00:15:39.848005 | 
2026-01-03 00:15:39.848122 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-03 00:15:40.171911 | controller | ok
2026-01-03 00:15:40.184382 | 
2026-01-03 00:15:40.184550 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-03 00:15:40.220838 | controller | skipping: Conditional result was False
2026-01-03 00:15:40.242765 | 
2026-01-03 00:15:40.242920 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-03 00:15:40.297864 | controller | ok
2026-01-03 00:15:40.321783 | 
2026-01-03 00:15:40.321910 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-03 00:15:40.571994 | controller -> localhost | ok
2026-01-03 00:15:40.579059 | 
2026-01-03 00:15:40.579136 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-03 00:15:40.608993 | controller | ok
2026-01-03 00:15:40.621380 | controller | included: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-03 00:15:40.627683 | 
2026-01-03 00:15:40.627748 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-03 00:15:40.897203 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-03 00:15:40.897570 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/d6841790dd4e4c68a4b18665e05a1d7c_id_ecdsa.
2026-01-03 00:15:40.897636 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/d6841790dd4e4c68a4b18665e05a1d7c_id_ecdsa.pub.
2026-01-03 00:15:40.897699 | controller -> localhost | The key fingerprint is:
2026-01-03 00:15:40.897747 | controller -> localhost | SHA256:5YcOCYIna3HQNQKJ4Hi5mZtnVi+ufJbXiAlTMU+Qrzg zuul-build-sshkey
2026-01-03 00:15:40.897789 | controller -> localhost | The key's randomart image is:
2026-01-03 00:15:40.897831 | controller -> localhost | +---[ECDSA 521]---+
2026-01-03 00:15:40.897872 | controller -> localhost | |o.o+..+o         |
2026-01-03 00:15:40.897913 | controller -> localhost | |+ .+..+..        |
2026-01-03 00:15:40.897953 | controller -> localhost | |..* + .*  .      |
2026-01-03 00:15:40.897992 | controller -> localhost | | . X ...o+ .     |
2026-01-03 00:15:40.898346 | controller -> localhost | |  *  o..S o .    |
2026-01-03 00:15:40.898412 | controller -> localhost | | . oE... o .     |
2026-01-03 00:15:40.898458 | controller -> localhost | |  o ++.+.o.      |
2026-01-03 00:15:40.898501 | controller -> localhost | |   = .*.o .      |
2026-01-03 00:15:40.898543 | controller -> localhost | |    o+..         |
2026-01-03 00:15:40.898583 | controller -> localhost | +----[SHA256]-----+
2026-01-03 00:15:40.898683 | controller -> localhost | ok: Runtime: 0:00:00.018756
2026-01-03 00:15:40.919134 | 
2026-01-03 00:15:40.919315 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-03 00:15:40.946533 | controller | ok
2026-01-03 00:15:40.957391 | controller | included: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-03 00:15:40.971423 | 
2026-01-03 00:15:40.971619 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-03 00:15:40.998219 | controller | skipping: Conditional result was False
2026-01-03 00:15:41.007643 | 
2026-01-03 00:15:41.007738 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-03 00:15:41.321437 | controller | changed
2026-01-03 00:15:41.336698 | 
2026-01-03 00:15:41.336869 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-03 00:15:41.554282 | controller | ok
2026-01-03 00:15:41.562539 | 
2026-01-03 00:15:41.562678 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-03 00:15:42.179751 | controller | changed
2026-01-03 00:15:42.187538 | 
2026-01-03 00:15:42.187977 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-03 00:15:42.823365 | controller | changed
2026-01-03 00:15:42.835102 | 
2026-01-03 00:15:42.835210 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-03 00:15:42.860234 | controller | skipping: Conditional result was False
2026-01-03 00:15:42.869619 | 
2026-01-03 00:15:42.869731 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-03 00:15:43.130143 | controller -> localhost | changed
2026-01-03 00:15:43.141893 | 
2026-01-03 00:15:43.141999 | TASK [add-build-sshkey : Add back temp key]
2026-01-03 00:15:43.431594 | controller -> localhost | Identity added: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/d6841790dd4e4c68a4b18665e05a1d7c_id_ecdsa (zuul-build-sshkey)
2026-01-03 00:15:43.431804 | controller -> localhost | ok: Runtime: 0:00:00.009966
2026-01-03 00:15:43.438242 | 
2026-01-03 00:15:43.438307 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-03 00:15:43.640431 | controller | ok
2026-01-03 00:15:43.653247 | 
2026-01-03 00:15:43.653405 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-03 00:15:43.681956 | controller | skipping: Conditional result was False
2026-01-03 00:15:43.694201 | 
2026-01-03 00:15:43.694315 | TASK [include_role : remove-zuul-sshkey]
2026-01-03 00:15:43.738518 | controller | skipping: Conditional result was False
2026-01-03 00:15:43.750727 | 
2026-01-03 00:15:43.750882 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-03 00:15:43.983400 | controller | ok: "logs"
2026-01-03 00:15:43.983726 | controller | ok: All items complete
2026-01-03 00:15:43.983777 | 
2026-01-03 00:15:44.170338 | controller | ok: "artifacts"
2026-01-03 00:15:44.349095 | controller | ok: "docs"
2026-01-03 00:15:44.360223 | 
2026-01-03 00:15:44.360348 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-03 00:15:44.597190 | controller | changed: "logs"
2026-01-03 00:15:44.802240 | controller | changed: "artifacts"
2026-01-03 00:15:45.069522 | controller | changed: "docs"
2026-01-03 00:15:45.111622 | 
2026-01-03 00:15:45.111805 | PLAY RECAP
2026-01-03 00:15:45.111857 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-03 00:15:45.111883 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-03 00:15:45.111902 | 
2026-01-03 00:15:45.317999 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-03 00:15:45.319388 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-03 00:15:45.968411 | 
2026-01-03 00:15:45.968541 | PLAY [all]
2026-01-03 00:15:45.992542 | 
2026-01-03 00:15:45.992670 | TASK [Install binary dependencies]
2026-01-03 00:15:46.044618 | controller | ok
2026-01-03 00:15:46.065737 | 
2026-01-03 00:15:46.065909 | TASK [bindep : Include find tasks]
2026-01-03 00:15:46.106167 | controller | ok
2026-01-03 00:15:46.114915 | controller | included: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-03 00:15:46.121961 | 
2026-01-03 00:15:46.122069 | TASK [bindep : Look for bindep.txt]
2026-01-03 00:15:46.471687 | controller | ok
2026-01-03 00:15:46.478224 | 
2026-01-03 00:15:46.478309 | TASK [bindep : Define bindep_file fact]
2026-01-03 00:15:46.493223 | controller | skipping: Conditional result was False
2026-01-03 00:15:46.501292 | 
2026-01-03 00:15:46.501400 | TASK [bindep : Look for other-requirements.txt]
2026-01-03 00:15:46.708685 | controller | ok
2026-01-03 00:15:46.715552 | 
2026-01-03 00:15:46.715651 | TASK [bindep : Define bindep_file fact]
2026-01-03 00:15:46.742976 | controller | skipping: Conditional result was False
2026-01-03 00:15:46.759461 | 
2026-01-03 00:15:46.759636 | TASK [bindep : Look for bindep fallback file]
2026-01-03 00:15:46.804839 | controller | skipping: Conditional result was False
2026-01-03 00:15:46.812499 | 
2026-01-03 00:15:46.812577 | TASK [bindep : Define bindep_file fact]
2026-01-03 00:15:46.837597 | controller | skipping: Conditional result was False
2026-01-03 00:15:46.844714 | 
2026-01-03 00:15:46.844789 | TASK [bindep : Include bindep tasks]
2026-01-03 00:15:46.869551 | controller | skipping: Conditional result was False
2026-01-03 00:15:46.877160 | 
2026-01-03 00:15:46.877233 | TASK [bindep : Include install tasks]
2026-01-03 00:15:46.901920 | controller | skipping: Conditional result was False
2026-01-03 00:15:46.909534 | 
2026-01-03 00:15:46.909615 | LOOP [bindep : Include package tasks]
2026-01-03 00:15:46.976844 | 
2026-01-03 00:15:46.977064 | TASK [Run test-setup role]
2026-01-03 00:15:46.999420 | controller | ok
2026-01-03 00:15:47.081474 | 
2026-01-03 00:15:47.081620 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-03 00:15:47.322871 | controller | ok
2026-01-03 00:15:47.337457 | 
2026-01-03 00:15:47.337659 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-03 00:15:47.889271 | controller | skipping: Conditional result was False
2026-01-03 00:15:47.929122 | 
2026-01-03 00:15:47.929251 | PLAY RECAP
2026-01-03 00:15:47.929332 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-03 00:15:47.929362 | 
2026-01-03 00:15:48.026407 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-03 00:15:48.027702 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-03 00:15:48.606063 | 
2026-01-03 00:15:48.606204 | PLAY [controller]
2026-01-03 00:15:48.627755 | 
2026-01-03 00:15:48.627883 | TASK [Create the /root directory]
2026-01-03 00:15:49.010193 | controller | ok
2026-01-03 00:15:49.019778 | 
2026-01-03 00:15:49.019994 | TASK [Install glibc-langpack-en]
2026-01-03 00:15:52.977994 | controller | ok: Nothing to do
2026-01-03 00:15:52.990010 | 
2026-01-03 00:15:52.990328 | TASK [Ensure controller directory exists]
2026-01-03 00:15:53.209460 | controller | changed
2026-01-03 00:15:53.220493 | 
2026-01-03 00:15:53.220647 | TASK [Install container runtime]
2026-01-03 00:15:53.295576 | controller | ok
2026-01-03 00:15:53.349904 | 
2026-01-03 00:15:53.350104 | LOOP [ensure-podman : Find distribution installation]
2026-01-03 00:15:53.394741 | controller | ok: "/var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-03 00:15:53.408363 | controller | included: /var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-03 00:15:53.419137 | 
2026-01-03 00:15:53.419267 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-03 00:16:57.971700 | controller | changed
2026-01-03 00:16:57.981479 | 
2026-01-03 00:16:57.981572 | TASK [ensure-podman : Fetch podman version]
2026-01-03 00:16:58.493502 | controller | Client:       Podman Engine
2026-01-03 00:16:58.521859 | controller | Version:      4.6.2
2026-01-03 00:16:58.521911 | controller | API Version:  4.6.2
2026-01-03 00:16:58.521924 | controller | Go Version:   go1.19.12
2026-01-03 00:16:58.521950 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-03 00:16:58.521963 | controller | OS/Arch:      linux/amd64
2026-01-03 00:16:58.565748 | controller | ok: Runtime: 0:00:00.188544
2026-01-03 00:16:58.585695 | 
2026-01-03 00:16:58.585885 | TASK [ensure-podman : Print podman version installed]
2026-01-03 00:16:58.643785 | Podman version: Client:       Podman Engine
2026-01-03 00:16:58.644011 | Version:      4.6.2
2026-01-03 00:16:58.644111 | API Version:  4.6.2
2026-01-03 00:16:58.644163 | Go Version:   go1.19.12
2026-01-03 00:16:58.644207 | Built:        Mon Aug 28 19:38:31 2023
2026-01-03 00:16:58.644249 | OS/Arch:      linux/amd64
2026-01-03 00:16:58.652739 | 
2026-01-03 00:16:58.652834 | TASK [ensure-podman : Validate podman engine]
2026-01-03 00:16:59.189399 | controller | skipping: Conditional result was False
2026-01-03 00:16:59.203056 | 
2026-01-03 00:16:59.203206 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-03 00:16:59.230762 | controller | skipping: Conditional result was False
2026-01-03 00:16:59.254285 | 
2026-01-03 00:16:59.254448 | TASK [Ensure python3.8 is present]
2026-01-03 00:16:59.271052 | controller | skipping: Conditional result was False
2026-01-03 00:16:59.280693 | 
2026-01-03 00:16:59.280806 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-03 00:16:59.303865 | controller | ok
2026-01-03 00:16:59.334302 | 
2026-01-03 00:16:59.334447 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-03 00:17:00.802687 | controller | ok: Nothing to do
2026-01-03 00:17:00.816506 | 
2026-01-03 00:17:00.816703 | TASK [our-ensure-python : Also install python3-devel]
2026-01-03 00:17:10.641548 | controller | changed
2026-01-03 00:17:10.666989 | 
2026-01-03 00:17:10.667178 | TASK [Run ensure-virtualenv role]
2026-01-03 00:17:10.693000 | controller | ok
2026-01-03 00:17:10.724873 | 
2026-01-03 00:17:10.725144 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-03 00:17:10.965505 | controller | /usr/bin/virtualenv
2026-01-03 00:17:11.290833 | controller | ok: Runtime: 0:00:00.003198
2026-01-03 00:17:11.297375 | 
2026-01-03 00:17:11.297441 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-03 00:17:11.333439 | controller | skipping: Conditional result was False
2026-01-03 00:17:11.333935 | controller | ok: All items complete
2026-01-03 00:17:11.333994 | 
2026-01-03 00:17:11.361491 | 
2026-01-03 00:17:11.361638 | TASK [Find the full path of the Python interpreter]
2026-01-03 00:17:11.592958 | controller | /usr/bin/python3
2026-01-03 00:17:11.905053 | controller | ok
2026-01-03 00:17:11.910831 | 
2026-01-03 00:17:11.910904 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-03 00:17:12.768068 | controller | created virtual environment CPython3.11.0.final.0-64 in 444ms
2026-01-03 00:17:12.784168 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-03 00:17:12.784206 | 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-03 00:17:12.784216 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-03 00:17:12.784229 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-03 00:17:12.945890 | controller | changed
2026-01-03 00:17:12.960095 | 
2026-01-03 00:17:12.960287 | TASK [Set selinux package]
2026-01-03 00:17:13.000895 | controller | ok
2026-01-03 00:17:13.012621 | 
2026-01-03 00:17:13.012775 | TASK [Set selinux package (Fedora)]
2026-01-03 00:17:13.066148 | controller | ok
2026-01-03 00:17:13.080852 | 
2026-01-03 00:17:13.081086 | TASK [Install selinux into virtualenv]
2026-01-03 00:17:38.546307 | controller | Collecting selinux-please-lie-to-me
2026-01-03 00:17:50.813520 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-03 00:17:51.122741 | controller | Collecting setuptools<50.0.0
2026-01-03 00:17:51.129320 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-03 00:17:51.163656 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.7 MB/s eta 0:00:00
2026-01-03 00:17:51.240473 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-03 00:17:51.240709 | controller |   Attempting uninstall: setuptools
2026-01-03 00:17:51.243097 | controller |     Found existing installation: setuptools 62.6.0
2026-01-03 00:17:51.301861 | controller |     Uninstalling setuptools-62.6.0:
2026-01-03 00:17:51.309817 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-03 00:17:51.647221 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-03 00:18:03.181851 | controller |
2026-01-03 00:18:03.269471 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-03 00:18:03.269516 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-03 00:18:03.661868 | controller | ok: Runtime: 0:00:49.971233
2026-01-03 00:18:03.675355 | 
2026-01-03 00:18:03.675491 | TASK [Install pytest-forked into virtualenv]
2026-01-03 00:18:40.471067 | controller | Collecting pytest-forked
2026-01-03 00:19:04.731689 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-03 00:19:04.771660 | controller | Collecting py
2026-01-03 00:19:04.775058 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-03 00:19:04.799174 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.3 MB/s eta 0:00:00
2026-01-03 00:19:04.908106 | controller | Collecting pytest>=3.10
2026-01-03 00:19:04.912906 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-03 00:19:04.936214 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 19.0 MB/s eta 0:00:00
2026-01-03 00:19:04.974645 | controller | Collecting iniconfig>=1.0.1
2026-01-03 00:19:04.981391 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-03 00:19:05.025851 | controller | Collecting packaging>=22
2026-01-03 00:19:05.029337 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-03 00:19:05.037462 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.7 MB/s eta 0:00:00
2026-01-03 00:19:05.069707 | controller | Collecting pluggy<2,>=1.5
2026-01-03 00:19:05.072772 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-03 00:19:05.121358 | controller | Collecting pygments>=2.7.2
2026-01-03 00:19:05.130902 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-03 00:19:05.160924 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 48.2 MB/s eta 0:00:00
2026-01-03 00:19:05.231780 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-03 00:19:06.253380 | 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-03 00:19:06.262424 | controller |
2026-01-03 00:19:06.348163 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-03 00:19:06.348213 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-03 00:19:06.763705 | controller | ok: Runtime: 0:01:02.446418
2026-01-03 00:19:06.772976 | 
2026-01-03 00:19:06.773134 | TASK [Update pip]
2026-01-03 00:19:07.324458 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-03 00:19:17.123526 | controller | Collecting pip
2026-01-03 00:19:29.326411 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-03 00:19:29.398385 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 28.1 MB/s eta 0:00:00
2026-01-03 00:19:29.460966 | controller | Installing collected packages: pip
2026-01-03 00:19:29.461175 | controller |   Attempting uninstall: pip
2026-01-03 00:19:29.463290 | controller |     Found existing installation: pip 22.2.2
2026-01-03 00:19:29.598290 | controller |     Uninstalling pip-22.2.2:
2026-01-03 00:19:29.613340 | controller |       Successfully uninstalled pip-22.2.2
2026-01-03 00:19:30.443899 | controller | Successfully installed pip-25.3
2026-01-03 00:19:30.838520 | controller | ok: Runtime: 0:00:23.511349
2026-01-03 00:19:30.858696 | 
2026-01-03 00:19:30.858872 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-03 00:19:31.100082 | controller | changed
2026-01-03 00:19:31.109378 | 
2026-01-03 00:19:31.109527 | TASK [Install ansible into virtualenv]
2026-01-03 00:19:31.654670 | controller | Processing ./src/github.com/ansible/ansible
2026-01-03 00:19:31.658101 | controller |   Installing build dependencies: started
2026-01-03 00:19:54.216567 | controller |   Installing build dependencies: finished with status 'done'
2026-01-03 00:19:54.217299 | controller |   Getting requirements to build wheel: started
2026-01-03 00:19:54.949877 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-03 00:19:54.951203 | controller |   Preparing metadata (pyproject.toml): started
2026-01-03 00:19:55.398387 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-03 00:19:55.403442 | 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-03 00:19:55.406935 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-03 00:19:55.711140 | controller | ERROR
2026-01-03 00:19:55.711403 | controller | {
2026-01-03 00:19:55.711459 | controller |   "delta": "0:00:24.114122",
2026-01-03 00:19:55.711495 | controller |   "end": "2026-01-03 00:19:55.476314",
2026-01-03 00:19:55.711533 | controller |   "msg": "non-zero return code",
2026-01-03 00:19:55.711586 | controller |   "rc": 1,
2026-01-03 00:19:55.711622 | controller |   "start": "2026-01-03 00:19:31.362192"
2026-01-03 00:19:55.711653 | controller | }
failure
2026-01-03 00:19:55.713837 | 
2026-01-03 00:19:55.713910 | PLAY RECAP
2026-01-03 00:19:55.713969 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-03 00:19:55.713998 | 
2026-01-03 00:19:55.875155 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-03 00:19:55.876245 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-03 00:19:56.478936 | 
2026-01-03 00:19:56.479076 | PLAY [all]
2026-01-03 00:19:56.502372 | 
2026-01-03 00:19:56.502584 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-03 00:19:56.778633 | controller | changed: non-zero return code
2026-01-03 00:19:56.784637 | 
2026-01-03 00:19:56.784718 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-03 00:19:56.809119 | controller | skipping: Conditional result was False
2026-01-03 00:19:56.815684 | 
2026-01-03 00:19:56.815768 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-03 00:19:56.846917 | 
2026-01-03 00:19:56.847156 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-03 00:19:56.878256 | 
2026-01-03 00:19:56.878428 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-03 00:19:56.905101 | controller | skipping: Conditional result was False
2026-01-03 00:19:56.916652 | 
2026-01-03 00:19:56.916808 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-03 00:19:56.951487 | 
2026-01-03 00:19:56.951668 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-03 00:19:56.975899 | controller | skipping: Conditional result was False
2026-01-03 00:19:56.982514 | 
2026-01-03 00:19:56.982595 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-03 00:19:57.006362 | controller | skipping: Conditional result was False
2026-01-03 00:19:57.013452 | 
2026-01-03 00:19:57.013539 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-03 00:19:57.037625 | controller | skipping: Conditional result was False
2026-01-03 00:19:57.066052 | 
2026-01-03 00:19:57.066156 | PLAY RECAP
2026-01-03 00:19:57.066198 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-03 00:19:57.066220 | 
2026-01-03 00:19:57.168821 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-03 00:19:57.169794 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-03 00:19:57.759667 | 
2026-01-03 00:19:57.759802 | PLAY [all:!appliance*]
2026-01-03 00:19:57.787472 | 
2026-01-03 00:19:57.787604 | TASK [unregister the node]
2026-01-03 00:19:58.319618 | controller | skipping: Conditional result was False
2026-01-03 00:19:58.331106 | 
2026-01-03 00:19:58.331254 | TASK [include_role : fetch-output]
2026-01-03 00:19:58.363301 | controller | ok
2026-01-03 00:19:58.385000 | 
2026-01-03 00:19:58.385141 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-03 00:19:58.431422 | controller | skipping: Conditional result was False
2026-01-03 00:19:58.439174 | 
2026-01-03 00:19:58.439307 | TASK [fetch-output : Set log path for single node]
2026-01-03 00:19:58.479673 | controller | ok
2026-01-03 00:19:58.485231 | 
2026-01-03 00:19:58.485325 | LOOP [fetch-output : Ensure local output dirs]
2026-01-03 00:19:58.907171 | controller -> localhost | ok: "/var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/logs"
2026-01-03 00:19:59.173262 | controller -> localhost | changed: "/var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/artifacts"
2026-01-03 00:19:59.511932 | controller -> localhost | changed: "/var/lib/zuul/builds/d6841790dd4e4c68a4b18665e05a1d7c/work/docs"
2026-01-03 00:19:59.533088 | 
2026-01-03 00:19:59.533251 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-03 00:20:00.329329 | controller | changed:
2026-01-03 00:20:00.329625 | controller | .d..t...... ./
2026-01-03 00:20:00.329859 | controller | cd+++++++++ controller/
2026-01-03 00:20:00.329909 | controller | changed: All items complete
2026-01-03 00:20:00.329945 | 
2026-01-03 00:20:00.784370 | controller | changed: .d..t...... ./
2026-01-03 00:20:01.192312 | controller | changed: .d..t...... ./
2026-01-03 00:20:01.217492 | 
2026-01-03 00:20:01.217680 | TASK [include_role : fetch-output-openshift]
2026-01-03 00:20:01.234190 | controller | skipping: Conditional result was False
2026-01-03 00:20:01.243680 | 
2026-01-03 00:20:01.243837 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-03 00:20:01.269531 | controller | skipping: Conditional result was False
2026-01-03 00:20:01.280684 | controller | skipping: Conditional result was False
2026-01-03 00:20:01.324551 | 
2026-01-03 00:20:01.324730 | PLAY [localhost]
2026-01-03 00:20:01.337432 | 
2026-01-03 00:20:01.337504 | TASK [Run Zuul manifest role]
2026-01-03 00:20:01.355183 | localhost | ok
2026-01-03 00:20:01.382967 | 
2026-01-03 00:20:01.383121 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-03 00:20:01.752482 | localhost | changed
2026-01-03 00:20:01.768785 | 
2026-01-03 00:20:01.768927 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-03 00:20:01.797119 | localhost | ok
2026-01-03 00:20:01.805281 | 
2026-01-03 00:20:01.805340 | TASK [Set zuul-log-path fact]
2026-01-03 00:20:01.823597 | localhost | ok
2026-01-03 00:20:01.859764 | 
2026-01-03 00:20:01.859879 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-03 00:20:01.890622 | localhost | ok
2026-01-03 00:20:01.902746 | 
2026-01-03 00:20:01.902846 | LOOP [Run upload-logs-swift role]
2026-01-03 00:20:01.950340 | localhost | Output suppressed because no_log was given
2026-01-03 00:20:01.997043 | 
2026-01-03 00:20:01.997177 | TASK [Set zuul-log-path fact]
2026-01-03 00:20:02.023563 | localhost | skipping: Conditional result was False
2026-01-03 00:20:02.031313 | 
2026-01-03 00:20:02.031421 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-03 00:20:02.502372 | localhost -> localhost | ok: Runtime: 0:00:00.005622
2026-01-03 00:20:02.546889 | 
2026-01-03 00:20:02.547389 | TASK [upload-logs-swift : Upload logs to swift]