2026-01-20 00:06:40.820564 | Job console starting...
2026-01-20 00:06:40.839083 | Updating repositories
2026-01-20 00:06:41.075188 | Preparing job workspace
2026-01-20 00:06:49.587520 | Running Ansible setup...
2026-01-20 00:06:54.866008 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-20 00:06:55.471368 | 
2026-01-20 00:06:55.471532 | PLAY [localhost]
2026-01-20 00:06:55.480134 | 
2026-01-20 00:06:55.480210 | TASK [Gathering Facts]
2026-01-20 00:06:56.419792 | localhost | ok
2026-01-20 00:06:56.441116 | 
2026-01-20 00:06:56.441252 | TASK [Setup log path fact]
2026-01-20 00:06:56.459110 | localhost | ok
2026-01-20 00:06:56.473035 | 
2026-01-20 00:06:56.473124 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-20 00:06:56.500939 | localhost | ok
2026-01-20 00:06:56.509525 | 
2026-01-20 00:06:56.509604 | TASK [emit-job-header : Print job information]
2026-01-20 00:06:56.557924 | # Job Information
2026-01-20 00:06:56.558100 | Ansible Version: 2.15.12
2026-01-20 00:06:56.558133 | Job: ansible-test-sanity-docker-milestone
2026-01-20 00:06:56.558155 | Pipeline: periodic
2026-01-20 00:06:56.558174 | Executor: ze02.softwarefactory-project.io
2026-01-20 00:06:56.558192 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-20 00:06:56.558213 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/921/ansible/9211c145bc0340b8a64f4b7e290a5080/
2026-01-20 00:06:56.558232 | Event ID: 116c50ab7c10419082d19ef9dc1694bb
2026-01-20 00:06:56.562890 | 
2026-01-20 00:06:56.562958 | LOOP [emit-job-header : Print node information]
2026-01-20 00:06:56.666461 | localhost | ok:
2026-01-20 00:06:56.666600 | localhost | # Node Information
2026-01-20 00:06:56.666627 | localhost | Inventory Hostname: controller
2026-01-20 00:06:56.666648 | localhost | Hostname: np0005588425
2026-01-20 00:06:56.666672 | localhost | Username: zuul
2026-01-20 00:06:56.666715 | localhost | Distro: Fedora 37
2026-01-20 00:06:56.666736 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-20 00:06:56.666753 | localhost | Region: ca-ymq-1
2026-01-20 00:06:56.666770 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-20 00:06:56.666786 | localhost | Product Name: OpenStack Nova
2026-01-20 00:06:56.666803 | localhost | Interface IP: 162.253.55.227
2026-01-20 00:06:56.676932 | 
2026-01-20 00:06:56.677055 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-20 00:06:57.088116 | localhost -> localhost | changed
2026-01-20 00:06:57.096174 | 
2026-01-20 00:06:57.096248 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-20 00:06:58.325032 | localhost -> localhost | changed
2026-01-20 00:06:58.368262 | 
2026-01-20 00:06:58.368347 | PLAY [all:!appliance*]
2026-01-20 00:06:58.391807 | 
2026-01-20 00:06:58.391983 | TASK [include_role : start-zuul-console]
2026-01-20 00:06:58.416564 | controller | ok
2026-01-20 00:06:58.434607 | 
2026-01-20 00:06:58.434723 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-20 00:06:58.842292 | controller | ok
2026-01-20 00:06:58.853737 | 
2026-01-20 00:06:58.853843 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-20 00:07:21.348637 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-20 00:07:21.363790 | 
2026-01-20 00:07:21.363923 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-20 00:07:21.907792 | controller | skipping: Conditional result was False
2026-01-20 00:07:21.923002 | 
2026-01-20 00:07:21.923184 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-20 00:07:21.972715 | controller | skipping: Conditional result was False
2026-01-20 00:07:21.983930 | 
2026-01-20 00:07:21.984123 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-20 00:07:22.017838 | controller | skipping: Conditional result was False
2026-01-20 00:07:22.028910 | 
2026-01-20 00:07:22.029021 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-20 00:07:22.075186 | controller | skipping: Conditional result was False
2026-01-20 00:07:22.100263 | 
2026-01-20 00:07:22.100441 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-20 00:07:22.125017 | controller | skipping: Conditional result was False
2026-01-20 00:07:22.133363 | 
2026-01-20 00:07:22.133457 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-20 00:07:22.157922 | controller | skipping: Conditional result was False
2026-01-20 00:07:22.179868 | 
2026-01-20 00:07:22.180012 | TASK [Disable Fedora Modular]
2026-01-20 00:07:22.573103 | controller | changed
2026-01-20 00:07:22.587578 | 
2026-01-20 00:07:22.587754 | TASK [Enable EPEL]
2026-01-20 00:07:22.624411 | controller | skipping: Conditional result was False
2026-01-20 00:07:22.638659 | 
2026-01-20 00:07:22.638822 | TASK [Register the RHEL node]
2026-01-20 00:07:23.200501 | 
2026-01-20 00:07:23.200826 | TASK [Show the subscription-manager status]
2026-01-20 00:07:23.772690 | controller | skipping: Conditional result was False
2026-01-20 00:07:23.781431 | 
2026-01-20 00:07:23.781525 | TASK [Enable EPEL on RHEL]
2026-01-20 00:07:23.856381 | controller | skipping: Conditional result was False
2026-01-20 00:07:23.862885 | 
2026-01-20 00:07:23.862969 | TASK [Install git and tox]
2026-01-20 00:08:17.367419 | controller | changed
2026-01-20 00:08:17.373724 | 
2026-01-20 00:08:17.373784 | TASK [include_role : prepare-workspace]
2026-01-20 00:08:17.393237 | controller | ok
2026-01-20 00:08:17.414010 | 
2026-01-20 00:08:17.414086 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-20 00:08:17.647936 | controller | ok
2026-01-20 00:08:17.656484 | 
2026-01-20 00:08:17.657013 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-20 00:08:32.354018 | controller | Output suppressed because no_log was given
2026-01-20 00:08:32.402166 | 
2026-01-20 00:08:32.402297 | TASK [include_role : prepare-workspace-openshift]
2026-01-20 00:08:32.426716 | controller | skipping: Conditional result was False
2026-01-20 00:08:32.448223 | 
2026-01-20 00:08:32.448296 | PLAY [all:!appliance]
2026-01-20 00:08:32.464078 | 
2026-01-20 00:08:32.464146 | TASK [Run add-build-sshkey role (RSA)]
2026-01-20 00:08:32.493859 | controller | ok
2026-01-20 00:08:32.508256 | 
2026-01-20 00:08:32.508319 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-20 00:08:32.774836 | controller -> localhost | ok
2026-01-20 00:08:32.781558 | 
2026-01-20 00:08:32.781636 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-20 00:08:32.802453 | controller | ok
2026-01-20 00:08:32.816354 | controller | included: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-20 00:08:32.822794 | 
2026-01-20 00:08:32.822861 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-20 00:08:33.530367 | controller -> localhost | Generating public/private rsa key pair.
2026-01-20 00:08:33.530777 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/9211c145bc0340b8a64f4b7e290a5080_id_rsa.
2026-01-20 00:08:33.530845 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/9211c145bc0340b8a64f4b7e290a5080_id_rsa.pub.
2026-01-20 00:08:33.530892 | controller -> localhost | The key fingerprint is:
2026-01-20 00:08:33.530937 | controller -> localhost | SHA256:jVcEeJxGDjHshZz6B3havv6Z+uU81hXL+WTOvl9E1Qs zuul-build-sshkey
2026-01-20 00:08:33.530980 | controller -> localhost | The key's randomart image is:
2026-01-20 00:08:33.531022 | controller -> localhost | +---[RSA 2048]----+
2026-01-20 00:08:33.531063 | controller -> localhost | |       o+Boo.   o|
2026-01-20 00:08:33.531105 | controller -> localhost | |        *+*. E  o|
2026-01-20 00:08:33.531147 | controller -> localhost | |       + +. . . o|
2026-01-20 00:08:33.531188 | controller -> localhost | |      o =o .   + |
2026-01-20 00:08:33.531228 | controller -> localhost | |       *S.o   . =|
2026-01-20 00:08:33.531284 | controller -> localhost | |      . o..    =+|
2026-01-20 00:08:33.531333 | controller -> localhost | |         o  .. *o|
2026-01-20 00:08:33.531380 | controller -> localhost | |        .  *o . =|
2026-01-20 00:08:33.531422 | controller -> localhost | |       .o+=.o. o=|
2026-01-20 00:08:33.531484 | controller -> localhost | +----[SHA256]-----+
2026-01-20 00:08:33.531611 | controller -> localhost | ok: Runtime: 0:00:00.313159
2026-01-20 00:08:33.549499 | 
2026-01-20 00:08:33.549735 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-20 00:08:33.587555 | controller | ok
2026-01-20 00:08:33.601979 | controller | included: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-20 00:08:33.616013 | 
2026-01-20 00:08:33.616130 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-20 00:08:33.643020 | controller | skipping: Conditional result was False
2026-01-20 00:08:33.649570 | 
2026-01-20 00:08:33.649652 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-20 00:08:34.085577 | controller | changed
2026-01-20 00:08:34.092875 | 
2026-01-20 00:08:34.092947 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-20 00:08:34.345550 | controller | ok
2026-01-20 00:08:34.359773 | 
2026-01-20 00:08:34.359931 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-20 00:08:35.038803 | controller | changed
2026-01-20 00:08:35.051773 | 
2026-01-20 00:08:35.051914 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-20 00:08:35.718290 | controller | changed
2026-01-20 00:08:35.731875 | 
2026-01-20 00:08:35.732013 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-20 00:08:35.759730 | controller | skipping: Conditional result was False
2026-01-20 00:08:35.767633 | 
2026-01-20 00:08:35.767769 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-20 00:08:36.168733 | controller -> localhost | changed
2026-01-20 00:08:36.183042 | 
2026-01-20 00:08:36.183528 | TASK [add-build-sshkey : Add back temp key]
2026-01-20 00:08:36.444891 | controller -> localhost | Identity added: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/9211c145bc0340b8a64f4b7e290a5080_id_rsa (zuul-build-sshkey)
2026-01-20 00:08:36.445109 | controller -> localhost | ok: Runtime: 0:00:00.008560
2026-01-20 00:08:36.452912 | 
2026-01-20 00:08:36.453001 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-20 00:08:36.848122 | controller | ok
2026-01-20 00:08:36.866499 | 
2026-01-20 00:08:36.866938 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-20 00:08:36.907475 | controller | skipping: Conditional result was False
2026-01-20 00:08:36.928207 | 
2026-01-20 00:08:36.928342 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-20 00:08:36.965812 | controller | ok
2026-01-20 00:08:37.019139 | 
2026-01-20 00:08:37.019282 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-20 00:08:37.279623 | controller -> localhost | ok
2026-01-20 00:08:37.287343 | 
2026-01-20 00:08:37.287429 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-20 00:08:37.330166 | controller | ok
2026-01-20 00:08:37.345568 | controller | included: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-20 00:08:37.353442 | 
2026-01-20 00:08:37.353555 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-20 00:08:37.664911 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-20 00:08:37.665218 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/9211c145bc0340b8a64f4b7e290a5080_id_ecdsa.
2026-01-20 00:08:37.665277 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/9211c145bc0340b8a64f4b7e290a5080_id_ecdsa.pub.
2026-01-20 00:08:37.665319 | controller -> localhost | The key fingerprint is:
2026-01-20 00:08:37.665350 | controller -> localhost | SHA256:MTODFhRQfw3BWBjyrdmgcxa3Z79TS2kJScWbKO6Qsks zuul-build-sshkey
2026-01-20 00:08:37.665380 | controller -> localhost | The key's randomart image is:
2026-01-20 00:08:37.665409 | controller -> localhost | +---[ECDSA 521]---+
2026-01-20 00:08:37.665438 | controller -> localhost | |    .+*..*+.  o. |
2026-01-20 00:08:37.665468 | controller -> localhost | |       *o..o . . |
2026-01-20 00:08:37.665503 | controller -> localhost | |      o @ + o o o|
2026-01-20 00:08:37.665540 | controller -> localhost | |     . . # o + o |
2026-01-20 00:08:37.665577 | controller -> localhost | |      o S = + . o|
2026-01-20 00:08:37.665613 | controller -> localhost | |       = o + . =.|
2026-01-20 00:08:37.665650 | controller -> localhost | |       Eo o   +..|
2026-01-20 00:08:37.665720 | controller -> localhost | |      ..   .  .o |
2026-01-20 00:08:37.665761 | controller -> localhost | |       ..     .. |
2026-01-20 00:08:37.665798 | controller -> localhost | +----[SHA256]-----+
2026-01-20 00:08:37.665889 | controller -> localhost | ok: Runtime: 0:00:00.008723
2026-01-20 00:08:37.678476 | 
2026-01-20 00:08:37.678613 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-20 00:08:37.706034 | controller | ok
2026-01-20 00:08:37.716840 | controller | included: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-20 00:08:37.728976 | 
2026-01-20 00:08:37.729088 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-20 00:08:37.753926 | controller | skipping: Conditional result was False
2026-01-20 00:08:37.761952 | 
2026-01-20 00:08:37.762063 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-20 00:08:38.049337 | controller | changed
2026-01-20 00:08:38.060524 | 
2026-01-20 00:08:38.060686 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-20 00:08:38.277207 | controller | ok
2026-01-20 00:08:38.285293 | 
2026-01-20 00:08:38.285361 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-20 00:08:38.916571 | controller | changed
2026-01-20 00:08:38.929978 | 
2026-01-20 00:08:38.930169 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-20 00:08:39.616359 | controller | changed
2026-01-20 00:08:39.630736 | 
2026-01-20 00:08:39.630898 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-20 00:08:39.668709 | controller | skipping: Conditional result was False
2026-01-20 00:08:39.718192 | 
2026-01-20 00:08:39.718308 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-20 00:08:39.997530 | controller -> localhost | changed
2026-01-20 00:08:40.028795 | 
2026-01-20 00:08:40.028937 | TASK [add-build-sshkey : Add back temp key]
2026-01-20 00:08:40.362987 | controller -> localhost | Identity added: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/9211c145bc0340b8a64f4b7e290a5080_id_ecdsa (zuul-build-sshkey)
2026-01-20 00:08:40.363394 | controller -> localhost | ok: Runtime: 0:00:00.014092
2026-01-20 00:08:40.378387 | 
2026-01-20 00:08:40.378520 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-20 00:08:40.623705 | controller | ok
2026-01-20 00:08:40.639556 | 
2026-01-20 00:08:40.639720 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-20 00:08:40.688420 | controller | skipping: Conditional result was False
2026-01-20 00:08:40.714163 | 
2026-01-20 00:08:40.714295 | TASK [include_role : remove-zuul-sshkey]
2026-01-20 00:08:40.742105 | controller | skipping: Conditional result was False
2026-01-20 00:08:40.752926 | 
2026-01-20 00:08:40.753035 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-20 00:08:41.004403 | controller | ok: "logs"
2026-01-20 00:08:41.004786 | controller | ok: All items complete
2026-01-20 00:08:41.004835 | 
2026-01-20 00:08:41.221511 | controller | ok: "artifacts"
2026-01-20 00:08:41.415394 | controller | ok: "docs"
2026-01-20 00:08:41.433629 | 
2026-01-20 00:08:41.433772 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-20 00:08:41.661314 | controller | changed: "logs"
2026-01-20 00:08:41.851907 | controller | changed: "artifacts"
2026-01-20 00:08:42.050537 | controller | changed: "docs"
2026-01-20 00:08:42.087351 | 
2026-01-20 00:08:42.087443 | PLAY RECAP
2026-01-20 00:08:42.087486 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-20 00:08:42.087513 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-20 00:08:42.087532 | 
2026-01-20 00:08:42.194309 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-20 00:08:42.195183 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-20 00:08:42.863473 | 
2026-01-20 00:08:42.864763 | PLAY [all]
2026-01-20 00:08:42.890730 | 
2026-01-20 00:08:42.890835 | TASK [Install binary dependencies]
2026-01-20 00:08:42.991176 | controller | ok
2026-01-20 00:08:43.012204 | 
2026-01-20 00:08:43.012319 | TASK [bindep : Include find tasks]
2026-01-20 00:08:43.041789 | controller | ok
2026-01-20 00:08:43.049723 | controller | included: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-20 00:08:43.056005 | 
2026-01-20 00:08:43.056070 | TASK [bindep : Look for bindep.txt]
2026-01-20 00:08:43.434612 | controller | ok
2026-01-20 00:08:43.442009 | 
2026-01-20 00:08:43.442105 | TASK [bindep : Define bindep_file fact]
2026-01-20 00:08:43.476598 | controller | skipping: Conditional result was False
2026-01-20 00:08:43.486038 | 
2026-01-20 00:08:43.486153 | TASK [bindep : Look for other-requirements.txt]
2026-01-20 00:08:43.712347 | controller | ok
2026-01-20 00:08:43.719980 | 
2026-01-20 00:08:43.720092 | TASK [bindep : Define bindep_file fact]
2026-01-20 00:08:43.744489 | controller | skipping: Conditional result was False
2026-01-20 00:08:43.752599 | 
2026-01-20 00:08:43.752724 | TASK [bindep : Look for bindep fallback file]
2026-01-20 00:08:43.788467 | controller | skipping: Conditional result was False
2026-01-20 00:08:43.797430 | 
2026-01-20 00:08:43.797521 | TASK [bindep : Define bindep_file fact]
2026-01-20 00:08:43.821985 | controller | skipping: Conditional result was False
2026-01-20 00:08:43.830116 | 
2026-01-20 00:08:43.830215 | TASK [bindep : Include bindep tasks]
2026-01-20 00:08:43.857976 | controller | skipping: Conditional result was False
2026-01-20 00:08:43.866475 | 
2026-01-20 00:08:43.866583 | TASK [bindep : Include install tasks]
2026-01-20 00:08:43.893858 | controller | skipping: Conditional result was False
2026-01-20 00:08:43.901511 | 
2026-01-20 00:08:43.901591 | LOOP [bindep : Include package tasks]
2026-01-20 00:08:43.969851 | 
2026-01-20 00:08:43.970006 | TASK [Run test-setup role]
2026-01-20 00:08:43.992253 | controller | ok
2026-01-20 00:08:44.015143 | 
2026-01-20 00:08:44.015278 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-20 00:08:44.219517 | controller | ok
2026-01-20 00:08:44.235116 | 
2026-01-20 00:08:44.235226 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-20 00:08:44.782749 | controller | skipping: Conditional result was False
2026-01-20 00:08:44.829637 | 
2026-01-20 00:08:44.829759 | PLAY RECAP
2026-01-20 00:08:44.829802 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-20 00:08:44.829822 | 
2026-01-20 00:08:44.954857 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-20 00:08:44.955806 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-20 00:08:45.571483 | 
2026-01-20 00:08:45.571616 | PLAY [controller]
2026-01-20 00:08:45.592776 | 
2026-01-20 00:08:45.592906 | TASK [Create the /root directory]
2026-01-20 00:08:45.975644 | controller | ok
2026-01-20 00:08:46.002619 | 
2026-01-20 00:08:46.002795 | TASK [Install glibc-langpack-en]
2026-01-20 00:08:50.023723 | controller | ok: Nothing to do
2026-01-20 00:08:50.030505 | 
2026-01-20 00:08:50.030582 | TASK [Ensure controller directory exists]
2026-01-20 00:08:50.231574 | controller | changed
2026-01-20 00:08:50.239319 | 
2026-01-20 00:08:50.239456 | TASK [Install container runtime]
2026-01-20 00:08:50.290833 | controller | ok
2026-01-20 00:08:50.335280 | 
2026-01-20 00:08:50.335383 | LOOP [ensure-podman : Find distribution installation]
2026-01-20 00:08:50.359450 | controller | ok: "/var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-20 00:08:50.377292 | controller | included: /var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-20 00:08:50.383870 | 
2026-01-20 00:08:50.383938 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-20 00:09:56.539876 | controller | changed
2026-01-20 00:09:56.548310 | 
2026-01-20 00:09:56.548424 | TASK [ensure-podman : Fetch podman version]
2026-01-20 00:09:57.063609 | controller | Client:       Podman Engine
2026-01-20 00:09:57.095140 | controller | Version:      4.6.2
2026-01-20 00:09:57.095185 | controller | API Version:  4.6.2
2026-01-20 00:09:57.095198 | controller | Go Version:   go1.19.12
2026-01-20 00:09:57.095222 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-20 00:09:57.095235 | controller | OS/Arch:      linux/amd64
2026-01-20 00:09:57.589042 | controller | ok: Runtime: 0:00:00.187571
2026-01-20 00:09:57.595485 | 
2026-01-20 00:09:57.595566 | TASK [ensure-podman : Print podman version installed]
2026-01-20 00:09:57.624935 | Podman version: Client:       Podman Engine
2026-01-20 00:09:57.625090 | Version:      4.6.2
2026-01-20 00:09:57.625122 | API Version:  4.6.2
2026-01-20 00:09:57.625146 | Go Version:   go1.19.12
2026-01-20 00:09:57.625188 | Built:        Mon Aug 28 19:38:31 2023
2026-01-20 00:09:57.625209 | OS/Arch:      linux/amd64
2026-01-20 00:09:57.631106 | 
2026-01-20 00:09:57.631199 | TASK [ensure-podman : Validate podman engine]
2026-01-20 00:09:58.162106 | controller | skipping: Conditional result was False
2026-01-20 00:09:58.177927 | 
2026-01-20 00:09:58.178194 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-20 00:09:58.204020 | controller | skipping: Conditional result was False
2026-01-20 00:09:58.227966 | 
2026-01-20 00:09:58.228121 | TASK [Ensure python3.8 is present]
2026-01-20 00:09:58.254375 | controller | skipping: Conditional result was False
2026-01-20 00:09:58.267864 | 
2026-01-20 00:09:58.268009 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-20 00:09:58.296167 | controller | ok
2026-01-20 00:09:58.324324 | 
2026-01-20 00:09:58.324414 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-20 00:09:59.715060 | controller | ok: Nothing to do
2026-01-20 00:09:59.729419 | 
2026-01-20 00:09:59.729619 | TASK [our-ensure-python : Also install python3-devel]
2026-01-20 00:10:09.167416 | controller | changed
2026-01-20 00:10:09.191499 | 
2026-01-20 00:10:09.191635 | TASK [Run ensure-virtualenv role]
2026-01-20 00:10:09.215059 | controller | ok
2026-01-20 00:10:09.243778 | 
2026-01-20 00:10:09.243881 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-20 00:10:09.493123 | controller | /usr/bin/virtualenv
2026-01-20 00:10:09.803435 | controller | ok: Runtime: 0:00:00.005518
2026-01-20 00:10:09.809312 | 
2026-01-20 00:10:09.809372 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-20 00:10:09.842385 | controller | skipping: Conditional result was False
2026-01-20 00:10:09.842855 | controller | ok: All items complete
2026-01-20 00:10:09.842915 | 
2026-01-20 00:10:09.864417 | 
2026-01-20 00:10:09.864512 | TASK [Find the full path of the Python interpreter]
2026-01-20 00:10:10.082334 | controller | /usr/bin/python3
2026-01-20 00:10:10.394869 | controller | ok
2026-01-20 00:10:10.414492 | 
2026-01-20 00:10:10.414818 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-20 00:10:11.283540 | controller | created virtual environment CPython3.11.0.final.0-64 in 515ms
2026-01-20 00:10:11.311226 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-20 00:10:11.311475 | 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-20 00:10:11.311528 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-20 00:10:11.311542 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-20 00:10:11.475176 | controller | changed
2026-01-20 00:10:11.488822 | 
2026-01-20 00:10:11.488987 | TASK [Set selinux package]
2026-01-20 00:10:11.527679 | controller | ok
2026-01-20 00:10:11.539409 | 
2026-01-20 00:10:11.539541 | TASK [Set selinux package (Fedora)]
2026-01-20 00:10:11.599181 | controller | ok
2026-01-20 00:10:11.610649 | 
2026-01-20 00:10:11.610805 | TASK [Install selinux into virtualenv]
2026-01-20 00:10:25.161861 | controller | Collecting selinux-please-lie-to-me
2026-01-20 00:10:37.391932 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-20 00:10:37.786740 | controller | Collecting setuptools<50.0.0
2026-01-20 00:10:37.879675 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-20 00:10:37.919002 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 22.9 MB/s eta 0:00:00
2026-01-20 00:10:37.999460 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-20 00:10:37.999672 | controller |   Attempting uninstall: setuptools
2026-01-20 00:10:38.002095 | controller |     Found existing installation: setuptools 62.6.0
2026-01-20 00:10:38.062767 | controller |     Uninstalling setuptools-62.6.0:
2026-01-20 00:10:38.070651 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-20 00:10:38.407251 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-20 00:10:49.731193 | controller |
2026-01-20 00:10:49.817637 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-20 00:10:49.817680 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-20 00:10:50.186571 | controller | ok: Runtime: 0:00:37.982142
2026-01-20 00:10:50.192782 | 
2026-01-20 00:10:50.192847 | TASK [Install pytest-forked into virtualenv]
2026-01-20 00:11:02.018560 | controller | Collecting pytest-forked
2026-01-20 00:11:14.273679 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-20 00:11:14.328640 | controller | Collecting py
2026-01-20 00:11:14.367601 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-20 00:11:14.385710 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.8 MB/s eta 0:00:00
2026-01-20 00:11:14.508915 | controller | Collecting pytest>=3.10
2026-01-20 00:11:14.585004 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-20 00:11:14.609066 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 18.8 MB/s eta 0:00:00
2026-01-20 00:11:14.645748 | controller | Collecting iniconfig>=1.0.1
2026-01-20 00:11:14.723241 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-20 00:11:14.783235 | controller | Collecting packaging>=22
2026-01-20 00:11:14.845148 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-20 00:11:14.862519 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 4.0 MB/s eta 0:00:00
2026-01-20 00:11:14.950837 | controller | Collecting pluggy<2,>=1.5
2026-01-20 00:11:14.996478 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-20 00:11:15.050121 | controller | Collecting pygments>=2.7.2
2026-01-20 00:11:15.131313 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-20 00:11:15.165146 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 42.9 MB/s eta 0:00:00
2026-01-20 00:11:15.238195 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-20 00:11:16.289116 | 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-20 00:11:16.298106 | controller |
2026-01-20 00:11:16.369768 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-20 00:11:16.369912 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-20 00:11:16.755869 | controller | ok: Runtime: 0:00:25.964712
2026-01-20 00:11:16.770644 | 
2026-01-20 00:11:16.770923 | TASK [Update pip]
2026-01-20 00:11:17.319949 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-20 00:11:29.762911 | controller | Collecting pip
2026-01-20 00:11:42.086484 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-20 00:11:42.146147 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.0 MB/s eta 0:00:00
2026-01-20 00:11:42.213556 | controller | Installing collected packages: pip
2026-01-20 00:11:42.213686 | controller |   Attempting uninstall: pip
2026-01-20 00:11:42.215853 | controller |     Found existing installation: pip 22.2.2
2026-01-20 00:11:42.361346 | controller |     Uninstalling pip-22.2.2:
2026-01-20 00:11:42.376841 | controller |       Successfully uninstalled pip-22.2.2
2026-01-20 00:11:43.209719 | controller | Successfully installed pip-25.3
2026-01-20 00:11:43.350861 | controller | ok: Runtime: 0:00:26.260339
2026-01-20 00:11:43.359776 | 
2026-01-20 00:11:43.359903 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-20 00:11:43.584124 | controller | changed
2026-01-20 00:11:43.597949 | 
2026-01-20 00:11:43.598103 | TASK [Install ansible into virtualenv]
2026-01-20 00:11:44.163654 | controller | Processing ./src/github.com/ansible/ansible
2026-01-20 00:11:44.166932 | controller |   Installing build dependencies: started
2026-01-20 00:12:07.118113 | controller |   Installing build dependencies: finished with status 'done'
2026-01-20 00:12:07.119273 | controller |   Getting requirements to build wheel: started
2026-01-20 00:12:07.875127 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-20 00:12:07.875843 | controller |   Preparing metadata (pyproject.toml): started
2026-01-20 00:12:08.338848 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-20 00:12:08.344284 | 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-20 00:12:08.348453 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-20 00:12:08.703373 | controller | ERROR
2026-01-20 00:12:08.703524 | controller | {
2026-01-20 00:12:08.703566 | controller |   "delta": "0:00:24.544304",
2026-01-20 00:12:08.703596 | controller |   "end": "2026-01-20 00:12:08.421375",
2026-01-20 00:12:08.703630 | controller |   "msg": "non-zero return code",
2026-01-20 00:12:08.703710 | controller |   "rc": 1,
2026-01-20 00:12:08.703748 | controller |   "start": "2026-01-20 00:11:43.877071"
2026-01-20 00:12:08.703775 | controller | }
failure
2026-01-20 00:12:08.705838 | 
2026-01-20 00:12:08.705918 | PLAY RECAP
2026-01-20 00:12:08.705993 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-20 00:12:08.706036 | 
2026-01-20 00:12:08.835581 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-20 00:12:08.836508 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-20 00:12:09.527437 | 
2026-01-20 00:12:09.527570 | PLAY [all]
2026-01-20 00:12:09.549638 | 
2026-01-20 00:12:09.549755 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-20 00:12:09.845719 | controller | changed: non-zero return code
2026-01-20 00:12:09.851639 | 
2026-01-20 00:12:09.851728 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-20 00:12:09.865424 | controller | skipping: Conditional result was False
2026-01-20 00:12:09.872054 | 
2026-01-20 00:12:09.872150 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-20 00:12:09.894063 | 
2026-01-20 00:12:09.894290 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-20 00:12:09.915995 | 
2026-01-20 00:12:09.916227 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-20 00:12:09.932944 | controller | skipping: Conditional result was False
2026-01-20 00:12:09.941930 | 
2026-01-20 00:12:09.942042 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-20 00:12:09.965059 | 
2026-01-20 00:12:09.965299 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-20 00:12:09.982848 | controller | skipping: Conditional result was False
2026-01-20 00:12:09.989649 | 
2026-01-20 00:12:09.989750 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-20 00:12:10.016319 | controller | skipping: Conditional result was False
2026-01-20 00:12:10.023499 | 
2026-01-20 00:12:10.023578 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-20 00:12:10.036970 | controller | skipping: Conditional result was False
2026-01-20 00:12:10.068065 | 
2026-01-20 00:12:10.068149 | PLAY RECAP
2026-01-20 00:12:10.068187 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-20 00:12:10.068208 | 
2026-01-20 00:12:10.158076 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-20 00:12:10.158923 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-20 00:12:12.073062 | 
2026-01-20 00:12:12.073191 | PLAY [all:!appliance*]
2026-01-20 00:12:12.096346 | 
2026-01-20 00:12:12.096458 | TASK [unregister the node]
2026-01-20 00:12:12.631964 | controller | skipping: Conditional result was False
2026-01-20 00:12:12.638069 | 
2026-01-20 00:12:12.638171 | TASK [include_role : fetch-output]
2026-01-20 00:12:12.683880 | controller | ok
2026-01-20 00:12:12.714060 | 
2026-01-20 00:12:12.714193 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-20 00:12:12.770727 | controller | skipping: Conditional result was False
2026-01-20 00:12:12.778282 | 
2026-01-20 00:12:12.778414 | TASK [fetch-output : Set log path for single node]
2026-01-20 00:12:12.818752 | controller | ok
2026-01-20 00:12:12.824710 | 
2026-01-20 00:12:12.824808 | LOOP [fetch-output : Ensure local output dirs]
2026-01-20 00:12:13.213491 | controller -> localhost | ok: "/var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/logs"
2026-01-20 00:12:13.487384 | controller -> localhost | changed: "/var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/artifacts"
2026-01-20 00:12:13.767692 | controller -> localhost | changed: "/var/lib/zuul/builds/9211c145bc0340b8a64f4b7e290a5080/work/docs"
2026-01-20 00:12:13.784023 | 
2026-01-20 00:12:13.784124 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-20 00:12:14.454568 | controller | changed:
2026-01-20 00:12:14.454968 | controller | .d..t...... ./
2026-01-20 00:12:14.454998 | controller | cd+++++++++ controller/
2026-01-20 00:12:14.455032 | controller | changed: All items complete
2026-01-20 00:12:14.455054 | 
2026-01-20 00:12:14.885304 | controller | changed: .d..t...... ./
2026-01-20 00:12:15.318745 | controller | changed: .d..t...... ./
2026-01-20 00:12:15.339989 | 
2026-01-20 00:12:15.340121 | TASK [include_role : fetch-output-openshift]
2026-01-20 00:12:15.368351 | controller | skipping: Conditional result was False
2026-01-20 00:12:15.375776 | 
2026-01-20 00:12:15.375858 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-20 00:12:15.418012 | controller | skipping: Conditional result was False
2026-01-20 00:12:15.420907 | controller | skipping: Conditional result was False
2026-01-20 00:12:15.479876 | 
2026-01-20 00:12:15.479974 | PLAY [localhost]
2026-01-20 00:12:15.494999 | 
2026-01-20 00:12:15.495078 | TASK [Run Zuul manifest role]
2026-01-20 00:12:15.522561 | localhost | ok
2026-01-20 00:12:15.536966 | 
2026-01-20 00:12:15.537059 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-20 00:12:15.872162 | localhost | changed
2026-01-20 00:12:15.876687 | 
2026-01-20 00:12:15.876751 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-20 00:12:15.930169 | localhost | ok
2026-01-20 00:12:15.946323 | 
2026-01-20 00:12:15.946467 | TASK [Set zuul-log-path fact]
2026-01-20 00:12:15.968627 | localhost | ok
2026-01-20 00:12:15.989038 | 
2026-01-20 00:12:15.989148 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-20 00:12:16.017740 | localhost | ok
2026-01-20 00:12:16.026188 | 
2026-01-20 00:12:16.026271 | LOOP [Run upload-logs-swift role]
2026-01-20 00:12:16.050380 | localhost | Output suppressed because no_log was given
2026-01-20 00:12:16.088807 | 
2026-01-20 00:12:16.088924 | TASK [Set zuul-log-path fact]
2026-01-20 00:12:16.113481 | localhost | skipping: Conditional result was False
2026-01-20 00:12:16.118999 | 
2026-01-20 00:12:16.119077 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-20 00:12:16.532066 | localhost -> localhost | ok: Runtime: 0:00:00.012730
2026-01-20 00:12:16.564293 | 
2026-01-20 00:12:16.564417 | TASK [upload-logs-swift : Upload logs to swift]