2026-02-02 00:14:32.067196 | Job console starting...
2026-02-02 00:14:32.078679 | Updating repositories
2026-02-02 00:14:32.240065 | Preparing job workspace
2026-02-02 00:14:36.473414 | Running Ansible setup...
2026-02-02 00:14:41.037435 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-02 00:14:41.714264 | 
2026-02-02 00:14:41.714402 | PLAY [localhost]
2026-02-02 00:14:41.723611 | 
2026-02-02 00:14:41.723697 | TASK [Gathering Facts]
2026-02-02 00:14:42.698612 | localhost | ok
2026-02-02 00:14:42.713029 | 
2026-02-02 00:14:42.713150 | TASK [Setup log path fact]
2026-02-02 00:14:42.732801 | localhost | ok
2026-02-02 00:14:42.747069 | 
2026-02-02 00:14:42.747187 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-02 00:14:42.775012 | localhost | ok
2026-02-02 00:14:42.782769 | 
2026-02-02 00:14:42.782852 | TASK [emit-job-header : Print job information]
2026-02-02 00:14:42.821791 | # Job Information
2026-02-02 00:14:42.821942 | Ansible Version: 2.15.12
2026-02-02 00:14:42.821978 | Job: ansible-test-sanity-docker-milestone
2026-02-02 00:14:42.822000 | Pipeline: periodic
2026-02-02 00:14:42.822019 | Executor: ze03.softwarefactory-project.io
2026-02-02 00:14:42.822039 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-02 00:14:42.822060 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/7a9/ansible/7a9def057ad84e53af060f5d0449ff59/
2026-02-02 00:14:42.822080 | Event ID: b8572a2a6ece47cf97aed7a79436eb14
2026-02-02 00:14:42.825847 | 
2026-02-02 00:14:42.825910 | LOOP [emit-job-header : Print node information]
2026-02-02 00:14:42.921075 | localhost | ok:
2026-02-02 00:14:42.921242 | localhost | # Node Information
2026-02-02 00:14:42.921277 | localhost | Inventory Hostname: controller
2026-02-02 00:14:42.921301 | localhost | Hostname: np0005604590
2026-02-02 00:14:42.921320 | localhost | Username: zuul
2026-02-02 00:14:42.921342 | localhost | Distro: Fedora 37
2026-02-02 00:14:42.921362 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-02 00:14:42.921380 | localhost | Region: ca-ymq-1
2026-02-02 00:14:42.921406 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-02 00:14:42.921422 | localhost | Product Name: OpenStack Nova
2026-02-02 00:14:42.921439 | localhost | Interface IP: 162.253.55.227
2026-02-02 00:14:42.940530 | 
2026-02-02 00:14:42.940675 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-02 00:14:43.366181 | localhost -> localhost | changed
2026-02-02 00:14:43.371655 | 
2026-02-02 00:14:43.371757 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-02 00:14:44.297888 | localhost -> localhost | changed
2026-02-02 00:14:44.318076 | 
2026-02-02 00:14:44.318150 | PLAY [all:!appliance*]
2026-02-02 00:14:44.334777 | 
2026-02-02 00:14:44.334853 | TASK [include_role : start-zuul-console]
2026-02-02 00:14:44.355103 | controller | ok
2026-02-02 00:14:44.369936 | 
2026-02-02 00:14:44.370036 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-02 00:14:44.749587 | controller | ok
2026-02-02 00:14:44.772402 | 
2026-02-02 00:14:44.772540 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-02 00:14:45.554613 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-02 00:14:45.561499 | 
2026-02-02 00:14:45.561586 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-02 00:14:46.107962 | controller | skipping: Conditional result was False
2026-02-02 00:14:46.117115 | 
2026-02-02 00:14:46.117265 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-02 00:14:46.142834 | controller | skipping: Conditional result was False
2026-02-02 00:14:46.151573 | 
2026-02-02 00:14:46.151707 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-02 00:14:46.177153 | controller | skipping: Conditional result was False
2026-02-02 00:14:46.188065 | 
2026-02-02 00:14:46.188210 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-02 00:14:46.213257 | controller | skipping: Conditional result was False
2026-02-02 00:14:46.220047 | 
2026-02-02 00:14:46.220197 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-02 00:14:46.244151 | controller | skipping: Conditional result was False
2026-02-02 00:14:46.250921 | 
2026-02-02 00:14:46.251047 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-02 00:14:46.274918 | controller | skipping: Conditional result was False
2026-02-02 00:14:46.287617 | 
2026-02-02 00:14:46.287737 | TASK [Disable Fedora Modular]
2026-02-02 00:14:46.530893 | controller | changed
2026-02-02 00:14:46.540387 | 
2026-02-02 00:14:46.540496 | TASK [Enable EPEL]
2026-02-02 00:14:46.573491 | controller | skipping: Conditional result was False
2026-02-02 00:14:46.580109 | 
2026-02-02 00:14:46.580201 | TASK [Register the RHEL node]
2026-02-02 00:14:47.128865 | 
2026-02-02 00:14:47.129243 | TASK [Show the subscription-manager status]
2026-02-02 00:14:47.705307 | controller | skipping: Conditional result was False
2026-02-02 00:14:47.722932 | 
2026-02-02 00:14:47.723090 | TASK [Enable EPEL on RHEL]
2026-02-02 00:14:48.275366 | controller | skipping: Conditional result was False
2026-02-02 00:14:48.281721 | 
2026-02-02 00:14:48.281854 | TASK [Install git and tox]
2026-02-02 00:16:07.674382 | controller | changed
2026-02-02 00:16:07.689143 | 
2026-02-02 00:16:07.689283 | TASK [include_role : prepare-workspace]
2026-02-02 00:16:07.718697 | controller | ok
2026-02-02 00:16:07.755603 | 
2026-02-02 00:16:07.755762 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-02 00:16:07.999995 | controller | ok
2026-02-02 00:16:08.015488 | 
2026-02-02 00:16:08.015656 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-02 00:16:20.272056 | controller | Output suppressed because no_log was given
2026-02-02 00:16:20.317112 | 
2026-02-02 00:16:20.317245 | TASK [include_role : prepare-workspace-openshift]
2026-02-02 00:16:20.341262 | controller | skipping: Conditional result was False
2026-02-02 00:16:20.364954 | 
2026-02-02 00:16:20.365060 | PLAY [all:!appliance]
2026-02-02 00:16:20.382609 | 
2026-02-02 00:16:20.382715 | TASK [Run add-build-sshkey role (RSA)]
2026-02-02 00:16:20.414828 | controller | ok
2026-02-02 00:16:20.435962 | 
2026-02-02 00:16:20.436067 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-02 00:16:20.780661 | controller -> localhost | ok
2026-02-02 00:16:20.794425 | 
2026-02-02 00:16:20.794581 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-02 00:16:20.818393 | controller | ok
2026-02-02 00:16:20.839048 | controller | included: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-02 00:16:20.848627 | 
2026-02-02 00:16:20.848808 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-02 00:16:21.466007 | controller -> localhost | Generating public/private rsa key pair.
2026-02-02 00:16:21.466232 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/7a9def057ad84e53af060f5d0449ff59_id_rsa.
2026-02-02 00:16:21.466262 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/7a9def057ad84e53af060f5d0449ff59_id_rsa.pub.
2026-02-02 00:16:21.466283 | controller -> localhost | The key fingerprint is:
2026-02-02 00:16:21.466302 | controller -> localhost | SHA256:CmAmIUlr4EzlylsXgWKuaYzPcvG23APPz4vOs1SSp0E zuul-build-sshkey
2026-02-02 00:16:21.466321 | controller -> localhost | The key's randomart image is:
2026-02-02 00:16:21.466339 | controller -> localhost | +---[RSA 2048]----+
2026-02-02 00:16:21.466357 | controller -> localhost | |=+....           |
2026-02-02 00:16:21.466375 | controller -> localhost | |B+o.  .          |
2026-02-02 00:16:21.466392 | controller -> localhost | |+==. .E          |
2026-02-02 00:16:21.466410 | controller -> localhost | |o=.. ...         |
2026-02-02 00:16:21.466427 | controller -> localhost | |++ ...+ S        |
2026-02-02 00:16:21.466454 | controller -> localhost | |+o+ o. B         |
2026-02-02 00:16:21.466476 | controller -> localhost | |.+ o ++          |
2026-02-02 00:16:21.466496 | controller -> localhost | |. +.o+=o         |
2026-02-02 00:16:21.466513 | controller -> localhost | | o .oo*=+.       |
2026-02-02 00:16:21.466533 | controller -> localhost | +----[SHA256]-----+
2026-02-02 00:16:21.466582 | controller -> localhost | ok: Runtime: 0:00:00.159505
2026-02-02 00:16:21.473253 | 
2026-02-02 00:16:21.473319 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-02 00:16:21.505091 | controller | ok
2026-02-02 00:16:21.514705 | controller | included: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-02 00:16:21.523261 | 
2026-02-02 00:16:21.523322 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-02 00:16:21.557649 | controller | skipping: Conditional result was False
2026-02-02 00:16:21.566262 | 
2026-02-02 00:16:21.566350 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-02 00:16:21.995525 | controller | changed
2026-02-02 00:16:22.004758 | 
2026-02-02 00:16:22.004855 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-02 00:16:22.242351 | controller | ok
2026-02-02 00:16:22.256882 | 
2026-02-02 00:16:22.257035 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-02 00:16:22.895034 | controller | changed
2026-02-02 00:16:22.904768 | 
2026-02-02 00:16:22.904932 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-02 00:16:23.560437 | controller | changed
2026-02-02 00:16:23.568470 | 
2026-02-02 00:16:23.568554 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-02 00:16:23.583269 | controller | skipping: Conditional result was False
2026-02-02 00:16:23.592588 | 
2026-02-02 00:16:23.592683 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-02 00:16:23.963433 | controller -> localhost | changed
2026-02-02 00:16:24.006156 | 
2026-02-02 00:16:24.006288 | TASK [add-build-sshkey : Add back temp key]
2026-02-02 00:16:24.295712 | controller -> localhost | Identity added: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/7a9def057ad84e53af060f5d0449ff59_id_rsa (zuul-build-sshkey)
2026-02-02 00:16:24.296028 | controller -> localhost | ok: Runtime: 0:00:00.010096
2026-02-02 00:16:24.306048 | 
2026-02-02 00:16:24.306155 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-02 00:16:24.664871 | controller | ok
2026-02-02 00:16:24.681983 | 
2026-02-02 00:16:24.682254 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-02 00:16:24.719605 | controller | skipping: Conditional result was False
2026-02-02 00:16:24.736977 | 
2026-02-02 00:16:24.737077 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-02 00:16:24.771545 | controller | ok
2026-02-02 00:16:24.793756 | 
2026-02-02 00:16:24.793865 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-02 00:16:25.062538 | controller -> localhost | ok
2026-02-02 00:16:25.069122 | 
2026-02-02 00:16:25.069394 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-02 00:16:25.090030 | controller | ok
2026-02-02 00:16:25.103230 | controller | included: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-02 00:16:25.109897 | 
2026-02-02 00:16:25.110033 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-02 00:16:25.442662 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-02 00:16:25.443024 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/7a9def057ad84e53af060f5d0449ff59_id_ecdsa.
2026-02-02 00:16:25.443095 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/7a9def057ad84e53af060f5d0449ff59_id_ecdsa.pub.
2026-02-02 00:16:25.443168 | controller -> localhost | The key fingerprint is:
2026-02-02 00:16:25.443217 | controller -> localhost | SHA256:2/yxG8qaHscq0sz7EtDMe/MpXNF0co33b0ilPimiu0c zuul-build-sshkey
2026-02-02 00:16:25.443262 | controller -> localhost | The key's randomart image is:
2026-02-02 00:16:25.443309 | controller -> localhost | +---[ECDSA 521]---+
2026-02-02 00:16:25.443356 | controller -> localhost | |               o |
2026-02-02 00:16:25.443397 | controller -> localhost | |            o + +|
2026-02-02 00:16:25.443443 | controller -> localhost | |     +     o + +.|
2026-02-02 00:16:25.443487 | controller -> localhost | |    . +   . . o .|
2026-02-02 00:16:25.443531 | controller -> localhost | |     . .S  . o o.|
2026-02-02 00:16:25.443574 | controller -> localhost | |      o o=E . = o|
2026-02-02 00:16:25.443616 | controller -> localhost | |     + +o*=oo. o |
2026-02-02 00:16:25.443659 | controller -> localhost | |    . * +*+o +   |
2026-02-02 00:16:25.443705 | controller -> localhost | |     ..*O*o +.   |
2026-02-02 00:16:25.443790 | controller -> localhost | +----[SHA256]-----+
2026-02-02 00:16:25.443893 | controller -> localhost | ok: Runtime: 0:00:00.025067
2026-02-02 00:16:25.461052 | 
2026-02-02 00:16:25.461217 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-02 00:16:25.494283 | controller | ok
2026-02-02 00:16:25.504786 | controller | included: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-02 00:16:25.518105 | 
2026-02-02 00:16:25.518192 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-02 00:16:25.553479 | controller | skipping: Conditional result was False
2026-02-02 00:16:25.562498 | 
2026-02-02 00:16:25.562598 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-02 00:16:25.837844 | controller | changed
2026-02-02 00:16:25.843986 | 
2026-02-02 00:16:25.844072 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-02 00:16:26.056311 | controller | ok
2026-02-02 00:16:26.062185 | 
2026-02-02 00:16:26.062249 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-02 00:16:27.035134 | controller | changed
2026-02-02 00:16:27.041181 | 
2026-02-02 00:16:27.041245 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-02 00:16:27.732419 | controller | changed
2026-02-02 00:16:27.739175 | 
2026-02-02 00:16:27.739239 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-02 00:16:27.779242 | controller | skipping: Conditional result was False
2026-02-02 00:16:27.824301 | 
2026-02-02 00:16:27.824435 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-02 00:16:28.113835 | controller -> localhost | changed
2026-02-02 00:16:28.125603 | 
2026-02-02 00:16:28.125675 | TASK [add-build-sshkey : Add back temp key]
2026-02-02 00:16:28.405051 | controller -> localhost | Identity added: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/7a9def057ad84e53af060f5d0449ff59_id_ecdsa (zuul-build-sshkey)
2026-02-02 00:16:28.405293 | controller -> localhost | ok: Runtime: 0:00:00.009822
2026-02-02 00:16:28.412255 | 
2026-02-02 00:16:28.412337 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-02 00:16:28.623457 | controller | ok
2026-02-02 00:16:28.642391 | 
2026-02-02 00:16:28.642556 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-02 00:16:28.668918 | controller | skipping: Conditional result was False
2026-02-02 00:16:28.688673 | 
2026-02-02 00:16:28.688861 | TASK [include_role : remove-zuul-sshkey]
2026-02-02 00:16:28.714213 | controller | skipping: Conditional result was False
2026-02-02 00:16:28.723868 | 
2026-02-02 00:16:28.724015 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-02 00:16:28.968502 | controller | ok: "logs"
2026-02-02 00:16:28.969158 | controller | ok: All items complete
2026-02-02 00:16:28.969228 | 
2026-02-02 00:16:29.152555 | controller | ok: "artifacts"
2026-02-02 00:16:29.344149 | controller | ok: "docs"
2026-02-02 00:16:29.362903 | 
2026-02-02 00:16:29.363103 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-02 00:16:29.613018 | controller | changed: "logs"
2026-02-02 00:16:29.810072 | controller | changed: "artifacts"
2026-02-02 00:16:29.994285 | controller | changed: "docs"
2026-02-02 00:16:30.028051 | 
2026-02-02 00:16:30.028153 | PLAY RECAP
2026-02-02 00:16:30.028195 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-02 00:16:30.028219 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-02 00:16:30.028237 | 
2026-02-02 00:16:30.133745 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-02 00:16:30.134562 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-02 00:16:30.743607 | 
2026-02-02 00:16:30.743719 | PLAY [all]
2026-02-02 00:16:30.765494 | 
2026-02-02 00:16:30.765586 | TASK [Install binary dependencies]
2026-02-02 00:16:30.838843 | controller | ok
2026-02-02 00:16:30.865832 | 
2026-02-02 00:16:30.865934 | TASK [bindep : Include find tasks]
2026-02-02 00:16:30.906696 | controller | ok
2026-02-02 00:16:30.914904 | controller | included: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-02 00:16:30.921259 | 
2026-02-02 00:16:30.921324 | TASK [bindep : Look for bindep.txt]
2026-02-02 00:16:31.340052 | controller | ok
2026-02-02 00:16:31.354407 | 
2026-02-02 00:16:31.354601 | TASK [bindep : Define bindep_file fact]
2026-02-02 00:16:31.385327 | controller | skipping: Conditional result was False
2026-02-02 00:16:31.401401 | 
2026-02-02 00:16:31.401584 | TASK [bindep : Look for other-requirements.txt]
2026-02-02 00:16:31.620392 | controller | ok
2026-02-02 00:16:31.625857 | 
2026-02-02 00:16:31.625927 | TASK [bindep : Define bindep_file fact]
2026-02-02 00:16:31.650399 | controller | skipping: Conditional result was False
2026-02-02 00:16:31.657299 | 
2026-02-02 00:16:31.657369 | TASK [bindep : Look for bindep fallback file]
2026-02-02 00:16:31.681622 | controller | skipping: Conditional result was False
2026-02-02 00:16:31.688718 | 
2026-02-02 00:16:31.688832 | TASK [bindep : Define bindep_file fact]
2026-02-02 00:16:31.713291 | controller | skipping: Conditional result was False
2026-02-02 00:16:31.719448 | 
2026-02-02 00:16:31.719518 | TASK [bindep : Include bindep tasks]
2026-02-02 00:16:31.743416 | controller | skipping: Conditional result was False
2026-02-02 00:16:31.749453 | 
2026-02-02 00:16:31.749519 | TASK [bindep : Include install tasks]
2026-02-02 00:16:31.773444 | controller | skipping: Conditional result was False
2026-02-02 00:16:31.782167 | 
2026-02-02 00:16:31.782250 | LOOP [bindep : Include package tasks]
2026-02-02 00:16:31.843328 | 
2026-02-02 00:16:31.843517 | TASK [Run test-setup role]
2026-02-02 00:16:31.868463 | controller | ok
2026-02-02 00:16:31.892129 | 
2026-02-02 00:16:31.892224 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-02 00:16:32.105894 | controller | ok
2026-02-02 00:16:32.112140 | 
2026-02-02 00:16:32.112218 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-02 00:16:32.646817 | controller | skipping: Conditional result was False
2026-02-02 00:16:32.705931 | 
2026-02-02 00:16:32.706112 | PLAY RECAP
2026-02-02 00:16:32.706177 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-02 00:16:32.706206 | 
2026-02-02 00:16:32.883824 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-02 00:16:32.884672 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-02 00:16:33.484849 | 
2026-02-02 00:16:33.484979 | PLAY [controller]
2026-02-02 00:16:33.505852 | 
2026-02-02 00:16:33.505975 | TASK [Create the /root directory]
2026-02-02 00:16:33.870659 | controller | ok
2026-02-02 00:16:33.876694 | 
2026-02-02 00:16:33.876781 | TASK [Install glibc-langpack-en]
2026-02-02 00:16:37.884626 | controller | ok: Nothing to do
2026-02-02 00:16:37.891119 | 
2026-02-02 00:16:37.891191 | TASK [Ensure controller directory exists]
2026-02-02 00:16:38.120659 | controller | changed
2026-02-02 00:16:38.129645 | 
2026-02-02 00:16:38.129764 | TASK [Install container runtime]
2026-02-02 00:16:38.181230 | controller | ok
2026-02-02 00:16:38.217515 | 
2026-02-02 00:16:38.217644 | LOOP [ensure-podman : Find distribution installation]
2026-02-02 00:16:38.241112 | controller | ok: "/var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-02 00:16:38.248473 | controller | included: /var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-02 00:16:38.255128 | 
2026-02-02 00:16:38.255230 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-02 00:17:43.999054 | controller | changed
2026-02-02 00:17:44.005873 | 
2026-02-02 00:17:44.005953 | TASK [ensure-podman : Fetch podman version]
2026-02-02 00:17:44.527116 | controller | Client:       Podman Engine
2026-02-02 00:17:44.527317 | controller | Version:      4.6.2
2026-02-02 00:17:44.527395 | controller | API Version:  4.6.2
2026-02-02 00:17:44.527467 | controller | Go Version:   go1.19.12
2026-02-02 00:17:44.527553 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-02 00:17:44.527753 | controller | OS/Arch:      linux/amd64
2026-02-02 00:17:45.040214 | controller | ok: Runtime: 0:00:00.205597
2026-02-02 00:17:45.046665 | 
2026-02-02 00:17:45.046763 | TASK [ensure-podman : Print podman version installed]
2026-02-02 00:17:45.096620 | Podman version: Client:       Podman Engine
2026-02-02 00:17:45.096773 | Version:      4.6.2
2026-02-02 00:17:45.096803 | API Version:  4.6.2
2026-02-02 00:17:45.096824 | Go Version:   go1.19.12
2026-02-02 00:17:45.096841 | Built:        Mon Aug 28 19:38:31 2023
2026-02-02 00:17:45.096860 | OS/Arch:      linux/amd64
2026-02-02 00:17:45.102378 | 
2026-02-02 00:17:45.102437 | TASK [ensure-podman : Validate podman engine]
2026-02-02 00:17:45.642369 | controller | skipping: Conditional result was False
2026-02-02 00:17:45.652973 | 
2026-02-02 00:17:45.653084 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-02 00:17:45.678001 | controller | skipping: Conditional result was False
2026-02-02 00:17:45.694775 | 
2026-02-02 00:17:45.694874 | TASK [Ensure python3.8 is present]
2026-02-02 00:17:45.709473 | controller | skipping: Conditional result was False
2026-02-02 00:17:45.718446 | 
2026-02-02 00:17:45.718624 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-02 00:17:45.740007 | controller | ok
2026-02-02 00:17:45.762816 | 
2026-02-02 00:17:45.762934 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-02 00:17:47.140146 | controller | ok: Nothing to do
2026-02-02 00:17:47.149430 | 
2026-02-02 00:17:47.149550 | TASK [our-ensure-python : Also install python3-devel]
2026-02-02 00:17:55.931623 | controller | changed
2026-02-02 00:17:55.954048 | 
2026-02-02 00:17:55.954214 | TASK [Run ensure-virtualenv role]
2026-02-02 00:17:55.983184 | controller | ok
2026-02-02 00:17:56.014443 | 
2026-02-02 00:17:56.014570 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-02 00:17:56.259589 | controller | /usr/bin/virtualenv
2026-02-02 00:17:56.577648 | controller | ok: Runtime: 0:00:00.005136
2026-02-02 00:17:56.591529 | 
2026-02-02 00:17:56.591695 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-02 00:17:56.612638 | controller | skipping: Conditional result was False
2026-02-02 00:17:56.613112 | controller | ok: All items complete
2026-02-02 00:17:56.613175 | 
2026-02-02 00:17:56.646691 | 
2026-02-02 00:17:56.646931 | TASK [Find the full path of the Python interpreter]
2026-02-02 00:17:56.886006 | controller | /usr/bin/python3
2026-02-02 00:17:57.200527 | controller | ok
2026-02-02 00:17:57.206613 | 
2026-02-02 00:17:57.206678 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-02 00:17:57.976511 | controller | created virtual environment CPython3.11.0.final.0-64 in 448ms
2026-02-02 00:17:57.992792 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-02 00:17:57.992826 | 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-02-02 00:17:57.992837 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-02 00:17:57.992850 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-02 00:17:58.240960 | controller | changed
2026-02-02 00:17:58.254188 | 
2026-02-02 00:17:58.254323 | TASK [Set selinux package]
2026-02-02 00:17:58.292804 | controller | ok
2026-02-02 00:17:58.306358 | 
2026-02-02 00:17:58.306493 | TASK [Set selinux package (Fedora)]
2026-02-02 00:17:58.355877 | controller | ok
2026-02-02 00:17:58.367209 | 
2026-02-02 00:17:58.367339 | TASK [Install selinux into virtualenv]
2026-02-02 00:18:11.972431 | controller | Collecting selinux-please-lie-to-me
2026-02-02 00:18:24.232310 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-02 00:18:24.551818 | controller | Collecting setuptools<50.0.0
2026-02-02 00:18:24.556913 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-02 00:18:24.604881 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 19.4 MB/s eta 0:00:00
2026-02-02 00:18:24.688354 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-02 00:18:24.688571 | controller |   Attempting uninstall: setuptools
2026-02-02 00:18:24.690979 | controller |     Found existing installation: setuptools 62.6.0
2026-02-02 00:18:24.751609 | controller |     Uninstalling setuptools-62.6.0:
2026-02-02 00:18:24.759587 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-02 00:18:25.126706 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-02 00:18:36.601750 | controller |
2026-02-02 00:18:36.683956 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-02 00:18:36.683998 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-02 00:18:36.941220 | controller | ok: Runtime: 0:00:38.084905
2026-02-02 00:18:36.949928 | 
2026-02-02 00:18:36.950020 | TASK [Install pytest-forked into virtualenv]
2026-02-02 00:18:48.851543 | controller | Collecting pytest-forked
2026-02-02 00:19:01.094136 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-02 00:19:01.145912 | controller | Collecting py
2026-02-02 00:19:01.151316 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-02 00:19:01.167856 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.7 MB/s eta 0:00:00
2026-02-02 00:19:01.278427 | controller | Collecting pytest>=3.10
2026-02-02 00:19:01.283157 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-02 00:19:01.297428 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 30.8 MB/s eta 0:00:00
2026-02-02 00:19:01.327284 | controller | Collecting iniconfig>=1.0.1
2026-02-02 00:19:01.330623 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-02 00:19:01.372477 | controller | Collecting packaging>=22
2026-02-02 00:19:01.375845 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-02 00:19:01.381439 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 20.9 MB/s eta 0:00:00
2026-02-02 00:19:01.411654 | controller | Collecting pluggy<2,>=1.5
2026-02-02 00:19:01.418357 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-02 00:19:01.468203 | controller | Collecting pygments>=2.7.2
2026-02-02 00:19:01.473691 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-02 00:19:01.497326 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 61.9 MB/s eta 0:00:00
2026-02-02 00:19:01.564303 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-02 00:19:02.633863 | 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-02-02 00:19:02.642712 | controller |
2026-02-02 00:19:02.711546 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-02 00:19:02.711590 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-02 00:19:03.030835 | controller | ok: Runtime: 0:00:25.553040
2026-02-02 00:19:03.045156 | 
2026-02-02 00:19:03.045357 | TASK [Update pip]
2026-02-02 00:19:03.611436 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-02 00:19:13.490430 | controller | Collecting pip
2026-02-02 00:19:25.862935 | controller |   Downloading pip-26.0-py3-none-any.whl (1.8 MB)
2026-02-02 00:19:25.920720 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.0 MB/s eta 0:00:00
2026-02-02 00:19:25.990479 | controller | Installing collected packages: pip
2026-02-02 00:19:25.990603 | controller |   Attempting uninstall: pip
2026-02-02 00:19:25.992926 | controller |     Found existing installation: pip 22.2.2
2026-02-02 00:19:26.137974 | controller |     Uninstalling pip-22.2.2:
2026-02-02 00:19:26.153129 | controller |       Successfully uninstalled pip-22.2.2
2026-02-02 00:19:26.964031 | controller | Successfully installed pip-26.0
2026-02-02 00:19:27.153693 | controller | ok: Runtime: 0:00:23.722585
2026-02-02 00:19:27.162207 | 
2026-02-02 00:19:27.162301 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-02 00:19:27.406195 | controller | changed
2026-02-02 00:19:27.417367 | 
2026-02-02 00:19:27.417505 | TASK [Install ansible into virtualenv]
2026-02-02 00:19:27.932882 | controller | Processing ./src/github.com/ansible/ansible
2026-02-02 00:19:27.935465 | controller |   Installing build dependencies: started
2026-02-02 00:19:50.925034 | controller |   Installing build dependencies: finished with status 'done'
2026-02-02 00:19:50.930366 | controller |   Getting requirements to build wheel: started
2026-02-02 00:19:51.721636 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-02 00:19:51.723168 | controller |   Preparing metadata (pyproject.toml): started
2026-02-02 00:19:52.204061 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-02 00:19:52.208818 | 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-02-02 00:19:52.214152 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-02 00:19:52.478378 | controller | ERROR
2026-02-02 00:19:52.478993 | controller | {
2026-02-02 00:19:52.479071 | controller |   "delta": "0:00:24.644057",
2026-02-02 00:19:52.479118 | controller |   "end": "2026-02-02 00:19:52.280691",
2026-02-02 00:19:52.479157 | controller |   "msg": "non-zero return code",
2026-02-02 00:19:52.479214 | controller |   "rc": 1,
2026-02-02 00:19:52.479253 | controller |   "start": "2026-02-02 00:19:27.636634"
2026-02-02 00:19:52.479288 | controller | }
failure
2026-02-02 00:19:52.482392 | 
2026-02-02 00:19:52.482492 | PLAY RECAP
2026-02-02 00:19:52.482576 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-02 00:19:52.482622 | 
2026-02-02 00:19:52.640480 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-02 00:19:52.641616 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-02 00:19:53.263488 | 
2026-02-02 00:19:53.263603 | PLAY [all]
2026-02-02 00:19:53.285161 | 
2026-02-02 00:19:53.285245 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-02 00:19:53.550445 | controller | changed: non-zero return code
2026-02-02 00:19:53.556551 | 
2026-02-02 00:19:53.562565 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-02 00:19:53.597286 | controller | skipping: Conditional result was False
2026-02-02 00:19:53.604213 | 
2026-02-02 00:19:53.604283 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-02 00:19:53.639247 | 
2026-02-02 00:19:53.639420 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-02 00:19:53.670862 | 
2026-02-02 00:19:53.671131 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-02 00:19:53.698949 | controller | skipping: Conditional result was False
2026-02-02 00:19:53.706593 | 
2026-02-02 00:19:53.706668 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-02 00:19:53.758322 | 
2026-02-02 00:19:53.758492 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-02 00:19:53.802773 | controller | skipping: Conditional result was False
2026-02-02 00:19:53.809262 | 
2026-02-02 00:19:53.809334 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-02 00:19:53.853529 | controller | skipping: Conditional result was False
2026-02-02 00:19:53.864408 | 
2026-02-02 00:19:53.864567 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-02 00:19:53.889595 | controller | skipping: Conditional result was False
2026-02-02 00:19:53.922380 | 
2026-02-02 00:19:53.922459 | PLAY RECAP
2026-02-02 00:19:53.922507 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-02 00:19:53.922527 | 
2026-02-02 00:19:54.015803 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-02 00:19:54.016653 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-02 00:19:54.642276 | 
2026-02-02 00:19:54.642438 | PLAY [all:!appliance*]
2026-02-02 00:19:54.691267 | 
2026-02-02 00:19:54.691379 | TASK [unregister the node]
2026-02-02 00:19:55.233088 | controller | skipping: Conditional result was False
2026-02-02 00:19:55.248140 | 
2026-02-02 00:19:55.248348 | TASK [include_role : fetch-output]
2026-02-02 00:19:55.290898 | controller | ok
2026-02-02 00:19:55.312386 | 
2026-02-02 00:19:55.312512 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-02 00:19:55.369664 | controller | skipping: Conditional result was False
2026-02-02 00:19:55.376538 | 
2026-02-02 00:19:55.376626 | TASK [fetch-output : Set log path for single node]
2026-02-02 00:19:55.437549 | controller | ok
2026-02-02 00:19:55.443429 | 
2026-02-02 00:19:55.443550 | LOOP [fetch-output : Ensure local output dirs]
2026-02-02 00:19:55.884624 | controller -> localhost | ok: "/var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/logs"
2026-02-02 00:19:56.130710 | controller -> localhost | changed: "/var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/artifacts"
2026-02-02 00:19:56.364443 | controller -> localhost | changed: "/var/lib/zuul/builds/7a9def057ad84e53af060f5d0449ff59/work/docs"
2026-02-02 00:19:56.382392 | 
2026-02-02 00:19:56.382562 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-02 00:19:57.027532 | controller | changed:
2026-02-02 00:19:57.027713 | controller | .d..t...... ./
2026-02-02 00:19:57.027773 | controller | cd+++++++++ controller/
2026-02-02 00:19:57.027810 | controller | changed: All items complete
2026-02-02 00:19:57.027831 | 
2026-02-02 00:19:57.453765 | controller | changed: .d..t...... ./
2026-02-02 00:19:57.891554 | controller | changed: .d..t...... ./
2026-02-02 00:19:57.915290 | 
2026-02-02 00:19:57.915456 | TASK [include_role : fetch-output-openshift]
2026-02-02 00:19:57.941350 | controller | skipping: Conditional result was False
2026-02-02 00:19:57.948856 | 
2026-02-02 00:19:57.948932 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-02 00:19:57.985615 | controller | skipping: Conditional result was False
2026-02-02 00:19:57.996343 | controller | skipping: Conditional result was False
2026-02-02 00:19:58.031964 | 
2026-02-02 00:19:58.032108 | PLAY [localhost]
2026-02-02 00:19:58.044218 | 
2026-02-02 00:19:58.044282 | TASK [Run Zuul manifest role]
2026-02-02 00:19:58.061956 | localhost | ok
2026-02-02 00:19:58.075847 | 
2026-02-02 00:19:58.075916 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-02 00:19:58.535744 | localhost | changed
2026-02-02 00:19:58.543074 | 
2026-02-02 00:19:58.543166 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-02 00:19:58.575931 | localhost | ok
2026-02-02 00:19:58.588243 | 
2026-02-02 00:19:58.588411 | TASK [Set zuul-log-path fact]
2026-02-02 00:19:58.611166 | localhost | ok
2026-02-02 00:19:58.633303 | 
2026-02-02 00:19:58.633524 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-02 00:19:58.679682 | localhost | ok
2026-02-02 00:19:58.689362 | 
2026-02-02 00:19:58.689454 | LOOP [Run upload-logs-swift role]
2026-02-02 00:19:58.725337 | localhost | Output suppressed because no_log was given
2026-02-02 00:19:58.750264 | 
2026-02-02 00:19:58.750381 | TASK [Set zuul-log-path fact]
2026-02-02 00:19:58.776001 | localhost | skipping: Conditional result was False
2026-02-02 00:19:58.781993 | 
2026-02-02 00:19:58.782067 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-02 00:19:59.207317 | localhost -> localhost | ok: Runtime: 0:00:00.010529
2026-02-02 00:19:59.214799 | 
2026-02-02 00:19:59.214893 | TASK [upload-logs-swift : Upload logs to swift]