2026-01-23 00:20:02.162986 | Job console starting...
2026-01-23 00:20:02.173383 | Updating repositories
2026-01-23 00:20:02.324858 | Preparing job workspace
2026-01-23 00:20:06.209570 | Running Ansible setup...
2026-01-23 00:20:10.521954 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-23 00:20:11.117513 | 
2026-01-23 00:20:11.117631 | PLAY [localhost]
2026-01-23 00:20:11.126155 | 
2026-01-23 00:20:11.126228 | TASK [Gathering Facts]
2026-01-23 00:20:12.094912 | localhost | ok
2026-01-23 00:20:12.108422 | 
2026-01-23 00:20:12.108498 | TASK [Setup log path fact]
2026-01-23 00:20:12.127183 | localhost | ok
2026-01-23 00:20:12.139278 | 
2026-01-23 00:20:12.139344 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-23 00:20:12.180983 | localhost | ok
2026-01-23 00:20:12.195398 | 
2026-01-23 00:20:12.195492 | TASK [emit-job-header : Print job information]
2026-01-23 00:20:12.246308 | # Job Information
2026-01-23 00:20:12.246491 | Ansible Version: 2.15.12
2026-01-23 00:20:12.246537 | Job: ansible-test-sanity-docker-devel
2026-01-23 00:20:12.246569 | Pipeline: periodic
2026-01-23 00:20:12.246596 | Executor: ze04.softwarefactory-project.io
2026-01-23 00:20:12.246623 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-23 00:20:12.246657 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/0c7/ansible/0c7b8d9d3c1c4e4cbdb39572f971c3b2/
2026-01-23 00:20:12.246712 | Event ID: fb76f19001064f93b4e01b68aefdba99
2026-01-23 00:20:12.252127 | 
2026-01-23 00:20:12.252217 | LOOP [emit-job-header : Print node information]
2026-01-23 00:20:12.362855 | localhost | ok:
2026-01-23 00:20:12.363089 | localhost | # Node Information
2026-01-23 00:20:12.363126 | localhost | Inventory Hostname: controller
2026-01-23 00:20:12.363153 | localhost | Hostname: np0005592938
2026-01-23 00:20:12.363174 | localhost | Username: zuul
2026-01-23 00:20:12.363197 | localhost | Distro: Fedora 37
2026-01-23 00:20:12.363217 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-23 00:20:12.363236 | localhost | Region: ca-ymq-1
2026-01-23 00:20:12.363253 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-23 00:20:12.363271 | localhost | Product Name: OpenStack Nova
2026-01-23 00:20:12.363288 | localhost | Interface IP: 199.204.45.35
2026-01-23 00:20:12.378813 | 
2026-01-23 00:20:12.378946 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-23 00:20:12.801435 | localhost -> localhost | changed
2026-01-23 00:20:12.815142 | 
2026-01-23 00:20:12.815331 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-23 00:20:13.709007 | localhost -> localhost | changed
2026-01-23 00:20:13.752108 | 
2026-01-23 00:20:13.752350 | PLAY [all:!appliance*]
2026-01-23 00:20:13.784482 | 
2026-01-23 00:20:13.784644 | TASK [include_role : start-zuul-console]
2026-01-23 00:20:13.808315 | controller | ok
2026-01-23 00:20:13.827658 | 
2026-01-23 00:20:13.827766 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-23 00:20:14.201011 | controller | ok
2026-01-23 00:20:14.227378 | 
2026-01-23 00:20:14.227520 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-23 00:20:37.212998 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-23 00:20:37.224586 | 
2026-01-23 00:20:37.224671 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-23 00:20:37.760982 | controller | skipping: Conditional result was False
2026-01-23 00:20:37.775406 | 
2026-01-23 00:20:37.776028 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-23 00:20:37.793445 | controller | skipping: Conditional result was False
2026-01-23 00:20:37.817172 | 
2026-01-23 00:20:37.817322 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-23 00:20:37.834889 | controller | skipping: Conditional result was False
2026-01-23 00:20:37.841673 | 
2026-01-23 00:20:37.841795 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-23 00:20:37.866387 | controller | skipping: Conditional result was False
2026-01-23 00:20:37.873645 | 
2026-01-23 00:20:37.873771 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-23 00:20:37.888978 | controller | skipping: Conditional result was False
2026-01-23 00:20:37.896051 | 
2026-01-23 00:20:37.896163 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-23 00:20:37.911155 | controller | skipping: Conditional result was False
2026-01-23 00:20:37.925088 | 
2026-01-23 00:20:37.925206 | TASK [Disable Fedora Modular]
2026-01-23 00:20:38.248589 | controller | changed
2026-01-23 00:20:38.261739 | 
2026-01-23 00:20:38.261903 | TASK [Enable EPEL]
2026-01-23 00:20:38.290044 | controller | skipping: Conditional result was False
2026-01-23 00:20:38.299249 | 
2026-01-23 00:20:38.299376 | TASK [Register the RHEL node]
2026-01-23 00:20:38.871848 | 
2026-01-23 00:20:38.872195 | TASK [Show the subscription-manager status]
2026-01-23 00:20:39.437018 | controller | skipping: Conditional result was False
2026-01-23 00:20:39.458599 | 
2026-01-23 00:20:39.458876 | TASK [Enable EPEL on RHEL]
2026-01-23 00:20:39.522865 | controller | skipping: Conditional result was False
2026-01-23 00:20:39.532144 | 
2026-01-23 00:20:39.532245 | TASK [Install git and tox]
2026-01-23 00:21:31.490010 | controller | changed
2026-01-23 00:21:31.504735 | 
2026-01-23 00:21:31.504857 | TASK [include_role : prepare-workspace]
2026-01-23 00:21:31.546612 | controller | ok
2026-01-23 00:21:31.586070 | 
2026-01-23 00:21:31.586177 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-23 00:21:31.849025 | controller | ok
2026-01-23 00:21:31.864570 | 
2026-01-23 00:21:31.864749 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-23 00:21:44.615365 | controller | Output suppressed because no_log was given
2026-01-23 00:21:44.629788 | 
2026-01-23 00:21:44.629875 | TASK [include_role : prepare-workspace-openshift]
2026-01-23 00:21:44.655143 | controller | skipping: Conditional result was False
2026-01-23 00:21:44.688394 | 
2026-01-23 00:21:44.688479 | PLAY [all:!appliance]
2026-01-23 00:21:44.732629 | 
2026-01-23 00:21:44.732754 | TASK [Run add-build-sshkey role (RSA)]
2026-01-23 00:21:44.763764 | controller | ok
2026-01-23 00:21:44.778769 | 
2026-01-23 00:21:44.778835 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-23 00:21:45.069612 | controller -> localhost | ok
2026-01-23 00:21:45.077957 | 
2026-01-23 00:21:45.078035 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-23 00:21:45.100776 | controller | ok
2026-01-23 00:21:45.117907 | controller | included: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-23 00:21:45.124173 | 
2026-01-23 00:21:45.124241 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-23 00:21:45.533963 | controller -> localhost | Generating public/private rsa key pair.
2026-01-23 00:21:45.534447 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/0c7b8d9d3c1c4e4cbdb39572f971c3b2_id_rsa.
2026-01-23 00:21:45.534530 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/0c7b8d9d3c1c4e4cbdb39572f971c3b2_id_rsa.pub.
2026-01-23 00:21:45.534593 | controller -> localhost | The key fingerprint is:
2026-01-23 00:21:45.534651 | controller -> localhost | SHA256:A0ofLYizEy65TgUuCbjr97WDZQZmxDvPOD136zXGJrA zuul-build-sshkey
2026-01-23 00:21:45.534788 | controller -> localhost | The key's randomart image is:
2026-01-23 00:21:45.535004 | controller -> localhost | +---[RSA 2048]----+
2026-01-23 00:21:45.535068 | controller -> localhost | |    .            |
2026-01-23 00:21:45.535127 | controller -> localhost | |.  . + .         |
2026-01-23 00:21:45.535181 | controller -> localhost | |o.+ + = .        |
2026-01-23 00:21:45.535235 | controller -> localhost | |o=.= O +         |
2026-01-23 00:21:45.535289 | controller -> localhost | |*.+.+ O S.       |
2026-01-23 00:21:45.535359 | controller -> localhost | |.+.. o O oo..    |
2026-01-23 00:21:45.535423 | controller -> localhost | |o.    *.oE...*   |
2026-01-23 00:21:45.535479 | controller -> localhost | |+  . ....  .= .  |
2026-01-23 00:21:45.535532 | controller -> localhost | | o. .. .. ..     |
2026-01-23 00:21:45.535591 | controller -> localhost | +----[SHA256]-----+
2026-01-23 00:21:45.535744 | controller -> localhost | ok: Runtime: 0:00:00.067527
2026-01-23 00:21:45.553093 | 
2026-01-23 00:21:45.553236 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-23 00:21:45.586392 | controller | ok
2026-01-23 00:21:45.606059 | controller | included: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-23 00:21:45.619219 | 
2026-01-23 00:21:45.619324 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-23 00:21:45.644749 | controller | skipping: Conditional result was False
2026-01-23 00:21:45.654176 | 
2026-01-23 00:21:45.654272 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-23 00:21:46.095971 | controller | changed
2026-01-23 00:21:46.109556 | 
2026-01-23 00:21:46.109745 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-23 00:21:46.334730 | controller | ok
2026-01-23 00:21:46.348778 | 
2026-01-23 00:21:46.348936 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-23 00:21:47.005713 | controller | changed
2026-01-23 00:21:47.020332 | 
2026-01-23 00:21:47.020483 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-23 00:21:47.658488 | controller | changed
2026-01-23 00:21:47.667138 | 
2026-01-23 00:21:47.667229 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-23 00:21:47.692258 | controller | skipping: Conditional result was False
2026-01-23 00:21:47.702370 | 
2026-01-23 00:21:47.702490 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-23 00:21:48.104127 | controller -> localhost | changed
2026-01-23 00:21:48.132830 | 
2026-01-23 00:21:48.133019 | TASK [add-build-sshkey : Add back temp key]
2026-01-23 00:21:48.446660 | controller -> localhost | Identity added: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/0c7b8d9d3c1c4e4cbdb39572f971c3b2_id_rsa (zuul-build-sshkey)
2026-01-23 00:21:48.447103 | controller -> localhost | ok: Runtime: 0:00:00.008313
2026-01-23 00:21:48.462457 | 
2026-01-23 00:21:48.462602 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-23 00:21:48.798142 | controller | ok
2026-01-23 00:21:48.805842 | 
2026-01-23 00:21:48.805933 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-23 00:21:48.842966 | controller | skipping: Conditional result was False
2026-01-23 00:21:48.863849 | 
2026-01-23 00:21:48.863959 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-23 00:21:48.898012 | controller | ok
2026-01-23 00:21:48.921744 | 
2026-01-23 00:21:48.921836 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-23 00:21:49.201604 | controller -> localhost | ok
2026-01-23 00:21:49.208191 | 
2026-01-23 00:21:49.208254 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-23 00:21:49.251311 | controller | ok
2026-01-23 00:21:49.266388 | controller | included: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-23 00:21:49.275207 | 
2026-01-23 00:21:49.275292 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-23 00:21:49.600472 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-23 00:21:49.600793 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/0c7b8d9d3c1c4e4cbdb39572f971c3b2_id_ecdsa.
2026-01-23 00:21:49.600853 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/0c7b8d9d3c1c4e4cbdb39572f971c3b2_id_ecdsa.pub.
2026-01-23 00:21:49.600942 | controller -> localhost | The key fingerprint is:
2026-01-23 00:21:49.600993 | controller -> localhost | SHA256:NtdT/7zoxUfNxZFXwKsEb6sy9zCLqUGc9BlcZoxE05Q zuul-build-sshkey
2026-01-23 00:21:49.601034 | controller -> localhost | The key's randomart image is:
2026-01-23 00:21:49.601076 | controller -> localhost | +---[ECDSA 521]---+
2026-01-23 00:21:49.601120 | controller -> localhost | |       o+==. ..o+|
2026-01-23 00:21:49.601176 | controller -> localhost | |       ..=E   .oo|
2026-01-23 00:21:49.601223 | controller -> localhost | |      . o  o  ..+|
2026-01-23 00:21:49.601263 | controller -> localhost | |     o o o .+..oo|
2026-01-23 00:21:49.601302 | controller -> localhost | |      + S .ooo  =|
2026-01-23 00:21:49.601340 | controller -> localhost | |     . . o  o..o.|
2026-01-23 00:21:49.601377 | controller -> localhost | |      .   o.   o+|
2026-01-23 00:21:49.601414 | controller -> localhost | |       .ooo+  o o|
2026-01-23 00:21:49.601452 | controller -> localhost | |      ..o+..oo . |
2026-01-23 00:21:49.601489 | controller -> localhost | +----[SHA256]-----+
2026-01-23 00:21:49.601578 | controller -> localhost | ok: Runtime: 0:00:00.014291
2026-01-23 00:21:49.616156 | 
2026-01-23 00:21:49.616357 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-23 00:21:49.645257 | controller | ok
2026-01-23 00:21:49.662405 | controller | included: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-23 00:21:49.674203 | 
2026-01-23 00:21:49.674290 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-23 00:21:49.700271 | controller | skipping: Conditional result was False
2026-01-23 00:21:49.713980 | 
2026-01-23 00:21:49.714114 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-23 00:21:49.976762 | controller | changed
2026-01-23 00:21:49.990834 | 
2026-01-23 00:21:49.991002 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-23 00:21:50.212704 | controller | ok
2026-01-23 00:21:50.227390 | 
2026-01-23 00:21:50.227540 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-23 00:21:50.933258 | controller | changed
2026-01-23 00:21:50.938980 | 
2026-01-23 00:21:50.939042 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-23 00:21:51.625988 | controller | changed
2026-01-23 00:21:51.636160 | 
2026-01-23 00:21:51.636313 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-23 00:21:51.672861 | controller | skipping: Conditional result was False
2026-01-23 00:21:51.681477 | 
2026-01-23 00:21:51.681581 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-23 00:21:51.942227 | controller -> localhost | changed
2026-01-23 00:21:51.953575 | 
2026-01-23 00:21:51.953652 | TASK [add-build-sshkey : Add back temp key]
2026-01-23 00:21:52.222042 | controller -> localhost | Identity added: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/0c7b8d9d3c1c4e4cbdb39572f971c3b2_id_ecdsa (zuul-build-sshkey)
2026-01-23 00:21:52.222268 | controller -> localhost | ok: Runtime: 0:00:00.007428
2026-01-23 00:21:52.228862 | 
2026-01-23 00:21:52.228941 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-23 00:21:52.489736 | controller | ok
2026-01-23 00:21:52.497494 | 
2026-01-23 00:21:52.497579 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-23 00:21:52.532877 | controller | skipping: Conditional result was False
2026-01-23 00:21:52.550063 | 
2026-01-23 00:21:52.550163 | TASK [include_role : remove-zuul-sshkey]
2026-01-23 00:21:52.596597 | controller | skipping: Conditional result was False
2026-01-23 00:21:52.611301 | 
2026-01-23 00:21:52.611448 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-23 00:21:52.864128 | controller | ok: "logs"
2026-01-23 00:21:52.864566 | controller | ok: All items complete
2026-01-23 00:21:52.864812 | 
2026-01-23 00:21:53.048792 | controller | ok: "artifacts"
2026-01-23 00:21:53.240239 | controller | ok: "docs"
2026-01-23 00:21:53.258803 | 
2026-01-23 00:21:53.259003 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-23 00:21:53.510462 | controller | changed: "logs"
2026-01-23 00:21:53.689957 | controller | changed: "artifacts"
2026-01-23 00:21:53.896910 | controller | changed: "docs"
2026-01-23 00:21:53.958051 | 
2026-01-23 00:21:53.958203 | PLAY RECAP
2026-01-23 00:21:53.958267 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-23 00:21:53.958306 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-23 00:21:53.958333 | 
2026-01-23 00:21:54.069901 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-23 00:21:54.071761 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-23 00:21:54.659100 | 
2026-01-23 00:21:54.659248 | PLAY [all]
2026-01-23 00:21:54.681212 | 
2026-01-23 00:21:54.681341 | TASK [Install binary dependencies]
2026-01-23 00:21:54.763780 | controller | ok
2026-01-23 00:21:54.783269 | 
2026-01-23 00:21:54.783364 | TASK [bindep : Include find tasks]
2026-01-23 00:21:54.822911 | controller | ok
2026-01-23 00:21:54.830514 | controller | included: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-23 00:21:54.836601 | 
2026-01-23 00:21:54.836664 | TASK [bindep : Look for bindep.txt]
2026-01-23 00:21:55.182563 | controller | ok
2026-01-23 00:21:55.196860 | 
2026-01-23 00:21:55.197035 | TASK [bindep : Define bindep_file fact]
2026-01-23 00:21:55.224791 | controller | skipping: Conditional result was False
2026-01-23 00:21:55.239395 | 
2026-01-23 00:21:55.239552 | TASK [bindep : Look for other-requirements.txt]
2026-01-23 00:21:55.464689 | controller | ok
2026-01-23 00:21:55.476986 | 
2026-01-23 00:21:55.477148 | TASK [bindep : Define bindep_file fact]
2026-01-23 00:21:55.515284 | controller | skipping: Conditional result was False
2026-01-23 00:21:55.528820 | 
2026-01-23 00:21:55.528972 | TASK [bindep : Look for bindep fallback file]
2026-01-23 00:21:55.573991 | controller | skipping: Conditional result was False
2026-01-23 00:21:55.591682 | 
2026-01-23 00:21:55.591900 | TASK [bindep : Define bindep_file fact]
2026-01-23 00:21:55.635088 | controller | skipping: Conditional result was False
2026-01-23 00:21:55.655637 | 
2026-01-23 00:21:55.655837 | TASK [bindep : Include bindep tasks]
2026-01-23 00:21:55.681081 | controller | skipping: Conditional result was False
2026-01-23 00:21:55.690683 | 
2026-01-23 00:21:55.690862 | TASK [bindep : Include install tasks]
2026-01-23 00:21:55.715920 | controller | skipping: Conditional result was False
2026-01-23 00:21:55.724764 | 
2026-01-23 00:21:55.724891 | LOOP [bindep : Include package tasks]
2026-01-23 00:21:55.786067 | 
2026-01-23 00:21:55.786263 | TASK [Run test-setup role]
2026-01-23 00:21:55.811423 | controller | ok
2026-01-23 00:21:55.836416 | 
2026-01-23 00:21:55.836536 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-23 00:21:56.054117 | controller | ok
2026-01-23 00:21:56.062595 | 
2026-01-23 00:21:56.062691 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-23 00:21:56.604416 | controller | skipping: Conditional result was False
2026-01-23 00:21:56.666124 | 
2026-01-23 00:21:56.666269 | PLAY RECAP
2026-01-23 00:21:56.666347 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-23 00:21:56.666390 | 
2026-01-23 00:21:56.799550 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-23 00:21:56.801523 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-23 00:21:57.385811 | 
2026-01-23 00:21:57.385947 | PLAY [controller]
2026-01-23 00:21:57.405801 | 
2026-01-23 00:21:57.405882 | TASK [Create the /root directory]
2026-01-23 00:21:57.794830 | controller | ok
2026-01-23 00:21:57.808122 | 
2026-01-23 00:21:57.808321 | TASK [Install glibc-langpack-en]
2026-01-23 00:22:01.752602 | controller | ok: Nothing to do
2026-01-23 00:22:01.765865 | 
2026-01-23 00:22:01.766002 | TASK [Ensure controller directory exists]
2026-01-23 00:22:02.007512 | controller | changed
2026-01-23 00:22:02.021805 | 
2026-01-23 00:22:02.021907 | TASK [Install container runtime]
2026-01-23 00:22:02.086864 | controller | ok
2026-01-23 00:22:02.137890 | 
2026-01-23 00:22:02.138009 | LOOP [ensure-podman : Find distribution installation]
2026-01-23 00:22:02.174671 | controller | ok: "/var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-23 00:22:02.190606 | controller | included: /var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-23 00:22:02.197112 | 
2026-01-23 00:22:02.197179 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-23 00:23:13.199225 | controller | changed
2026-01-23 00:23:13.216856 | 
2026-01-23 00:23:13.217040 | TASK [ensure-podman : Fetch podman version]
2026-01-23 00:23:13.744161 | controller | Client:       Podman Engine
2026-01-23 00:23:13.744256 | controller | Version:      4.6.2
2026-01-23 00:23:13.744302 | controller | API Version:  4.6.2
2026-01-23 00:23:13.744344 | controller | Go Version:   go1.19.12
2026-01-23 00:23:13.744396 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-23 00:23:13.744439 | controller | OS/Arch:      linux/amd64
2026-01-23 00:23:14.267086 | controller | ok: Runtime: 0:00:00.189709
2026-01-23 00:23:14.282277 | 
2026-01-23 00:23:14.282463 | TASK [ensure-podman : Print podman version installed]
2026-01-23 00:23:14.333904 | Podman version: Client:       Podman Engine
2026-01-23 00:23:14.334426 | Version:      4.6.2
2026-01-23 00:23:14.334515 | API Version:  4.6.2
2026-01-23 00:23:14.334566 | Go Version:   go1.19.12
2026-01-23 00:23:14.334611 | Built:        Mon Aug 28 19:38:31 2023
2026-01-23 00:23:14.334659 | OS/Arch:      linux/amd64
2026-01-23 00:23:14.349125 | 
2026-01-23 00:23:14.349257 | TASK [ensure-podman : Validate podman engine]
2026-01-23 00:23:14.901921 | controller | skipping: Conditional result was False
2026-01-23 00:23:14.916178 | 
2026-01-23 00:23:14.916485 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-23 00:23:14.943957 | controller | skipping: Conditional result was False
2026-01-23 00:23:14.973734 | 
2026-01-23 00:23:14.973918 | TASK [Ensure python3.8 is present]
2026-01-23 00:23:14.992135 | controller | skipping: Conditional result was False
2026-01-23 00:23:15.001339 | 
2026-01-23 00:23:15.001457 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-23 00:23:15.024930 | controller | ok
2026-01-23 00:23:15.053332 | 
2026-01-23 00:23:15.053420 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-23 00:23:16.358374 | controller | ok: Nothing to do
2026-01-23 00:23:16.374267 | 
2026-01-23 00:23:16.374592 | TASK [our-ensure-python : Also install python3-devel]
2026-01-23 00:23:25.670070 | controller | changed
2026-01-23 00:23:25.686464 | 
2026-01-23 00:23:25.686571 | TASK [Run ensure-virtualenv role]
2026-01-23 00:23:25.710535 | controller | ok
2026-01-23 00:23:25.742080 | 
2026-01-23 00:23:25.742164 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-23 00:23:25.974559 | controller | /usr/bin/virtualenv
2026-01-23 00:23:26.275254 | controller | ok: Runtime: 0:00:00.006810
2026-01-23 00:23:26.288984 | 
2026-01-23 00:23:26.289163 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-23 00:23:26.329561 | controller | skipping: Conditional result was False
2026-01-23 00:23:26.330105 | controller | ok: All items complete
2026-01-23 00:23:26.330185 | 
2026-01-23 00:23:26.353199 | 
2026-01-23 00:23:26.353330 | TASK [Find the full path of the Python interpreter]
2026-01-23 00:23:26.605041 | controller | /usr/bin/python3
2026-01-23 00:23:26.934672 | controller | ok
2026-01-23 00:23:26.948018 | 
2026-01-23 00:23:26.948169 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-23 00:23:27.866049 | controller | created virtual environment CPython3.11.0.final.0-64 in 437ms
2026-01-23 00:23:27.890820 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-23 00:23:27.890837 | 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-23 00:23:27.890903 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-23 00:23:27.890917 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-23 00:23:28.005900 | controller | changed
2026-01-23 00:23:28.021120 | 
2026-01-23 00:23:28.021283 | TASK [Set selinux package]
2026-01-23 00:23:28.064459 | controller | ok
2026-01-23 00:23:28.079325 | 
2026-01-23 00:23:28.079495 | TASK [Set selinux package (Fedora)]
2026-01-23 00:23:28.129637 | controller | ok
2026-01-23 00:23:28.142324 | 
2026-01-23 00:23:28.142458 | TASK [Install selinux into virtualenv]
2026-01-23 00:23:53.676415 | controller | Collecting selinux-please-lie-to-me
2026-01-23 00:24:05.937240 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-23 00:24:06.244021 | controller | Collecting setuptools<50.0.0
2026-01-23 00:24:06.251212 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-23 00:24:06.296825 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 20.1 MB/s eta 0:00:00
2026-01-23 00:24:06.379459 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-23 00:24:06.379695 | controller |   Attempting uninstall: setuptools
2026-01-23 00:24:06.382448 | controller |     Found existing installation: setuptools 62.6.0
2026-01-23 00:24:06.442177 | controller |     Uninstalling setuptools-62.6.0:
2026-01-23 00:24:06.450347 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-23 00:24:06.802673 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-23 00:24:18.318395 | controller |
2026-01-23 00:24:18.398396 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-23 00:24:18.398442 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-23 00:24:18.723891 | controller | ok: Runtime: 0:00:50.029262
2026-01-23 00:24:18.737355 | 
2026-01-23 00:24:18.737517 | TASK [Install pytest-forked into virtualenv]
2026-01-23 00:24:30.557695 | controller | Collecting pytest-forked
2026-01-23 00:24:42.801098 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-23 00:24:42.843098 | controller | Collecting py
2026-01-23 00:24:42.855338 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-23 00:24:42.880874 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.5 MB/s eta 0:00:00
2026-01-23 00:24:42.991934 | controller | Collecting pytest>=3.10
2026-01-23 00:24:42.996923 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-23 00:24:43.016655 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 22.0 MB/s eta 0:00:00
2026-01-23 00:24:43.073115 | controller | Collecting iniconfig>=1.0.1
2026-01-23 00:24:43.076375 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-23 00:24:43.121906 | controller | Collecting packaging>=22
2026-01-23 00:24:43.126353 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-01-23 00:24:43.134157 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 12.5 MB/s eta 0:00:00
2026-01-23 00:24:43.167015 | controller | Collecting pluggy<2,>=1.5
2026-01-23 00:24:43.170126 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-23 00:24:43.217344 | controller | Collecting pygments>=2.7.2
2026-01-23 00:24:43.221193 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-23 00:24:43.241181 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 70.4 MB/s eta 0:00:00
2026-01-23 00:24:43.312339 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-23 00:24:44.421075 | 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-23 00:24:44.429787 | controller |
2026-01-23 00:24:44.498456 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-23 00:24:44.498486 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-23 00:24:44.809478 | controller | ok: Runtime: 0:00:25.508225
2026-01-23 00:24:44.823967 | 
2026-01-23 00:24:44.824117 | TASK [Update pip]
2026-01-23 00:24:45.382940 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-23 00:24:55.185654 | controller | Collecting pip
2026-01-23 00:25:07.378282 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-23 00:25:07.564428 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 9.8 MB/s eta 0:00:00
2026-01-23 00:25:07.629947 | controller | Installing collected packages: pip
2026-01-23 00:25:07.630066 | controller |   Attempting uninstall: pip
2026-01-23 00:25:07.632245 | controller |     Found existing installation: pip 22.2.2
2026-01-23 00:25:07.772221 | controller |     Uninstalling pip-22.2.2:
2026-01-23 00:25:07.787570 | controller |       Successfully uninstalled pip-22.2.2
2026-01-23 00:25:08.663771 | controller | Successfully installed pip-25.3
2026-01-23 00:25:08.900438 | controller | ok: Runtime: 0:00:23.658482
2026-01-23 00:25:08.915258 | 
2026-01-23 00:25:08.915396 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-23 00:25:09.153559 | controller | changed
2026-01-23 00:25:09.167617 | 
2026-01-23 00:25:09.167787 | TASK [Install ansible into virtualenv]
2026-01-23 00:25:09.762115 | controller | Processing ./src/github.com/ansible/ansible
2026-01-23 00:25:09.765340 | controller |   Installing build dependencies: started
2026-01-23 00:25:32.253876 | controller |   Installing build dependencies: finished with status 'done'
2026-01-23 00:25:32.254493 | controller |   Getting requirements to build wheel: started
2026-01-23 00:25:33.005254 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-23 00:25:33.006745 | controller |   Preparing metadata (pyproject.toml): started
2026-01-23 00:25:33.481374 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-23 00:25:33.486507 | 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-23 00:25:33.490346 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-23 00:25:33.794267 | controller | ERROR
2026-01-23 00:25:33.794658 | controller | {
2026-01-23 00:25:33.794772 | controller |   "delta": "0:00:24.077115",
2026-01-23 00:25:33.794817 | controller |   "end": "2026-01-23 00:25:33.549000",
2026-01-23 00:25:33.794856 | controller |   "msg": "non-zero return code",
2026-01-23 00:25:33.794923 | controller |   "rc": 1,
2026-01-23 00:25:33.794967 | controller |   "start": "2026-01-23 00:25:09.471885"
2026-01-23 00:25:33.795002 | controller | }
failure
2026-01-23 00:25:33.798493 | 
2026-01-23 00:25:33.798634 | PLAY RECAP
2026-01-23 00:25:33.798836 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-23 00:25:33.798893 | 
2026-01-23 00:25:33.921270 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-23 00:25:33.927488 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-23 00:25:34.572179 | 
2026-01-23 00:25:34.572322 | PLAY [all]
2026-01-23 00:25:34.594444 | 
2026-01-23 00:25:34.594526 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-23 00:25:34.898093 | controller | changed: non-zero return code
2026-01-23 00:25:34.911799 | 
2026-01-23 00:25:34.911969 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-23 00:25:34.940487 | controller | skipping: Conditional result was False
2026-01-23 00:25:34.960243 | 
2026-01-23 00:25:34.960475 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-23 00:25:35.002637 | 
2026-01-23 00:25:35.002944 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-23 00:25:35.037784 | 
2026-01-23 00:25:35.037963 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-23 00:25:35.063507 | controller | skipping: Conditional result was False
2026-01-23 00:25:35.080403 | 
2026-01-23 00:25:35.080577 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-23 00:25:35.115846 | 
2026-01-23 00:25:35.116112 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-23 00:25:35.142044 | controller | skipping: Conditional result was False
2026-01-23 00:25:35.150198 | 
2026-01-23 00:25:35.150291 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-23 00:25:35.165181 | controller | skipping: Conditional result was False
2026-01-23 00:25:35.178242 | 
2026-01-23 00:25:35.178368 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-23 00:25:35.205796 | controller | skipping: Conditional result was False
2026-01-23 00:25:35.247658 | 
2026-01-23 00:25:35.247809 | PLAY RECAP
2026-01-23 00:25:35.247918 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-23 00:25:35.247954 | 
2026-01-23 00:25:35.355803 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-23 00:25:35.358279 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-23 00:25:35.991033 | 
2026-01-23 00:25:35.991141 | PLAY [all:!appliance*]
2026-01-23 00:25:36.013318 | 
2026-01-23 00:25:36.013453 | TASK [unregister the node]
2026-01-23 00:25:36.551191 | controller | skipping: Conditional result was False
2026-01-23 00:25:36.565485 | 
2026-01-23 00:25:36.565712 | TASK [include_role : fetch-output]
2026-01-23 00:25:36.614981 | controller | ok
2026-01-23 00:25:36.653742 | 
2026-01-23 00:25:36.653884 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-23 00:25:36.730059 | controller | skipping: Conditional result was False
2026-01-23 00:25:36.738441 | 
2026-01-23 00:25:36.738537 | TASK [fetch-output : Set log path for single node]
2026-01-23 00:25:36.780509 | controller | ok
2026-01-23 00:25:36.788273 | 
2026-01-23 00:25:36.788378 | LOOP [fetch-output : Ensure local output dirs]
2026-01-23 00:25:37.231501 | controller -> localhost | ok: "/var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/logs"
2026-01-23 00:25:37.548628 | controller -> localhost | changed: "/var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/artifacts"
2026-01-23 00:25:37.792166 | controller -> localhost | changed: "/var/lib/zuul/builds/0c7b8d9d3c1c4e4cbdb39572f971c3b2/work/docs"
2026-01-23 00:25:37.821329 | 
2026-01-23 00:25:37.821592 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-23 00:25:38.526593 | controller | changed:
2026-01-23 00:25:38.527030 | controller | .d..t...... ./
2026-01-23 00:25:38.527093 | controller | cd+++++++++ controller/
2026-01-23 00:25:38.527158 | controller | changed: All items complete
2026-01-23 00:25:38.527201 | 
2026-01-23 00:25:39.093952 | controller | changed: .d..t...... ./
2026-01-23 00:25:39.640650 | controller | changed: .d..t...... ./
2026-01-23 00:25:39.675895 | 
2026-01-23 00:25:39.676105 | TASK [include_role : fetch-output-openshift]
2026-01-23 00:25:39.705543 | controller | skipping: Conditional result was False
2026-01-23 00:25:39.723419 | 
2026-01-23 00:25:39.723602 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-23 00:25:39.772196 | controller | skipping: Conditional result was False
2026-01-23 00:25:39.782534 | controller | skipping: Conditional result was False
2026-01-23 00:25:39.838190 | 
2026-01-23 00:25:39.838326 | PLAY [localhost]
2026-01-23 00:25:39.855619 | 
2026-01-23 00:25:39.855758 | TASK [Run Zuul manifest role]
2026-01-23 00:25:39.879558 | localhost | ok
2026-01-23 00:25:39.897957 | 
2026-01-23 00:25:39.898048 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-23 00:25:40.362842 | localhost | changed
2026-01-23 00:25:40.373015 | 
2026-01-23 00:25:40.373145 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-23 00:25:40.410878 | localhost | ok
2026-01-23 00:25:40.429427 | 
2026-01-23 00:25:40.429513 | TASK [Set zuul-log-path fact]
2026-01-23 00:25:40.449843 | localhost | ok
2026-01-23 00:25:40.470058 | 
2026-01-23 00:25:40.470170 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-23 00:25:40.511373 | localhost | ok
2026-01-23 00:25:40.522527 | 
2026-01-23 00:25:40.522613 | LOOP [Run upload-logs-swift role]
2026-01-23 00:25:40.558641 | localhost | Output suppressed because no_log was given
2026-01-23 00:25:40.592563 | 
2026-01-23 00:25:40.592666 | TASK [Set zuul-log-path fact]
2026-01-23 00:25:40.637530 | localhost | skipping: Conditional result was False
2026-01-23 00:25:40.643984 | 
2026-01-23 00:25:40.644056 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-23 00:25:41.039311 | localhost -> localhost | ok: Runtime: 0:00:00.009264
2026-01-23 00:25:41.049725 | 
2026-01-23 00:25:41.049863 | TASK [upload-logs-swift : Upload logs to swift]