2026-01-20 00:20:11.625424 | Job console starting...
2026-01-20 00:20:11.636211 | Updating repositories
2026-01-20 00:20:11.770333 | Preparing job workspace
2026-01-20 00:20:15.428273 | Running Ansible setup...
2026-01-20 00:20:23.353461 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-20 00:20:23.988379 | 
2026-01-20 00:20:23.988509 | PLAY [localhost]
2026-01-20 00:20:23.998002 | 
2026-01-20 00:20:23.998139 | TASK [Gathering Facts]
2026-01-20 00:20:25.064969 | localhost | ok
2026-01-20 00:20:25.099984 | 
2026-01-20 00:20:25.100285 | TASK [Setup log path fact]
2026-01-20 00:20:25.121947 | localhost | ok
2026-01-20 00:20:25.141151 | 
2026-01-20 00:20:25.141271 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-20 00:20:25.172346 | localhost | ok
2026-01-20 00:20:25.185430 | 
2026-01-20 00:20:25.185581 | TASK [emit-job-header : Print job information]
2026-01-20 00:20:25.238102 | # Job Information
2026-01-20 00:20:25.238302 | Ansible Version: 2.15.12
2026-01-20 00:20:25.238353 | Job: ansible-test-sanity-docker-devel
2026-01-20 00:20:25.238390 | Pipeline: periodic
2026-01-20 00:20:25.238424 | Executor: ze02.softwarefactory-project.io
2026-01-20 00:20:25.238459 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-20 00:20:25.238497 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/eb6/ansible/eb6af7d6a0fa49aaa135c4bc1c133cd1/
2026-01-20 00:20:25.238534 | Event ID: 116c50ab7c10419082d19ef9dc1694bb
2026-01-20 00:20:25.244450 | 
2026-01-20 00:20:25.244575 | LOOP [emit-job-header : Print node information]
2026-01-20 00:20:25.355875 | localhost | ok:
2026-01-20 00:20:25.356134 | localhost | # Node Information
2026-01-20 00:20:25.356176 | localhost | Inventory Hostname: controller
2026-01-20 00:20:25.356205 | localhost | Hostname: np0005588437
2026-01-20 00:20:25.356232 | localhost | Username: zuul
2026-01-20 00:20:25.356267 | localhost | Distro: Fedora 37
2026-01-20 00:20:25.356295 | localhost | Provider: ansible-vexxhost-ams1
2026-01-20 00:20:25.356323 | localhost | Region: ams1
2026-01-20 00:20:25.356360 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-20 00:20:25.356393 | localhost | Product Name: OpenStack Nova
2026-01-20 00:20:25.356425 | localhost | Interface IP: 38.129.16.128
2026-01-20 00:20:25.372940 | 
2026-01-20 00:20:25.373081 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-20 00:20:25.794653 | localhost -> localhost | changed
2026-01-20 00:20:25.812248 | 
2026-01-20 00:20:25.812955 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-20 00:20:26.629300 | localhost -> localhost | changed
2026-01-20 00:20:26.654768 | 
2026-01-20 00:20:26.654901 | PLAY [all:!appliance*]
2026-01-20 00:20:26.671016 | 
2026-01-20 00:20:26.671098 | TASK [include_role : start-zuul-console]
2026-01-20 00:20:26.690054 | controller | ok
2026-01-20 00:20:26.703720 | 
2026-01-20 00:20:26.703801 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-20 00:20:27.738089 | controller | ok
2026-01-20 00:20:27.758745 | 
2026-01-20 00:20:27.758885 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-20 00:20:30.363175 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-20 00:20:30.379275 | 
2026-01-20 00:20:30.379450 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-20 00:20:30.758382 | controller | skipping: Conditional result was False
2026-01-20 00:20:30.767062 | 
2026-01-20 00:20:30.767193 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-20 00:20:30.802599 | controller | skipping: Conditional result was False
2026-01-20 00:20:30.817653 | 
2026-01-20 00:20:30.817875 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-20 00:20:30.844957 | controller | skipping: Conditional result was False
2026-01-20 00:20:30.859748 | 
2026-01-20 00:20:30.860062 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-20 00:20:30.887143 | controller | skipping: Conditional result was False
2026-01-20 00:20:30.895380 | 
2026-01-20 00:20:30.895473 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-20 00:20:30.920654 | controller | skipping: Conditional result was False
2026-01-20 00:20:30.930146 | 
2026-01-20 00:20:30.930270 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-20 00:20:30.954934 | controller | skipping: Conditional result was False
2026-01-20 00:20:30.971394 | 
2026-01-20 00:20:30.971526 | TASK [Disable Fedora Modular]
2026-01-20 00:20:32.094092 | controller | changed
2026-01-20 00:20:32.099915 | 
2026-01-20 00:20:32.100004 | TASK [Enable EPEL]
2026-01-20 00:20:32.124391 | controller | skipping: Conditional result was False
2026-01-20 00:20:32.130433 | 
2026-01-20 00:20:32.130498 | TASK [Register the RHEL node]
2026-01-20 00:20:32.537858 | 
2026-01-20 00:20:32.538012 | TASK [Show the subscription-manager status]
2026-01-20 00:20:32.912535 | controller | skipping: Conditional result was False
2026-01-20 00:20:32.927621 | 
2026-01-20 00:20:32.927800 | TASK [Enable EPEL on RHEL]
2026-01-20 00:20:33.321730 | controller | skipping: Conditional result was False
2026-01-20 00:20:33.336736 | 
2026-01-20 00:20:33.336902 | TASK [Install git and tox]
2026-01-20 00:22:40.385746 | controller | changed
2026-01-20 00:22:40.402237 | 
2026-01-20 00:22:40.402417 | TASK [include_role : prepare-workspace]
2026-01-20 00:22:40.445496 | controller | ok
2026-01-20 00:22:40.486168 | 
2026-01-20 00:22:40.486312 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-20 00:22:41.337399 | controller | ok
2026-01-20 00:22:41.345553 | 
2026-01-20 00:22:41.345687 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-20 00:22:56.930782 | controller | Output suppressed because no_log was given
2026-01-20 00:22:56.941121 | 
2026-01-20 00:22:56.941202 | TASK [include_role : prepare-workspace-openshift]
2026-01-20 00:22:56.965834 | controller | skipping: Conditional result was False
2026-01-20 00:22:56.990490 | 
2026-01-20 00:22:56.990603 | PLAY [all:!appliance]
2026-01-20 00:22:57.006318 | 
2026-01-20 00:22:57.006387 | TASK [Run add-build-sshkey role (RSA)]
2026-01-20 00:22:57.037678 | controller | ok
2026-01-20 00:22:57.056200 | 
2026-01-20 00:22:57.056280 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-20 00:22:57.357520 | controller -> localhost | ok
2026-01-20 00:22:57.364298 | 
2026-01-20 00:22:57.364395 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-20 00:22:57.384792 | controller | ok
2026-01-20 00:22:57.400235 | controller | included: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-20 00:22:57.407867 | 
2026-01-20 00:22:57.407967 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-20 00:22:57.921925 | controller -> localhost | Generating public/private rsa key pair.
2026-01-20 00:22:57.922169 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/eb6af7d6a0fa49aaa135c4bc1c133cd1_id_rsa.
2026-01-20 00:22:57.922202 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/eb6af7d6a0fa49aaa135c4bc1c133cd1_id_rsa.pub.
2026-01-20 00:22:57.922224 | controller -> localhost | The key fingerprint is:
2026-01-20 00:22:57.922244 | controller -> localhost | SHA256:z8OT9PeH6kzSd96QLakZ4XxpHuvdPwY1dUYJluhYswo zuul-build-sshkey
2026-01-20 00:22:57.922263 | controller -> localhost | The key's randomart image is:
2026-01-20 00:22:57.922282 | controller -> localhost | +---[RSA 2048]----+
2026-01-20 00:22:57.922299 | controller -> localhost | |            .oo.o|
2026-01-20 00:22:57.922319 | controller -> localhost | |           +.. .+|
2026-01-20 00:22:57.922337 | controller -> localhost | |          + o  .o|
2026-01-20 00:22:57.922354 | controller -> localhost | |       E . o   o |
2026-01-20 00:22:57.922372 | controller -> localhost | |        S o . . .|
2026-01-20 00:22:57.922400 | controller -> localhost | |         * * o = |
2026-01-20 00:22:57.922422 | controller -> localhost | |          O B &.o|
2026-01-20 00:22:57.922441 | controller -> localhost | |           * X.%+|
2026-01-20 00:22:57.922459 | controller -> localhost | |           .*o= @|
2026-01-20 00:22:57.922480 | controller -> localhost | +----[SHA256]-----+
2026-01-20 00:22:57.922555 | controller -> localhost | ok: Runtime: 0:00:00.032716
2026-01-20 00:22:57.930520 | 
2026-01-20 00:22:57.930640 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-20 00:22:57.964280 | controller | ok
2026-01-20 00:22:57.981721 | controller | included: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-20 00:22:57.993442 | 
2026-01-20 00:22:57.993535 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-20 00:22:58.018129 | controller | skipping: Conditional result was False
2026-01-20 00:22:58.029931 | 
2026-01-20 00:22:58.030139 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-20 00:22:59.128120 | controller | changed
2026-01-20 00:22:59.134660 | 
2026-01-20 00:22:59.134742 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-20 00:22:59.798747 | controller | ok
2026-01-20 00:22:59.814220 | 
2026-01-20 00:22:59.814413 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-20 00:23:02.881906 | controller | changed
2026-01-20 00:23:02.895108 | 
2026-01-20 00:23:02.895262 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-20 00:23:05.936109 | controller | changed
2026-01-20 00:23:05.951339 | 
2026-01-20 00:23:05.951567 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-20 00:23:05.968717 | controller | skipping: Conditional result was False
2026-01-20 00:23:05.976750 | 
2026-01-20 00:23:05.976886 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-20 00:23:06.354207 | controller -> localhost | changed
2026-01-20 00:23:06.384927 | 
2026-01-20 00:23:06.385134 | TASK [add-build-sshkey : Add back temp key]
2026-01-20 00:23:06.681429 | controller -> localhost | Identity added: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/eb6af7d6a0fa49aaa135c4bc1c133cd1_id_rsa (zuul-build-sshkey)
2026-01-20 00:23:06.681746 | controller -> localhost | ok: Runtime: 0:00:00.014202
2026-01-20 00:23:06.688045 | 
2026-01-20 00:23:06.688114 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-20 00:23:07.593281 | controller | ok
2026-01-20 00:23:07.599510 | 
2026-01-20 00:23:07.599621 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-20 00:23:07.635559 | controller | skipping: Conditional result was False
2026-01-20 00:23:07.656000 | 
2026-01-20 00:23:07.656161 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-20 00:23:07.689502 | controller | ok
2026-01-20 00:23:07.707437 | 
2026-01-20 00:23:07.707573 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-20 00:23:07.956972 | controller -> localhost | ok
2026-01-20 00:23:07.966887 | 
2026-01-20 00:23:07.967023 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-20 00:23:07.991373 | controller | ok
2026-01-20 00:23:08.010144 | controller | included: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-20 00:23:08.020264 | 
2026-01-20 00:23:08.020465 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-20 00:23:08.304217 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-20 00:23:08.304530 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/eb6af7d6a0fa49aaa135c4bc1c133cd1_id_ecdsa.
2026-01-20 00:23:08.304593 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/eb6af7d6a0fa49aaa135c4bc1c133cd1_id_ecdsa.pub.
2026-01-20 00:23:08.304655 | controller -> localhost | The key fingerprint is:
2026-01-20 00:23:08.304946 | controller -> localhost | SHA256:xdGf5zFnM3n3P/BL8rFYMghhJIAKWlcjIqnP8+VDTPo zuul-build-sshkey
2026-01-20 00:23:08.305011 | controller -> localhost | The key's randomart image is:
2026-01-20 00:23:08.305055 | controller -> localhost | +---[ECDSA 521]---+
2026-01-20 00:23:08.305095 | controller -> localhost | |... oo+. ...     |
2026-01-20 00:23:08.305133 | controller -> localhost | |o..o.. .o. ..    |
2026-01-20 00:23:08.305173 | controller -> localhost | |+...     oo  . ..|
2026-01-20 00:23:08.305211 | controller -> localhost | |o.    . ...   o**|
2026-01-20 00:23:08.305247 | controller -> localhost | | o   +  S.     +X|
2026-01-20 00:23:08.305283 | controller -> localhost | |  + . +   . ..  o|
2026-01-20 00:23:08.305320 | controller -> localhost | |   o =     . +o+.|
2026-01-20 00:23:08.305357 | controller -> localhost | |    . E       Oo+|
2026-01-20 00:23:08.305393 | controller -> localhost | |       .     . +o|
2026-01-20 00:23:08.305429 | controller -> localhost | +----[SHA256]-----+
2026-01-20 00:23:08.305518 | controller -> localhost | ok: Runtime: 0:00:00.015497
2026-01-20 00:23:08.321704 | 
2026-01-20 00:23:08.321871 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-20 00:23:08.361318 | controller | ok
2026-01-20 00:23:08.380135 | controller | included: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-20 00:23:08.407412 | 
2026-01-20 00:23:08.407558 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-20 00:23:08.422814 | controller | skipping: Conditional result was False
2026-01-20 00:23:08.471392 | 
2026-01-20 00:23:08.471512 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-20 00:23:09.381940 | controller | changed
2026-01-20 00:23:09.395473 | 
2026-01-20 00:23:09.395659 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-20 00:23:10.077361 | controller | ok
2026-01-20 00:23:10.086928 | 
2026-01-20 00:23:10.087037 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-20 00:23:13.145041 | controller | changed
2026-01-20 00:23:13.154394 | 
2026-01-20 00:23:13.154545 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-20 00:23:16.212723 | controller | changed
2026-01-20 00:23:16.220771 | 
2026-01-20 00:23:16.220864 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-20 00:23:16.246527 | controller | skipping: Conditional result was False
2026-01-20 00:23:16.255584 | 
2026-01-20 00:23:16.255719 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-20 00:23:16.567372 | controller -> localhost | changed
2026-01-20 00:23:16.580317 | 
2026-01-20 00:23:16.580434 | TASK [add-build-sshkey : Add back temp key]
2026-01-20 00:23:16.899317 | controller -> localhost | Identity added: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/eb6af7d6a0fa49aaa135c4bc1c133cd1_id_ecdsa (zuul-build-sshkey)
2026-01-20 00:23:16.899578 | controller -> localhost | ok: Runtime: 0:00:00.011781
2026-01-20 00:23:16.906418 | 
2026-01-20 00:23:16.906531 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-20 00:23:17.630514 | controller | ok
2026-01-20 00:23:17.638269 | 
2026-01-20 00:23:17.638347 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-20 00:23:17.674650 | controller | skipping: Conditional result was False
2026-01-20 00:23:17.692202 | 
2026-01-20 00:23:17.692285 | TASK [include_role : remove-zuul-sshkey]
2026-01-20 00:23:17.719231 | controller | skipping: Conditional result was False
2026-01-20 00:23:17.728696 | 
2026-01-20 00:23:17.728790 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-20 00:23:18.409801 | controller | ok: "logs"
2026-01-20 00:23:18.410320 | controller | ok: All items complete
2026-01-20 00:23:18.410421 | 
2026-01-20 00:23:19.023570 | controller | ok: "artifacts"
2026-01-20 00:23:19.698884 | controller | ok: "docs"
2026-01-20 00:23:19.717563 | 
2026-01-20 00:23:19.717751 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-20 00:23:20.448954 | controller | changed: "logs"
2026-01-20 00:23:21.086410 | controller | changed: "artifacts"
2026-01-20 00:23:21.740200 | controller | changed: "docs"
2026-01-20 00:23:21.799044 | 
2026-01-20 00:23:21.799162 | PLAY RECAP
2026-01-20 00:23:21.799224 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-20 00:23:21.799261 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-20 00:23:21.799288 | 
2026-01-20 00:23:21.924884 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-20 00:23:21.926614 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-20 00:23:22.509851 | 
2026-01-20 00:23:22.509970 | PLAY [all]
2026-01-20 00:23:22.532703 | 
2026-01-20 00:23:22.532805 | TASK [Install binary dependencies]
2026-01-20 00:23:22.586027 | controller | ok
2026-01-20 00:23:22.610757 | 
2026-01-20 00:23:22.610897 | TASK [bindep : Include find tasks]
2026-01-20 00:23:22.640435 | controller | ok
2026-01-20 00:23:22.648687 | controller | included: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-20 00:23:22.654987 | 
2026-01-20 00:23:22.655068 | TASK [bindep : Look for bindep.txt]
2026-01-20 00:23:23.600467 | controller | ok
2026-01-20 00:23:23.610112 | 
2026-01-20 00:23:23.610242 | TASK [bindep : Define bindep_file fact]
2026-01-20 00:23:23.639694 | controller | skipping: Conditional result was False
2026-01-20 00:23:23.650501 | 
2026-01-20 00:23:23.650700 | TASK [bindep : Look for other-requirements.txt]
2026-01-20 00:23:24.310750 | controller | ok
2026-01-20 00:23:24.316707 | 
2026-01-20 00:23:24.316773 | TASK [bindep : Define bindep_file fact]
2026-01-20 00:23:24.341865 | controller | skipping: Conditional result was False
2026-01-20 00:23:24.348659 | 
2026-01-20 00:23:24.348784 | TASK [bindep : Look for bindep fallback file]
2026-01-20 00:23:24.394457 | controller | skipping: Conditional result was False
2026-01-20 00:23:24.401832 | 
2026-01-20 00:23:24.401960 | TASK [bindep : Define bindep_file fact]
2026-01-20 00:23:24.426495 | controller | skipping: Conditional result was False
2026-01-20 00:23:24.436328 | 
2026-01-20 00:23:24.436454 | TASK [bindep : Include bindep tasks]
2026-01-20 00:23:24.464121 | controller | skipping: Conditional result was False
2026-01-20 00:23:24.470950 | 
2026-01-20 00:23:24.471038 | TASK [bindep : Include install tasks]
2026-01-20 00:23:24.506449 | controller | skipping: Conditional result was False
2026-01-20 00:23:24.514548 | 
2026-01-20 00:23:24.514659 | LOOP [bindep : Include package tasks]
2026-01-20 00:23:24.573598 | 
2026-01-20 00:23:24.573805 | TASK [Run test-setup role]
2026-01-20 00:23:24.594752 | controller | ok
2026-01-20 00:23:24.623191 | 
2026-01-20 00:23:24.623335 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-20 00:23:25.327503 | controller | ok
2026-01-20 00:23:25.334174 | 
2026-01-20 00:23:25.334265 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-20 00:23:25.699346 | controller | skipping: Conditional result was False
2026-01-20 00:23:25.727726 | 
2026-01-20 00:23:25.727836 | PLAY RECAP
2026-01-20 00:23:25.727879 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-20 00:23:25.727901 | 
2026-01-20 00:23:25.859877 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-20 00:23:25.860749 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-20 00:23:26.522462 | 
2026-01-20 00:23:26.522645 | PLAY [controller]
2026-01-20 00:23:26.554792 | 
2026-01-20 00:23:26.554941 | TASK [Create the /root directory]
2026-01-20 00:23:27.689215 | controller | ok
2026-01-20 00:23:27.703451 | 
2026-01-20 00:23:27.703568 | TASK [Install glibc-langpack-en]
2026-01-20 00:23:36.011563 | controller | ok: Nothing to do
2026-01-20 00:23:36.024567 | 
2026-01-20 00:23:36.024759 | TASK [Ensure controller directory exists]
2026-01-20 00:23:36.821181 | controller | changed
2026-01-20 00:23:36.831338 | 
2026-01-20 00:23:36.831469 | TASK [Install container runtime]
2026-01-20 00:23:36.907093 | controller | ok
2026-01-20 00:23:36.965171 | 
2026-01-20 00:23:36.965328 | LOOP [ensure-podman : Find distribution installation]
2026-01-20 00:23:36.996520 | controller | ok: "/var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-20 00:23:37.007568 | controller | included: /var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-20 00:23:37.014264 | 
2026-01-20 00:23:37.014346 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-20 00:25:37.438201 | controller | changed
2026-01-20 00:25:37.457890 | 
2026-01-20 00:25:37.458317 | TASK [ensure-podman : Fetch podman version]
2026-01-20 00:25:38.633484 | controller | Client:       Podman Engine
2026-01-20 00:25:38.675930 | controller | Version:      4.6.2
2026-01-20 00:25:38.675983 | controller | API Version:  4.6.2
2026-01-20 00:25:38.675992 | controller | Go Version:   go1.19.12
2026-01-20 00:25:38.676013 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-20 00:25:38.676022 | controller | OS/Arch:      linux/amd64
2026-01-20 00:25:38.848560 | controller | ok: Runtime: 0:00:00.297643
2026-01-20 00:25:38.861901 | 
2026-01-20 00:25:38.862047 | TASK [ensure-podman : Print podman version installed]
2026-01-20 00:25:38.900757 | Podman version: Client:       Podman Engine
2026-01-20 00:25:38.901018 | Version:      4.6.2
2026-01-20 00:25:38.901079 | API Version:  4.6.2
2026-01-20 00:25:38.901122 | Go Version:   go1.19.12
2026-01-20 00:25:38.901161 | Built:        Mon Aug 28 19:38:31 2023
2026-01-20 00:25:38.901203 | OS/Arch:      linux/amd64
2026-01-20 00:25:38.913295 | 
2026-01-20 00:25:38.913419 | TASK [ensure-podman : Validate podman engine]
2026-01-20 00:25:39.287949 | controller | skipping: Conditional result was False
2026-01-20 00:25:39.302535 | 
2026-01-20 00:25:39.302748 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-20 00:25:39.319585 | controller | skipping: Conditional result was False
2026-01-20 00:25:39.346078 | 
2026-01-20 00:25:39.346233 | TASK [Ensure python3.8 is present]
2026-01-20 00:25:39.362108 | controller | skipping: Conditional result was False
2026-01-20 00:25:39.371155 | 
2026-01-20 00:25:39.371240 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-20 00:25:39.395187 | controller | ok
2026-01-20 00:25:39.422557 | 
2026-01-20 00:25:39.422668 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-20 00:25:43.187901 | controller | ok: Nothing to do
2026-01-20 00:25:43.201924 | 
2026-01-20 00:25:43.202109 | TASK [our-ensure-python : Also install python3-devel]
2026-01-20 00:25:58.984350 | controller | changed
2026-01-20 00:25:59.001178 | 
2026-01-20 00:25:59.001322 | TASK [Run ensure-virtualenv role]
2026-01-20 00:25:59.026187 | controller | ok
2026-01-20 00:25:59.053976 | 
2026-01-20 00:25:59.054074 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-20 00:25:59.834919 | controller | /usr/bin/virtualenv
2026-01-20 00:26:00.432797 | controller | ok: Runtime: 0:00:00.008377
2026-01-20 00:26:00.446333 | 
2026-01-20 00:26:00.446475 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-20 00:26:00.472367 | controller | skipping: Conditional result was False
2026-01-20 00:26:00.472888 | controller | ok: All items complete
2026-01-20 00:26:00.472986 | 
2026-01-20 00:26:00.499018 | 
2026-01-20 00:26:00.499178 | TASK [Find the full path of the Python interpreter]
2026-01-20 00:26:01.354462 | controller | /usr/bin/python3
2026-01-20 00:26:01.866418 | controller | ok
2026-01-20 00:26:01.879947 | 
2026-01-20 00:26:01.880128 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-20 00:26:03.661992 | controller | created virtual environment CPython3.11.0.final.0-64 in 819ms
2026-01-20 00:26:03.715043 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-20 00:26:03.715102 | 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:26:03.715118 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-20 00:26:03.715139 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-20 00:26:04.272431 | controller | changed
2026-01-20 00:26:04.285238 | 
2026-01-20 00:26:04.285392 | TASK [Set selinux package]
2026-01-20 00:26:04.324234 | controller | ok
2026-01-20 00:26:04.336601 | 
2026-01-20 00:26:04.336803 | TASK [Set selinux package (Fedora)]
2026-01-20 00:26:04.387441 | controller | ok
2026-01-20 00:26:04.400277 | 
2026-01-20 00:26:04.400424 | TASK [Install selinux into virtualenv]
2026-01-20 00:26:07.738753 | controller | Collecting selinux-please-lie-to-me
2026-01-20 00:26:07.896374 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-20 00:26:08.493555 | controller | Collecting setuptools<50.0.0
2026-01-20 00:26:08.498962 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-20 00:26:08.555552 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.7 MB/s eta 0:00:00
2026-01-20 00:26:08.716536 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-20 00:26:08.716702 | controller |   Attempting uninstall: setuptools
2026-01-20 00:26:08.724065 | controller |     Found existing installation: setuptools 62.6.0
2026-01-20 00:26:08.834257 | controller |     Uninstalling setuptools-62.6.0:
2026-01-20 00:26:08.852406 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-20 00:26:09.701353 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-20 00:26:09.915011 | controller |
2026-01-20 00:26:10.302798 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-20 00:26:10.303196 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-20 00:26:10.810037 | controller | ok: Runtime: 0:00:05.080465
2026-01-20 00:26:10.823477 | 
2026-01-20 00:26:10.823704 | TASK [Install pytest-forked into virtualenv]
2026-01-20 00:26:12.471032 | controller | Collecting pytest-forked
2026-01-20 00:26:12.543436 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-20 00:26:12.637421 | controller | Collecting py
2026-01-20 00:26:12.645728 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-20 00:26:12.682018 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.0 MB/s eta 0:00:00
2026-01-20 00:26:12.916594 | controller | Collecting pytest>=3.10
2026-01-20 00:26:12.923475 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-20 00:26:12.948388 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 23.2 MB/s eta 0:00:00
2026-01-20 00:26:13.014965 | controller | Collecting iniconfig>=1.0.1
2026-01-20 00:26:13.022064 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-20 00:26:13.083107 | controller | Collecting packaging>=22
2026-01-20 00:26:13.087472 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-20 00:26:13.098674 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 6.9 MB/s eta 0:00:00
2026-01-20 00:26:13.149348 | controller | Collecting pluggy<2,>=1.5
2026-01-20 00:26:13.154344 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-20 00:26:13.244662 | controller | Collecting pygments>=2.7.2
2026-01-20 00:26:13.250477 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-20 00:26:13.286158 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 40.5 MB/s eta 0:00:00
2026-01-20 00:26:13.399373 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-20 00:26:15.675800 | 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:26:15.690345 | controller |
2026-01-20 00:26:15.904947 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-20 00:26:15.904997 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-20 00:26:16.223310 | controller | ok: Runtime: 0:00:04.292582
2026-01-20 00:26:16.237438 | 
2026-01-20 00:26:16.237704 | TASK [Update pip]
2026-01-20 00:26:17.699924 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-20 00:26:17.968844 | controller | Collecting pip
2026-01-20 00:26:18.034812 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-20 00:26:18.123145 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 21.1 MB/s eta 0:00:00
2026-01-20 00:26:18.294735 | controller | Installing collected packages: pip
2026-01-20 00:26:18.295070 | controller |   Attempting uninstall: pip
2026-01-20 00:26:18.302522 | controller |     Found existing installation: pip 22.2.2
2026-01-20 00:26:18.576127 | controller |     Uninstalling pip-22.2.2:
2026-01-20 00:26:18.631426 | controller |       Successfully uninstalled pip-22.2.2
2026-01-20 00:26:20.475710 | controller | Successfully installed pip-25.3
2026-01-20 00:26:21.148418 | controller | ok: Runtime: 0:00:03.741130
2026-01-20 00:26:21.160859 | 
2026-01-20 00:26:21.160998 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-20 00:26:22.062702 | controller | changed
2026-01-20 00:26:22.069373 | 
2026-01-20 00:26:22.069615 | TASK [Install ansible into virtualenv]
2026-01-20 00:26:23.324863 | controller | Processing ./src/github.com/ansible/ansible
2026-01-20 00:26:23.333722 | controller |   Installing build dependencies: started
2026-01-20 00:26:25.104381 | controller |   Installing build dependencies: finished with status 'done'
2026-01-20 00:26:26.590631 | controller |   Getting requirements to build wheel: started
2026-01-20 00:26:26.590688 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-20 00:26:26.592117 | controller |   Preparing metadata (pyproject.toml): started
2026-01-20 00:26:27.499406 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-20 00:26:27.506495 | 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:26:27.518350 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-20 00:26:27.983977 | controller | ERROR
2026-01-20 00:26:27.984265 | controller | {
2026-01-20 00:26:27.984328 | controller |   "delta": "0:00:04.881573",
2026-01-20 00:26:27.984371 | controller |   "end": "2026-01-20 00:26:27.681220",
2026-01-20 00:26:27.984410 | controller |   "msg": "non-zero return code",
2026-01-20 00:26:27.984465 | controller |   "rc": 1,
2026-01-20 00:26:27.984503 | controller |   "start": "2026-01-20 00:26:22.799647"
2026-01-20 00:26:27.984538 | controller | }
failure
2026-01-20 00:26:27.987530 | 
2026-01-20 00:26:27.987631 | PLAY RECAP
2026-01-20 00:26:27.987754 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-20 00:26:27.987804 | 
2026-01-20 00:26:28.107083 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-20 00:26:28.108072 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-20 00:26:28.677533 | 
2026-01-20 00:26:28.677641 | PLAY [all]
2026-01-20 00:26:28.699148 | 
2026-01-20 00:26:28.699238 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-20 00:26:30.562132 | controller | changed: non-zero return code
2026-01-20 00:26:30.575762 | 
2026-01-20 00:26:30.575963 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-20 00:26:30.603427 | controller | skipping: Conditional result was False
2026-01-20 00:26:30.617130 | 
2026-01-20 00:26:30.617283 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-20 00:26:30.661314 | 
2026-01-20 00:26:30.661592 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-20 00:26:30.702308 | 
2026-01-20 00:26:30.702574 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-20 00:26:30.719470 | controller | skipping: Conditional result was False
2026-01-20 00:26:30.734587 | 
2026-01-20 00:26:30.734758 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-20 00:26:30.775192 | 
2026-01-20 00:26:30.775407 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-20 00:26:30.802550 | controller | skipping: Conditional result was False
2026-01-20 00:26:30.812574 | 
2026-01-20 00:26:30.812731 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-20 00:26:30.839280 | controller | skipping: Conditional result was False
2026-01-20 00:26:30.849184 | 
2026-01-20 00:26:30.849334 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-20 00:26:30.876459 | controller | skipping: Conditional result was False
2026-01-20 00:26:30.918185 | 
2026-01-20 00:26:30.918316 | PLAY RECAP
2026-01-20 00:26:30.918373 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-20 00:26:30.918397 | 
2026-01-20 00:26:31.032909 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-20 00:26:31.033744 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-20 00:26:31.667789 | 
2026-01-20 00:26:31.667900 | PLAY [all:!appliance*]
2026-01-20 00:26:31.689497 | 
2026-01-20 00:26:31.689593 | TASK [unregister the node]
2026-01-20 00:26:32.046394 | controller | skipping: Conditional result was False
2026-01-20 00:26:32.059269 | 
2026-01-20 00:26:32.059437 | TASK [include_role : fetch-output]
2026-01-20 00:26:32.110082 | controller | ok
2026-01-20 00:26:32.158468 | 
2026-01-20 00:26:32.158758 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-20 00:26:32.237748 | controller | skipping: Conditional result was False
2026-01-20 00:26:32.251818 | 
2026-01-20 00:26:32.251971 | TASK [fetch-output : Set log path for single node]
2026-01-20 00:26:32.312637 | controller | ok
2026-01-20 00:26:32.326768 | 
2026-01-20 00:26:32.327048 | LOOP [fetch-output : Ensure local output dirs]
2026-01-20 00:26:32.781585 | controller -> localhost | ok: "/var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/logs"
2026-01-20 00:26:33.002259 | controller -> localhost | changed: "/var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/artifacts"
2026-01-20 00:26:33.272330 | controller -> localhost | changed: "/var/lib/zuul/builds/eb6af7d6a0fa49aaa135c4bc1c133cd1/work/docs"
2026-01-20 00:26:33.296006 | 
2026-01-20 00:26:33.296188 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-20 00:26:35.518221 | controller | changed:
2026-01-20 00:26:35.518448 | controller | .d..t...... ./
2026-01-20 00:26:35.518488 | controller | cd+++++++++ controller/
2026-01-20 00:26:35.518533 | controller | changed: All items complete
2026-01-20 00:26:35.518563 | 
2026-01-20 00:26:37.582460 | controller | changed: .d..t...... ./
2026-01-20 00:26:39.710452 | controller | changed: .d..t...... ./
2026-01-20 00:26:39.737485 | 
2026-01-20 00:26:39.737639 | TASK [include_role : fetch-output-openshift]
2026-01-20 00:26:39.762912 | controller | skipping: Conditional result was False
2026-01-20 00:26:39.772793 | 
2026-01-20 00:26:39.772927 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-20 00:26:39.816514 | controller | skipping: Conditional result was False
2026-01-20 00:26:39.827360 | controller | skipping: Conditional result was False
2026-01-20 00:26:39.885103 | 
2026-01-20 00:26:39.885240 | PLAY [localhost]
2026-01-20 00:26:39.903402 | 
2026-01-20 00:26:39.903493 | TASK [Run Zuul manifest role]
2026-01-20 00:26:39.922147 | localhost | ok
2026-01-20 00:26:39.935842 | 
2026-01-20 00:26:39.935902 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-20 00:26:40.366326 | localhost | changed
2026-01-20 00:26:40.377246 | 
2026-01-20 00:26:40.377408 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-20 00:26:40.424805 | localhost | ok
2026-01-20 00:26:40.445060 | 
2026-01-20 00:26:40.445199 | TASK [Set zuul-log-path fact]
2026-01-20 00:26:40.496503 | localhost | ok
2026-01-20 00:26:40.515116 | 
2026-01-20 00:26:40.515212 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-20 00:26:40.556347 | localhost | ok
2026-01-20 00:26:40.567521 | 
2026-01-20 00:26:40.567602 | LOOP [Run upload-logs-swift role]
2026-01-20 00:26:40.614649 | localhost | Output suppressed because no_log was given
2026-01-20 00:26:40.667076 | 
2026-01-20 00:26:40.667199 | TASK [Set zuul-log-path fact]
2026-01-20 00:26:40.692191 | localhost | skipping: Conditional result was False
2026-01-20 00:26:40.700010 | 
2026-01-20 00:26:40.700164 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-20 00:26:41.052721 | localhost -> localhost | ok: Runtime: 0:00:00.007178
2026-01-20 00:26:41.060903 | 
2026-01-20 00:26:41.061014 | TASK [upload-logs-swift : Upload logs to swift]