2025-12-15 00:06:49.601550 | Job console starting...
2025-12-15 00:06:49.614355 | Updating repositories
2025-12-15 00:06:49.725604 | Preparing job workspace
2025-12-15 00:06:53.207268 | Running Ansible setup...
2025-12-15 00:06:57.911771 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-15 00:06:58.493853 | 
2025-12-15 00:06:58.493980 | PLAY [localhost]
2025-12-15 00:06:58.502402 | 
2025-12-15 00:06:58.502486 | TASK [Gathering Facts]
2025-12-15 00:06:59.567619 | localhost | ok
2025-12-15 00:06:59.582782 | 
2025-12-15 00:06:59.582901 | TASK [Setup log path fact]
2025-12-15 00:06:59.600170 | localhost | ok
2025-12-15 00:06:59.619124 | 
2025-12-15 00:06:59.619202 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-15 00:06:59.646161 | localhost | ok
2025-12-15 00:06:59.654078 | 
2025-12-15 00:06:59.654145 | TASK [emit-job-header : Print job information]
2025-12-15 00:06:59.703400 | # Job Information
2025-12-15 00:06:59.703583 | Ansible Version: 2.15.12
2025-12-15 00:06:59.703625 | Job: ansible-test-sanity-docker-milestone
2025-12-15 00:06:59.703656 | Pipeline: periodic
2025-12-15 00:06:59.703684 | Executor: ze03.softwarefactory-project.io
2025-12-15 00:06:59.703711 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-15 00:06:59.703781 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/eb6/ansible/eb6c64f734044d9fa61aff97f88cd91d/
2025-12-15 00:06:59.703812 | Event ID: 4fcac70710aa4c2dbcb2a11ca9888703
2025-12-15 00:06:59.708825 | 
2025-12-15 00:06:59.708913 | LOOP [emit-job-header : Print node information]
2025-12-15 00:06:59.842276 | localhost | ok:
2025-12-15 00:06:59.842504 | localhost | # Node Information
2025-12-15 00:06:59.842545 | localhost | Inventory Hostname: controller
2025-12-15 00:06:59.842566 | localhost | Hostname: np0005559292
2025-12-15 00:06:59.842584 | localhost | Username: zuul
2025-12-15 00:06:59.842608 | localhost | Distro: Fedora 37
2025-12-15 00:06:59.842637 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-15 00:06:59.842656 | localhost | Region: ca-ymq-1
2025-12-15 00:06:59.842677 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-15 00:06:59.842710 | localhost | Product Name: OpenStack Nova
2025-12-15 00:06:59.842756 | localhost | Interface IP: 162.253.55.204
2025-12-15 00:06:59.856920 | 
2025-12-15 00:06:59.857051 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-15 00:07:00.364256 | localhost -> localhost | changed
2025-12-15 00:07:00.369623 | 
2025-12-15 00:07:00.369701 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-15 00:07:01.296296 | localhost -> localhost | changed
2025-12-15 00:07:01.325247 | 
2025-12-15 00:07:01.325325 | PLAY [all:!appliance*]
2025-12-15 00:07:01.345753 | 
2025-12-15 00:07:01.345866 | TASK [include_role : start-zuul-console]
2025-12-15 00:07:01.376631 | controller | ok
2025-12-15 00:07:01.391862 | 
2025-12-15 00:07:01.391970 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-15 00:07:01.778670 | controller | ok
2025-12-15 00:07:01.799165 | 
2025-12-15 00:07:01.799280 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-15 00:07:02.783946 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-15 00:07:02.790751 | 
2025-12-15 00:07:02.790816 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-15 00:07:03.321582 | controller | skipping: Conditional result was False
2025-12-15 00:07:03.328490 | 
2025-12-15 00:07:03.328597 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-15 00:07:03.352816 | controller | skipping: Conditional result was False
2025-12-15 00:07:03.359279 | 
2025-12-15 00:07:03.359405 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-15 00:07:03.383977 | controller | skipping: Conditional result was False
2025-12-15 00:07:03.390471 | 
2025-12-15 00:07:03.390544 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-15 00:07:03.424986 | controller | skipping: Conditional result was False
2025-12-15 00:07:03.431706 | 
2025-12-15 00:07:03.431861 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-15 00:07:03.457124 | controller | skipping: Conditional result was False
2025-12-15 00:07:03.463825 | 
2025-12-15 00:07:03.463951 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-15 00:07:03.488266 | controller | skipping: Conditional result was False
2025-12-15 00:07:03.500658 | 
2025-12-15 00:07:03.500785 | TASK [Disable Fedora Modular]
2025-12-15 00:07:03.744160 | controller | changed
2025-12-15 00:07:03.749965 | 
2025-12-15 00:07:03.750026 | TASK [Enable EPEL]
2025-12-15 00:07:03.774173 | controller | skipping: Conditional result was False
2025-12-15 00:07:03.780215 | 
2025-12-15 00:07:03.780281 | TASK [Register the RHEL node]
2025-12-15 00:07:04.336977 | 
2025-12-15 00:07:04.337258 | TASK [Show the subscription-manager status]
2025-12-15 00:07:04.932485 | controller | skipping: Conditional result was False
2025-12-15 00:07:04.946828 | 
2025-12-15 00:07:04.946967 | TASK [Enable EPEL on RHEL]
2025-12-15 00:07:05.503853 | controller | skipping: Conditional result was False
2025-12-15 00:07:05.517665 | 
2025-12-15 00:07:05.517894 | TASK [Install git and tox]
2025-12-15 00:08:30.732374 | controller | changed
2025-12-15 00:08:30.741472 | 
2025-12-15 00:08:30.741583 | TASK [include_role : prepare-workspace]
2025-12-15 00:08:30.764094 | controller | ok
2025-12-15 00:08:30.793238 | 
2025-12-15 00:08:30.793357 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-15 00:08:31.043533 | controller | ok
2025-12-15 00:08:31.057898 | 
2025-12-15 00:08:31.058050 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-15 00:08:43.701027 | controller | Output suppressed because no_log was given
2025-12-15 00:08:43.718851 | 
2025-12-15 00:08:43.719025 | TASK [include_role : prepare-workspace-openshift]
2025-12-15 00:08:43.739092 | controller | skipping: Conditional result was False
2025-12-15 00:08:43.810982 | 
2025-12-15 00:08:43.811076 | PLAY [all:!appliance]
2025-12-15 00:08:43.829780 | 
2025-12-15 00:08:43.829908 | TASK [Run add-build-sshkey role (RSA)]
2025-12-15 00:08:43.859940 | controller | ok
2025-12-15 00:08:43.878144 | 
2025-12-15 00:08:43.878251 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-15 00:08:44.105172 | controller -> localhost | ok
2025-12-15 00:08:44.112194 | 
2025-12-15 00:08:44.112272 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-15 00:08:44.142684 | controller | ok
2025-12-15 00:08:44.157929 | controller | included: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-15 00:08:44.165302 | 
2025-12-15 00:08:44.165391 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-15 00:08:44.659618 | controller -> localhost | Generating public/private rsa key pair.
2025-12-15 00:08:44.659882 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/eb6c64f734044d9fa61aff97f88cd91d_id_rsa.
2025-12-15 00:08:44.659926 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/eb6c64f734044d9fa61aff97f88cd91d_id_rsa.pub.
2025-12-15 00:08:44.659958 | controller -> localhost | The key fingerprint is:
2025-12-15 00:08:44.659988 | controller -> localhost | SHA256:lUmxXo1FzXQNqaiPKe4/042oCHav7ftVm3R1Nk0hAS4 zuul-build-sshkey
2025-12-15 00:08:44.660017 | controller -> localhost | The key's randomart image is:
2025-12-15 00:08:44.660045 | controller -> localhost | +---[RSA 2048]----+
2025-12-15 00:08:44.660072 | controller -> localhost | |          oo.+=B*|
2025-12-15 00:08:44.660101 | controller -> localhost | |         ..+ +o.*|
2025-12-15 00:08:44.660129 | controller -> localhost | |         E=oo...=|
2025-12-15 00:08:44.660157 | controller -> localhost | |         oo..  oo|
2025-12-15 00:08:44.660185 | controller -> localhost | |        S.. o .  |
2025-12-15 00:08:44.660226 | controller -> localhost | |        .  o +   |
2025-12-15 00:08:44.660260 | controller -> localhost | |  o .    *.oo    |
2025-12-15 00:08:44.660289 | controller -> localhost | | . o +. *.+ .    |
2025-12-15 00:08:44.660317 | controller -> localhost | |    o=O*oo       |
2025-12-15 00:08:44.660347 | controller -> localhost | +----[SHA256]-----+
2025-12-15 00:08:44.660405 | controller -> localhost | ok: Runtime: 0:00:00.113161
2025-12-15 00:08:44.670180 | 
2025-12-15 00:08:44.670274 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-15 00:08:44.704705 | controller | ok
2025-12-15 00:08:44.719218 | controller | included: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-15 00:08:44.728282 | 
2025-12-15 00:08:44.728360 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-15 00:08:44.753172 | controller | skipping: Conditional result was False
2025-12-15 00:08:44.764782 | 
2025-12-15 00:08:44.764879 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-15 00:08:45.201964 | controller | changed
2025-12-15 00:08:45.207648 | 
2025-12-15 00:08:45.207714 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-15 00:08:45.424661 | controller | ok
2025-12-15 00:08:45.440561 | 
2025-12-15 00:08:45.440697 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-15 00:08:46.080311 | controller | changed
2025-12-15 00:08:46.094178 | 
2025-12-15 00:08:46.094339 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-15 00:08:46.737419 | controller | changed
2025-12-15 00:08:46.745789 | 
2025-12-15 00:08:46.745878 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-15 00:08:46.770623 | controller | skipping: Conditional result was False
2025-12-15 00:08:46.780522 | 
2025-12-15 00:08:46.780636 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-15 00:08:47.163006 | controller -> localhost | changed
2025-12-15 00:08:47.174284 | 
2025-12-15 00:08:47.174360 | TASK [add-build-sshkey : Add back temp key]
2025-12-15 00:08:47.523482 | controller -> localhost | Identity added: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/eb6c64f734044d9fa61aff97f88cd91d_id_rsa (zuul-build-sshkey)
2025-12-15 00:08:47.523742 | controller -> localhost | ok: Runtime: 0:00:00.010420
2025-12-15 00:08:47.532235 | 
2025-12-15 00:08:47.532319 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-15 00:08:47.883656 | controller | ok
2025-12-15 00:08:47.892091 | 
2025-12-15 00:08:47.892220 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-15 00:08:47.919657 | controller | skipping: Conditional result was False
2025-12-15 00:08:47.940424 | 
2025-12-15 00:08:47.940639 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-15 00:08:47.976798 | controller | ok
2025-12-15 00:08:48.015021 | 
2025-12-15 00:08:48.015269 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-15 00:08:48.329237 | controller -> localhost | ok
2025-12-15 00:08:48.337076 | 
2025-12-15 00:08:48.337179 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-15 00:08:48.372336 | controller | ok
2025-12-15 00:08:48.390304 | controller | included: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-15 00:08:48.400201 | 
2025-12-15 00:08:48.400311 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-15 00:08:48.710872 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-15 00:08:48.711084 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/eb6c64f734044d9fa61aff97f88cd91d_id_ecdsa.
2025-12-15 00:08:48.711113 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/eb6c64f734044d9fa61aff97f88cd91d_id_ecdsa.pub.
2025-12-15 00:08:48.711143 | controller -> localhost | The key fingerprint is:
2025-12-15 00:08:48.711164 | controller -> localhost | SHA256:JnyBVpdSijuPC+pTokVRDkNlVYrTuEIn5RlNIkk3O1o zuul-build-sshkey
2025-12-15 00:08:48.711184 | controller -> localhost | The key's randomart image is:
2025-12-15 00:08:48.711202 | controller -> localhost | +---[ECDSA 521]---+
2025-12-15 00:08:48.711220 | controller -> localhost | | o*+X+o.o.o.     |
2025-12-15 00:08:48.711238 | controller -> localhost | |  oX X.=.o.      |
2025-12-15 00:08:48.711255 | controller -> localhost | |  o.E * o.       |
2025-12-15 00:08:48.711273 | controller -> localhost | | ..= * . .       |
2025-12-15 00:08:48.711290 | controller -> localhost | | .o . = S        |
2025-12-15 00:08:48.711308 | controller -> localhost | |  o..  B         |
2025-12-15 00:08:48.711325 | controller -> localhost | | o o. . .        |
2025-12-15 00:08:48.711341 | controller -> localhost | |. .. . .         |
2025-12-15 00:08:48.711358 | controller -> localhost | | .o.  .          |
2025-12-15 00:08:48.711375 | controller -> localhost | +----[SHA256]-----+
2025-12-15 00:08:48.711428 | controller -> localhost | ok: Runtime: 0:00:00.014275
2025-12-15 00:08:48.718291 | 
2025-12-15 00:08:48.718354 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-15 00:08:48.749640 | controller | ok
2025-12-15 00:08:48.757135 | controller | included: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-15 00:08:48.766134 | 
2025-12-15 00:08:48.766200 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-15 00:08:48.781119 | controller | skipping: Conditional result was False
2025-12-15 00:08:48.788556 | 
2025-12-15 00:08:48.788624 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-15 00:08:49.041521 | controller | changed
2025-12-15 00:08:49.048030 | 
2025-12-15 00:08:49.048093 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-15 00:08:49.282714 | controller | ok
2025-12-15 00:08:49.288817 | 
2025-12-15 00:08:49.288888 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-15 00:08:49.957280 | controller | changed
2025-12-15 00:08:49.965534 | 
2025-12-15 00:08:49.965668 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-15 00:08:50.596861 | controller | changed
2025-12-15 00:08:50.602579 | 
2025-12-15 00:08:50.602643 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-15 00:08:50.626463 | controller | skipping: Conditional result was False
2025-12-15 00:08:50.640472 | 
2025-12-15 00:08:50.640625 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-15 00:08:50.890627 | controller -> localhost | changed
2025-12-15 00:08:50.902317 | 
2025-12-15 00:08:50.902411 | TASK [add-build-sshkey : Add back temp key]
2025-12-15 00:08:51.180757 | controller -> localhost | Identity added: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/eb6c64f734044d9fa61aff97f88cd91d_id_ecdsa (zuul-build-sshkey)
2025-12-15 00:08:51.180971 | controller -> localhost | ok: Runtime: 0:00:00.008045
2025-12-15 00:08:51.217825 | 
2025-12-15 00:08:51.217949 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-15 00:08:51.424746 | controller | ok
2025-12-15 00:08:51.430452 | 
2025-12-15 00:08:51.430528 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-15 00:08:51.454689 | controller | skipping: Conditional result was False
2025-12-15 00:08:51.466256 | 
2025-12-15 00:08:51.466338 | TASK [include_role : remove-zuul-sshkey]
2025-12-15 00:08:51.479814 | controller | skipping: Conditional result was False
2025-12-15 00:08:51.487569 | 
2025-12-15 00:08:51.487665 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-15 00:08:51.730224 | controller | ok: "logs"
2025-12-15 00:08:51.730491 | controller | ok: All items complete
2025-12-15 00:08:51.730524 | 
2025-12-15 00:08:51.925829 | controller | ok: "artifacts"
2025-12-15 00:08:52.117668 | controller | ok: "docs"
2025-12-15 00:08:52.153654 | 
2025-12-15 00:08:52.153888 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-15 00:08:52.390349 | controller | changed: "logs"
2025-12-15 00:08:52.602516 | controller | changed: "artifacts"
2025-12-15 00:08:52.796196 | controller | changed: "docs"
2025-12-15 00:08:52.849199 | 
2025-12-15 00:08:52.849315 | PLAY RECAP
2025-12-15 00:08:52.849374 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-15 00:08:52.849411 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-15 00:08:52.849438 | 
2025-12-15 00:08:52.960067 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-15 00:08:52.960948 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-15 00:08:53.567720 | 
2025-12-15 00:08:53.567858 | PLAY [all]
2025-12-15 00:08:53.591998 | 
2025-12-15 00:08:53.592139 | TASK [Install binary dependencies]
2025-12-15 00:08:53.680515 | controller | ok
2025-12-15 00:08:53.710470 | 
2025-12-15 00:08:53.710618 | TASK [bindep : Include find tasks]
2025-12-15 00:08:53.758223 | controller | ok
2025-12-15 00:08:53.774046 | controller | included: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-15 00:08:53.784133 | 
2025-12-15 00:08:53.784267 | TASK [bindep : Look for bindep.txt]
2025-12-15 00:08:54.120015 | controller | ok
2025-12-15 00:08:54.125831 | 
2025-12-15 00:08:54.125961 | TASK [bindep : Define bindep_file fact]
2025-12-15 00:08:54.151816 | controller | skipping: Conditional result was False
2025-12-15 00:08:54.165151 | 
2025-12-15 00:08:54.165301 | TASK [bindep : Look for other-requirements.txt]
2025-12-15 00:08:54.396344 | controller | ok
2025-12-15 00:08:54.409018 | 
2025-12-15 00:08:54.409165 | TASK [bindep : Define bindep_file fact]
2025-12-15 00:08:54.446190 | controller | skipping: Conditional result was False
2025-12-15 00:08:54.460001 | 
2025-12-15 00:08:54.460186 | TASK [bindep : Look for bindep fallback file]
2025-12-15 00:08:54.497673 | controller | skipping: Conditional result was False
2025-12-15 00:08:54.514818 | 
2025-12-15 00:08:54.514997 | TASK [bindep : Define bindep_file fact]
2025-12-15 00:08:54.552108 | controller | skipping: Conditional result was False
2025-12-15 00:08:54.566454 | 
2025-12-15 00:08:54.566611 | TASK [bindep : Include bindep tasks]
2025-12-15 00:08:54.593314 | controller | skipping: Conditional result was False
2025-12-15 00:08:54.607854 | 
2025-12-15 00:08:54.608172 | TASK [bindep : Include install tasks]
2025-12-15 00:08:54.634801 | controller | skipping: Conditional result was False
2025-12-15 00:08:54.649654 | 
2025-12-15 00:08:54.649848 | LOOP [bindep : Include package tasks]
2025-12-15 00:08:54.732689 | 
2025-12-15 00:08:54.733024 | TASK [Run test-setup role]
2025-12-15 00:08:54.770903 | controller | ok
2025-12-15 00:08:54.797934 | 
2025-12-15 00:08:54.798052 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-15 00:08:55.030105 | controller | ok
2025-12-15 00:08:55.044275 | 
2025-12-15 00:08:55.044411 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-15 00:08:55.594539 | controller | skipping: Conditional result was False
2025-12-15 00:08:55.631285 | 
2025-12-15 00:08:55.631380 | PLAY RECAP
2025-12-15 00:08:55.631453 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-15 00:08:55.631491 | 
2025-12-15 00:08:55.772005 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-15 00:08:55.773682 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-15 00:08:56.392974 | 
2025-12-15 00:08:56.393121 | PLAY [controller]
2025-12-15 00:08:56.414280 | 
2025-12-15 00:08:56.414379 | TASK [Create the /root directory]
2025-12-15 00:08:56.783700 | controller | ok
2025-12-15 00:08:56.797051 | 
2025-12-15 00:08:56.797214 | TASK [Install glibc-langpack-en]
2025-12-15 00:09:00.751165 | controller | ok: Nothing to do
2025-12-15 00:09:00.759247 | 
2025-12-15 00:09:00.759340 | TASK [Ensure controller directory exists]
2025-12-15 00:09:00.976509 | controller | changed
2025-12-15 00:09:00.985208 | 
2025-12-15 00:09:00.985311 | TASK [Install container runtime]
2025-12-15 00:09:01.034684 | controller | ok
2025-12-15 00:09:01.088131 | 
2025-12-15 00:09:01.088282 | LOOP [ensure-podman : Find distribution installation]
2025-12-15 00:09:01.139145 | controller | ok: "/var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-15 00:09:01.153419 | controller | included: /var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-15 00:09:01.162543 | 
2025-12-15 00:09:01.162638 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-15 00:10:09.191119 | controller | changed
2025-12-15 00:10:09.198403 | 
2025-12-15 00:10:09.198486 | TASK [ensure-podman : Fetch podman version]
2025-12-15 00:10:09.804986 | controller | Client:       Podman Engine
2025-12-15 00:10:09.835521 | controller | Version:      4.6.2
2025-12-15 00:10:09.835589 | controller | API Version:  4.6.2
2025-12-15 00:10:09.835599 | controller | Go Version:   go1.19.12
2025-12-15 00:10:09.835619 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-15 00:10:09.835633 | controller | OS/Arch:      linux/amd64
2025-12-15 00:10:10.233093 | controller | ok: Runtime: 0:00:00.296498
2025-12-15 00:10:10.241699 | 
2025-12-15 00:10:10.241811 | TASK [ensure-podman : Print podman version installed]
2025-12-15 00:10:10.274153 | Podman version: Client:       Podman Engine
2025-12-15 00:10:10.274313 | Version:      4.6.2
2025-12-15 00:10:10.274342 | API Version:  4.6.2
2025-12-15 00:10:10.274362 | Go Version:   go1.19.12
2025-12-15 00:10:10.274380 | Built:        Mon Aug 28 19:38:31 2023
2025-12-15 00:10:10.274398 | OS/Arch:      linux/amd64
2025-12-15 00:10:10.280320 | 
2025-12-15 00:10:10.280397 | TASK [ensure-podman : Validate podman engine]
2025-12-15 00:10:10.810983 | controller | skipping: Conditional result was False
2025-12-15 00:10:10.817942 | 
2025-12-15 00:10:10.818023 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-15 00:10:10.842383 | controller | skipping: Conditional result was False
2025-12-15 00:10:10.854856 | 
2025-12-15 00:10:10.854924 | TASK [Ensure python3.8 is present]
2025-12-15 00:10:10.869792 | controller | skipping: Conditional result was False
2025-12-15 00:10:10.877789 | 
2025-12-15 00:10:10.877863 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-15 00:10:10.897818 | controller | ok
2025-12-15 00:10:10.918857 | 
2025-12-15 00:10:10.918962 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-15 00:10:12.525818 | controller | ok: Nothing to do
2025-12-15 00:10:12.532543 | 
2025-12-15 00:10:12.532642 | TASK [our-ensure-python : Also install python3-devel]
2025-12-15 00:10:23.160964 | controller | changed
2025-12-15 00:10:23.176397 | 
2025-12-15 00:10:23.176477 | TASK [Run ensure-virtualenv role]
2025-12-15 00:10:23.201205 | controller | ok
2025-12-15 00:10:23.233226 | 
2025-12-15 00:10:23.233318 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-15 00:10:23.484242 | controller | /usr/bin/virtualenv
2025-12-15 00:10:23.807326 | controller | ok: Runtime: 0:00:00.005301
2025-12-15 00:10:23.816303 | 
2025-12-15 00:10:23.816515 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-15 00:10:23.850183 | controller | skipping: Conditional result was False
2025-12-15 00:10:23.850465 | controller | ok: All items complete
2025-12-15 00:10:23.850503 | 
2025-12-15 00:10:23.868673 | 
2025-12-15 00:10:23.868831 | TASK [Find the full path of the Python interpreter]
2025-12-15 00:10:24.105760 | controller | /usr/bin/python3
2025-12-15 00:10:24.423341 | controller | ok
2025-12-15 00:10:24.434376 | 
2025-12-15 00:10:24.434505 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-15 00:10:25.305182 | controller | created virtual environment CPython3.11.0.final.0-64 in 524ms
2025-12-15 00:10:25.338862 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-15 00:10:25.338909 | 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)
2025-12-15 00:10:25.338919 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-15 00:10:25.338934 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-15 00:10:25.492455 | controller | changed
2025-12-15 00:10:25.504052 | 
2025-12-15 00:10:25.504161 | TASK [Set selinux package]
2025-12-15 00:10:25.539352 | controller | ok
2025-12-15 00:10:25.548019 | 
2025-12-15 00:10:25.548170 | TASK [Set selinux package (Fedora)]
2025-12-15 00:10:25.583373 | controller | ok
2025-12-15 00:10:25.592445 | 
2025-12-15 00:10:25.592595 | TASK [Install selinux into virtualenv]
2025-12-15 00:11:27.000384 | controller | Collecting selinux-please-lie-to-me
2025-12-15 00:11:39.379199 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-15 00:11:39.696668 | controller | Collecting setuptools<50.0.0
2025-12-15 00:11:39.706006 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-15 00:11:39.749939 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 23.2 MB/s eta 0:00:00
2025-12-15 00:11:39.831717 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-15 00:11:39.831932 | controller |   Attempting uninstall: setuptools
2025-12-15 00:11:39.834330 | controller |     Found existing installation: setuptools 62.6.0
2025-12-15 00:11:39.893657 | controller |     Uninstalling setuptools-62.6.0:
2025-12-15 00:11:39.901545 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-15 00:11:40.249710 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-15 00:11:51.740607 | controller |
2025-12-15 00:11:51.823373 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-15 00:11:51.823414 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-15 00:11:52.186151 | controller | ok: Runtime: 0:01:26.020110
2025-12-15 00:11:52.200042 | 
2025-12-15 00:11:52.200173 | TASK [Install pytest-forked into virtualenv]
2025-12-15 00:12:04.035215 | controller | Collecting pytest-forked
2025-12-15 00:12:28.252006 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-15 00:12:28.327851 | controller | Collecting py
2025-12-15 00:12:28.354681 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-15 00:12:28.372972 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.3 MB/s eta 0:00:00
2025-12-15 00:12:28.485447 | controller | Collecting pytest>=3.10
2025-12-15 00:12:28.506054 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-15 00:12:28.521878 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 30.5 MB/s eta 0:00:00
2025-12-15 00:12:28.559602 | controller | Collecting iniconfig>=1.0.1
2025-12-15 00:12:28.576675 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-15 00:12:28.621400 | controller | Collecting packaging>=22
2025-12-15 00:12:28.630730 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-15 00:12:28.638604 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.0 MB/s eta 0:00:00
2025-12-15 00:12:28.669688 | controller | Collecting pluggy<2,>=1.5
2025-12-15 00:12:28.673481 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-15 00:12:28.718144 | controller | Collecting pygments>=2.7.2
2025-12-15 00:12:28.731937 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-15 00:12:28.752396 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 70.8 MB/s eta 0:00:00
2025-12-15 00:12:28.820872 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-15 00:12:29.824925 | 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
2025-12-15 00:12:29.833335 | controller |
2025-12-15 00:12:29.898995 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-15 00:12:29.899038 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-15 00:12:30.281159 | controller | ok: Runtime: 0:00:37.425239
2025-12-15 00:12:30.296924 | 
2025-12-15 00:12:30.297103 | TASK [Update pip]
2025-12-15 00:12:30.859178 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-15 00:12:43.276524 | controller | Collecting pip
2025-12-15 00:12:55.475915 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-15 00:12:55.556719 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 23.2 MB/s eta 0:00:00
2025-12-15 00:12:55.623445 | controller | Installing collected packages: pip
2025-12-15 00:12:55.623509 | controller |   Attempting uninstall: pip
2025-12-15 00:12:55.625828 | controller |     Found existing installation: pip 22.2.2
2025-12-15 00:12:55.761924 | controller |     Uninstalling pip-22.2.2:
2025-12-15 00:12:55.777069 | controller |       Successfully uninstalled pip-22.2.2
2025-12-15 00:12:56.600890 | controller | Successfully installed pip-25.3
2025-12-15 00:12:56.870929 | controller | ok: Runtime: 0:00:26.137386
2025-12-15 00:12:56.889179 | 
2025-12-15 00:12:56.889434 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-15 00:12:57.123372 | controller | changed
2025-12-15 00:12:57.131428 | 
2025-12-15 00:12:57.131520 | TASK [Install ansible into virtualenv]
2025-12-15 00:12:57.656071 | controller | Processing ./src/github.com/ansible/ansible
2025-12-15 00:12:57.659349 | controller |   Installing build dependencies: started
2025-12-15 00:13:20.573677 | controller |   Installing build dependencies: finished with status 'done'
2025-12-15 00:13:20.574841 | controller |   Getting requirements to build wheel: started
2025-12-15 00:13:21.282023 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-15 00:13:21.283271 | controller |   Preparing metadata (pyproject.toml): started
2025-12-15 00:13:21.759938 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-15 00:13:21.765144 | 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.
2025-12-15 00:13:21.770008 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-15 00:13:22.231543 | controller | ERROR
2025-12-15 00:13:22.231928 | controller | {
2025-12-15 00:13:22.232015 | controller |   "delta": "0:00:24.454675",
2025-12-15 00:13:22.232077 | controller |   "end": "2025-12-15 00:13:21.836760",
2025-12-15 00:13:22.232124 | controller |   "msg": "non-zero return code",
2025-12-15 00:13:22.232184 | controller |   "rc": 1,
2025-12-15 00:13:22.232224 | controller |   "start": "2025-12-15 00:12:57.382085"
2025-12-15 00:13:22.232261 | controller | }
failure
2025-12-15 00:13:22.235200 | 
2025-12-15 00:13:22.235336 | PLAY RECAP
2025-12-15 00:13:22.235438 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-15 00:13:22.235486 | 
2025-12-15 00:13:22.401838 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-15 00:13:22.403152 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-15 00:13:22.983777 | 
2025-12-15 00:13:22.983910 | PLAY [all]
2025-12-15 00:13:23.006885 | 
2025-12-15 00:13:23.007002 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-15 00:13:23.274352 | controller | changed: non-zero return code
2025-12-15 00:13:23.281669 | 
2025-12-15 00:13:23.281776 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-15 00:13:23.298462 | controller | skipping: Conditional result was False
2025-12-15 00:13:23.307850 | 
2025-12-15 00:13:23.308055 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-15 00:13:23.343785 | 
2025-12-15 00:13:23.344064 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-15 00:13:23.380719 | 
2025-12-15 00:13:23.380973 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-15 00:13:23.397573 | controller | skipping: Conditional result was False
2025-12-15 00:13:23.410075 | 
2025-12-15 00:13:23.410181 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-15 00:13:23.445870 | 
2025-12-15 00:13:23.446109 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-15 00:13:23.473282 | controller | skipping: Conditional result was False
2025-12-15 00:13:23.480684 | 
2025-12-15 00:13:23.480802 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-15 00:13:23.506390 | controller | skipping: Conditional result was False
2025-12-15 00:13:23.515779 | 
2025-12-15 00:13:23.515871 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-15 00:13:23.541926 | controller | skipping: Conditional result was False
2025-12-15 00:13:23.576661 | 
2025-12-15 00:13:23.576770 | PLAY RECAP
2025-12-15 00:13:23.576811 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-15 00:13:23.576830 | 
2025-12-15 00:13:23.737997 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-15 00:13:23.739118 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-15 00:13:24.286911 | 
2025-12-15 00:13:24.287013 | PLAY [all:!appliance*]
2025-12-15 00:13:24.307701 | 
2025-12-15 00:13:24.307796 | TASK [unregister the node]
2025-12-15 00:13:24.837415 | controller | skipping: Conditional result was False
2025-12-15 00:13:24.851505 | 
2025-12-15 00:13:24.851676 | TASK [include_role : fetch-output]
2025-12-15 00:13:24.893015 | controller | ok
2025-12-15 00:13:24.932876 | 
2025-12-15 00:13:24.932977 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-15 00:13:24.988869 | controller | skipping: Conditional result was False
2025-12-15 00:13:25.004317 | 
2025-12-15 00:13:25.004636 | TASK [fetch-output : Set log path for single node]
2025-12-15 00:13:25.065946 | controller | ok
2025-12-15 00:13:25.078753 | 
2025-12-15 00:13:25.078902 | LOOP [fetch-output : Ensure local output dirs]
2025-12-15 00:13:25.594982 | controller -> localhost | ok: "/var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/logs"
2025-12-15 00:13:25.842905 | controller -> localhost | changed: "/var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/artifacts"
2025-12-15 00:13:26.123359 | controller -> localhost | changed: "/var/lib/zuul/builds/eb6c64f734044d9fa61aff97f88cd91d/work/docs"
2025-12-15 00:13:26.139017 | 
2025-12-15 00:13:26.139143 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-15 00:13:26.905390 | controller | changed:
2025-12-15 00:13:26.905992 | controller | .d..t...... ./
2025-12-15 00:13:26.906083 | controller | cd+++++++++ controller/
2025-12-15 00:13:26.906164 | controller | changed: All items complete
2025-12-15 00:13:26.906214 | 
2025-12-15 00:13:27.449903 | controller | changed: .d..t...... ./
2025-12-15 00:13:27.961889 | controller | changed: .d..t...... ./
2025-12-15 00:13:27.996926 | 
2025-12-15 00:13:27.997183 | TASK [include_role : fetch-output-openshift]
2025-12-15 00:13:28.025599 | controller | skipping: Conditional result was False
2025-12-15 00:13:28.036901 | 
2025-12-15 00:13:28.037091 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-15 00:13:28.087591 | controller | skipping: Conditional result was False
2025-12-15 00:13:28.105326 | controller | skipping: Conditional result was False
2025-12-15 00:13:28.147253 | 
2025-12-15 00:13:28.147452 | PLAY [localhost]
2025-12-15 00:13:28.165436 | 
2025-12-15 00:13:28.165667 | TASK [Run Zuul manifest role]
2025-12-15 00:13:28.188953 | localhost | ok
2025-12-15 00:13:28.205826 | 
2025-12-15 00:13:28.205970 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-15 00:13:28.701188 | localhost | changed
2025-12-15 00:13:28.706759 | 
2025-12-15 00:13:28.706834 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-15 00:13:28.748600 | localhost | ok
2025-12-15 00:13:28.757956 | 
2025-12-15 00:13:28.758027 | TASK [Set zuul-log-path fact]
2025-12-15 00:13:28.779203 | localhost | ok
2025-12-15 00:13:28.805499 | 
2025-12-15 00:13:28.805813 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-15 00:13:28.838200 | localhost | ok
2025-12-15 00:13:28.846429 | 
2025-12-15 00:13:28.846489 | LOOP [Run upload-logs-swift role]
2025-12-15 00:13:28.892898 | localhost | Output suppressed because no_log was given
2025-12-15 00:13:28.920557 | 
2025-12-15 00:13:28.920632 | TASK [Set zuul-log-path fact]
2025-12-15 00:13:28.956214 | localhost | skipping: Conditional result was False
2025-12-15 00:13:28.961775 | 
2025-12-15 00:13:28.961842 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-15 00:13:29.439253 | localhost -> localhost | ok: Runtime: 0:00:00.010140
2025-12-15 00:13:29.496215 | 
2025-12-15 00:13:29.496366 | TASK [upload-logs-swift : Upload logs to swift]