2026-02-15 00:06:57.297755 | Job console starting...
2026-02-15 00:06:57.310959 | Updating repositories
2026-02-15 00:06:57.485217 | Preparing job workspace
2026-02-15 00:07:01.374330 | Running Ansible setup...
2026-02-15 00:07:06.050044 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-15 00:07:06.653737 | 
2026-02-15 00:07:06.653852 | PLAY [localhost]
2026-02-15 00:07:06.662155 | 
2026-02-15 00:07:06.662224 | TASK [Gathering Facts]
2026-02-15 00:07:07.552967 | localhost | ok
2026-02-15 00:07:07.573073 | 
2026-02-15 00:07:07.573247 | TASK [Setup log path fact]
2026-02-15 00:07:07.591543 | localhost | ok
2026-02-15 00:07:07.605723 | 
2026-02-15 00:07:07.605811 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-15 00:07:07.635597 | localhost | ok
2026-02-15 00:07:07.647285 | 
2026-02-15 00:07:07.647417 | TASK [emit-job-header : Print job information]
2026-02-15 00:07:07.697637 | # Job Information
2026-02-15 00:07:07.697834 | Ansible Version: 2.15.12
2026-02-15 00:07:07.697877 | Job: ansible-test-sanity-docker-devel
2026-02-15 00:07:07.697904 | Pipeline: periodic
2026-02-15 00:07:07.697928 | Executor: ze02.softwarefactory-project.io
2026-02-15 00:07:07.697954 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-15 00:07:07.697980 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/873/ansible/873289252c154a7194275cf1c2f19539/
2026-02-15 00:07:07.698003 | Event ID: bfcfc7f67e194cfab2f082a1d8ce3d78
2026-02-15 00:07:07.702192 | 
2026-02-15 00:07:07.702256 | LOOP [emit-job-header : Print node information]
2026-02-15 00:07:07.805812 | localhost | ok:
2026-02-15 00:07:07.805980 | localhost | # Node Information
2026-02-15 00:07:07.806007 | localhost | Inventory Hostname: controller
2026-02-15 00:07:07.806028 | localhost | Hostname: np0005620021
2026-02-15 00:07:07.806048 | localhost | Username: zuul
2026-02-15 00:07:07.806070 | localhost | Distro: Fedora 37
2026-02-15 00:07:07.806088 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-15 00:07:07.806106 | localhost | Region: ca-ymq-1
2026-02-15 00:07:07.806123 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-15 00:07:07.806139 | localhost | Product Name: OpenStack Nova
2026-02-15 00:07:07.806156 | localhost | Interface IP: 162.253.55.62
2026-02-15 00:07:07.819555 | 
2026-02-15 00:07:07.819736 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-15 00:07:08.201353 | localhost -> localhost | changed
2026-02-15 00:07:08.207687 | 
2026-02-15 00:07:08.208756 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-15 00:07:09.099902 | localhost -> localhost | changed
2026-02-15 00:07:09.119142 | 
2026-02-15 00:07:09.119219 | PLAY [all:!appliance*]
2026-02-15 00:07:09.135184 | 
2026-02-15 00:07:09.135248 | TASK [include_role : start-zuul-console]
2026-02-15 00:07:09.154246 | controller | ok
2026-02-15 00:07:09.167526 | 
2026-02-15 00:07:09.167659 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-15 00:07:09.569762 | controller | ok
2026-02-15 00:07:09.595019 | 
2026-02-15 00:07:09.595155 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-15 00:07:10.481462 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-15 00:07:10.492554 | 
2026-02-15 00:07:10.492708 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-15 00:07:11.054491 | controller | skipping: Conditional result was False
2026-02-15 00:07:11.065393 | 
2026-02-15 00:07:11.065523 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-15 00:07:11.092175 | controller | skipping: Conditional result was False
2026-02-15 00:07:11.102285 | 
2026-02-15 00:07:11.102449 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-15 00:07:11.127383 | controller | skipping: Conditional result was False
2026-02-15 00:07:11.138110 | 
2026-02-15 00:07:11.138249 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-15 00:07:11.165391 | controller | skipping: Conditional result was False
2026-02-15 00:07:11.176004 | 
2026-02-15 00:07:11.176144 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-15 00:07:11.202550 | controller | skipping: Conditional result was False
2026-02-15 00:07:11.212753 | 
2026-02-15 00:07:11.212890 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-15 00:07:11.251989 | controller | skipping: Conditional result was False
2026-02-15 00:07:11.274398 | 
2026-02-15 00:07:11.274552 | TASK [Disable Fedora Modular]
2026-02-15 00:07:11.567718 | controller | changed
2026-02-15 00:07:11.590987 | 
2026-02-15 00:07:11.591194 | TASK [Enable EPEL]
2026-02-15 00:07:11.640092 | controller | skipping: Conditional result was False
2026-02-15 00:07:11.652383 | 
2026-02-15 00:07:11.652571 | TASK [Register the RHEL node]
2026-02-15 00:07:12.232464 | 
2026-02-15 00:07:12.232639 | TASK [Show the subscription-manager status]
2026-02-15 00:07:12.912012 | controller | skipping: Conditional result was False
2026-02-15 00:07:12.927476 | 
2026-02-15 00:07:12.927626 | TASK [Enable EPEL on RHEL]
2026-02-15 00:07:13.500589 | controller | skipping: Conditional result was False
2026-02-15 00:07:13.518046 | 
2026-02-15 00:07:13.518251 | TASK [Install git and tox]
2026-02-15 00:08:43.112723 | controller | changed
2026-02-15 00:08:43.124554 | 
2026-02-15 00:08:43.124726 | TASK [include_role : prepare-workspace]
2026-02-15 00:08:43.169066 | controller | ok
2026-02-15 00:08:43.204772 | 
2026-02-15 00:08:43.204917 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-15 00:08:43.424866 | controller | ok
2026-02-15 00:08:43.436111 | 
2026-02-15 00:08:43.436256 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-15 00:14:34.714626 | controller | Output suppressed because no_log was given
2026-02-15 00:14:34.732537 | 
2026-02-15 00:14:34.732714 | TASK [include_role : prepare-workspace-openshift]
2026-02-15 00:14:34.763762 | controller | skipping: Conditional result was False
2026-02-15 00:14:34.804070 | 
2026-02-15 00:14:34.804200 | PLAY [all:!appliance]
2026-02-15 00:14:34.831863 | 
2026-02-15 00:14:34.832034 | TASK [Run add-build-sshkey role (RSA)]
2026-02-15 00:14:34.857487 | controller | ok
2026-02-15 00:14:34.878297 | 
2026-02-15 00:14:34.878423 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-15 00:14:35.162393 | controller -> localhost | ok
2026-02-15 00:14:35.183366 | 
2026-02-15 00:14:35.183564 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-15 00:14:35.222210 | controller | ok
2026-02-15 00:14:35.244560 | controller | included: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-15 00:14:35.253933 | 
2026-02-15 00:14:35.254033 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-15 00:14:35.741531 | controller -> localhost | Generating public/private rsa key pair.
2026-02-15 00:14:35.742148 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/873289252c154a7194275cf1c2f19539_id_rsa.
2026-02-15 00:14:35.742214 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/873289252c154a7194275cf1c2f19539_id_rsa.pub.
2026-02-15 00:14:35.742260 | controller -> localhost | The key fingerprint is:
2026-02-15 00:14:35.742303 | controller -> localhost | SHA256:4ni44EesuYl193fRbk9M8BbRNJcmdWcLdEUsAq3Woas zuul-build-sshkey
2026-02-15 00:14:35.742349 | controller -> localhost | The key's randomart image is:
2026-02-15 00:14:35.742390 | controller -> localhost | +---[RSA 2048]----+
2026-02-15 00:14:35.742429 | controller -> localhost | |          .o.o.O%|
2026-02-15 00:14:35.742469 | controller -> localhost | |            +.++X|
2026-02-15 00:14:35.742507 | controller -> localhost | |           + o++ |
2026-02-15 00:14:35.742544 | controller -> localhost | |          + .  o.|
2026-02-15 00:14:35.742581 | controller -> localhost | |   .  . S. . .  +|
2026-02-15 00:14:35.742639 | controller -> localhost | |    o+ .  . . .+ |
2026-02-15 00:14:35.742719 | controller -> localhost | |  o++ +  .   o  o|
2026-02-15 00:14:35.742769 | controller -> localhost | | +o+.+ .E . . o. |
2026-02-15 00:14:35.742810 | controller -> localhost | |. +o.   .. . . ..|
2026-02-15 00:14:35.742855 | controller -> localhost | +----[SHA256]-----+
2026-02-15 00:14:35.742961 | controller -> localhost | ok: Runtime: 0:00:00.037286
2026-02-15 00:14:35.759609 | 
2026-02-15 00:14:35.759783 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-15 00:14:35.805143 | controller | ok
2026-02-15 00:14:35.827029 | controller | included: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-15 00:14:35.840896 | 
2026-02-15 00:14:35.840985 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-15 00:14:35.868361 | controller | skipping: Conditional result was False
2026-02-15 00:14:35.879468 | 
2026-02-15 00:14:35.879558 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-15 00:14:36.566021 | controller | changed
2026-02-15 00:14:36.584110 | 
2026-02-15 00:14:36.584309 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-15 00:14:36.815731 | controller | ok
2026-02-15 00:14:36.830267 | 
2026-02-15 00:14:36.830404 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-15 00:14:37.488347 | controller | changed
2026-02-15 00:14:37.496998 | 
2026-02-15 00:14:37.497087 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-15 00:14:38.157162 | controller | changed
2026-02-15 00:14:38.172049 | 
2026-02-15 00:14:38.172192 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-15 00:14:38.202752 | controller | skipping: Conditional result was False
2026-02-15 00:14:38.219440 | 
2026-02-15 00:14:38.219602 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-15 00:14:38.740116 | controller -> localhost | changed
2026-02-15 00:14:38.751812 | 
2026-02-15 00:14:38.751895 | TASK [add-build-sshkey : Add back temp key]
2026-02-15 00:14:39.116279 | controller -> localhost | Identity added: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/873289252c154a7194275cf1c2f19539_id_rsa (zuul-build-sshkey)
2026-02-15 00:14:39.116577 | controller -> localhost | ok: Runtime: 0:00:00.015725
2026-02-15 00:14:39.124566 | 
2026-02-15 00:14:39.124644 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-15 00:14:39.552120 | controller | ok
2026-02-15 00:14:39.562086 | 
2026-02-15 00:14:39.562235 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-15 00:14:39.609633 | controller | skipping: Conditional result was False
2026-02-15 00:14:39.629733 | 
2026-02-15 00:14:39.629920 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-15 00:14:39.666592 | controller | ok
2026-02-15 00:14:39.689731 | 
2026-02-15 00:14:39.689889 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-15 00:14:39.973039 | controller -> localhost | ok
2026-02-15 00:14:39.980608 | 
2026-02-15 00:14:39.980703 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-15 00:14:40.012831 | controller | ok
2026-02-15 00:14:40.024028 | controller | included: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-15 00:14:40.030902 | 
2026-02-15 00:14:40.030961 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-15 00:14:40.369462 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-15 00:14:40.370120 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/873289252c154a7194275cf1c2f19539_id_ecdsa.
2026-02-15 00:14:40.370206 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/873289252c154a7194275cf1c2f19539_id_ecdsa.pub.
2026-02-15 00:14:40.370274 | controller -> localhost | The key fingerprint is:
2026-02-15 00:14:40.370323 | controller -> localhost | SHA256:v734CElIpyNscEmbGhfgsPwXCvTHPEeEa+LpbWfv/Eo zuul-build-sshkey
2026-02-15 00:14:40.370366 | controller -> localhost | The key's randomart image is:
2026-02-15 00:14:40.370409 | controller -> localhost | +---[ECDSA 521]---+
2026-02-15 00:14:40.370449 | controller -> localhost | |....o oo         |
2026-02-15 00:14:40.370487 | controller -> localhost | |o+..o*.          |
2026-02-15 00:14:40.370526 | controller -> localhost | |.o+.**o..        |
2026-02-15 00:14:40.370564 | controller -> localhost | |  oOo+++         |
2026-02-15 00:14:40.370647 | controller -> localhost | |  ooB.+ S        |
2026-02-15 00:14:40.370743 | controller -> localhost | |   +.. o o       |
2026-02-15 00:14:40.370791 | controller -> localhost | |  . .   oE.      |
2026-02-15 00:14:40.370830 | controller -> localhost | |   . o oo. =     |
2026-02-15 00:14:40.370868 | controller -> localhost | |    . o o=*o+.   |
2026-02-15 00:14:40.370906 | controller -> localhost | +----[SHA256]-----+
2026-02-15 00:14:40.371007 | controller -> localhost | ok: Runtime: 0:00:00.022846
2026-02-15 00:14:40.388586 | 
2026-02-15 00:14:40.389114 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-15 00:14:40.435097 | controller | ok
2026-02-15 00:14:40.454537 | controller | included: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-15 00:14:40.477117 | 
2026-02-15 00:14:40.477338 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-15 00:14:40.507411 | controller | skipping: Conditional result was False
2026-02-15 00:14:40.520943 | 
2026-02-15 00:14:40.521048 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-15 00:14:40.809446 | controller | changed
2026-02-15 00:14:40.823221 | 
2026-02-15 00:14:40.823359 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-15 00:14:41.072653 | controller | ok
2026-02-15 00:14:41.088374 | 
2026-02-15 00:14:41.088522 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-15 00:14:41.826944 | controller | changed
2026-02-15 00:14:41.834834 | 
2026-02-15 00:14:41.834964 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-15 00:14:42.509656 | controller | changed
2026-02-15 00:14:42.527024 | 
2026-02-15 00:14:42.527247 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-15 00:14:42.558373 | controller | skipping: Conditional result was False
2026-02-15 00:14:42.569919 | 
2026-02-15 00:14:42.570076 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-15 00:14:42.842810 | controller -> localhost | changed
2026-02-15 00:14:42.856657 | 
2026-02-15 00:14:42.856782 | TASK [add-build-sshkey : Add back temp key]
2026-02-15 00:14:43.209222 | controller -> localhost | Identity added: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/873289252c154a7194275cf1c2f19539_id_ecdsa (zuul-build-sshkey)
2026-02-15 00:14:43.209553 | controller -> localhost | ok: Runtime: 0:00:00.015974
2026-02-15 00:14:43.218511 | 
2026-02-15 00:14:43.218586 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-15 00:14:43.447371 | controller | ok
2026-02-15 00:14:43.454068 | 
2026-02-15 00:14:43.454154 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-15 00:14:43.492640 | controller | skipping: Conditional result was False
2026-02-15 00:14:43.516356 | 
2026-02-15 00:14:43.516563 | TASK [include_role : remove-zuul-sshkey]
2026-02-15 00:14:43.544611 | controller | skipping: Conditional result was False
2026-02-15 00:14:43.555292 | 
2026-02-15 00:14:43.555402 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-15 00:14:43.805762 | controller | ok: "logs"
2026-02-15 00:14:43.810275 | controller | ok: All items complete
2026-02-15 00:14:43.810344 | 
2026-02-15 00:14:44.050421 | controller | ok: "artifacts"
2026-02-15 00:14:44.261984 | controller | ok: "docs"
2026-02-15 00:14:44.290420 | 
2026-02-15 00:14:44.290748 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-15 00:14:44.571955 | controller | changed: "logs"
2026-02-15 00:14:44.776810 | controller | changed: "artifacts"
2026-02-15 00:14:44.990523 | controller | changed: "docs"
2026-02-15 00:14:45.060954 | 
2026-02-15 00:14:45.061151 | PLAY RECAP
2026-02-15 00:14:45.061218 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-15 00:14:45.061254 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-15 00:14:45.061279 | 
2026-02-15 00:14:45.261080 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-15 00:14:45.262171 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-15 00:14:46.001617 | 
2026-02-15 00:14:46.001810 | PLAY [all]
2026-02-15 00:14:46.030269 | 
2026-02-15 00:14:46.030636 | TASK [Install binary dependencies]
2026-02-15 00:14:46.093495 | controller | ok
2026-02-15 00:14:46.131990 | 
2026-02-15 00:14:46.132186 | TASK [bindep : Include find tasks]
2026-02-15 00:14:46.165657 | controller | ok
2026-02-15 00:14:46.177336 | controller | included: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-15 00:14:46.186353 | 
2026-02-15 00:14:46.186448 | TASK [bindep : Look for bindep.txt]
2026-02-15 00:14:46.788755 | controller | ok
2026-02-15 00:14:46.798124 | 
2026-02-15 00:14:46.798261 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:14:46.827570 | controller | skipping: Conditional result was False
2026-02-15 00:14:46.838441 | 
2026-02-15 00:14:46.838595 | TASK [bindep : Look for other-requirements.txt]
2026-02-15 00:14:47.076691 | controller | ok
2026-02-15 00:14:47.084379 | 
2026-02-15 00:14:47.084470 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:14:47.111969 | controller | skipping: Conditional result was False
2026-02-15 00:14:47.122426 | 
2026-02-15 00:14:47.122614 | TASK [bindep : Look for bindep fallback file]
2026-02-15 00:14:47.159753 | controller | skipping: Conditional result was False
2026-02-15 00:14:47.171990 | 
2026-02-15 00:14:47.172214 | TASK [bindep : Define bindep_file fact]
2026-02-15 00:14:47.199548 | controller | skipping: Conditional result was False
2026-02-15 00:14:47.211345 | 
2026-02-15 00:14:47.211471 | TASK [bindep : Include bindep tasks]
2026-02-15 00:14:47.248460 | controller | skipping: Conditional result was False
2026-02-15 00:14:47.260637 | 
2026-02-15 00:14:47.260832 | TASK [bindep : Include install tasks]
2026-02-15 00:14:47.310381 | controller | skipping: Conditional result was False
2026-02-15 00:14:47.320817 | 
2026-02-15 00:14:47.320933 | LOOP [bindep : Include package tasks]
2026-02-15 00:14:47.409051 | 
2026-02-15 00:14:47.409306 | TASK [Run test-setup role]
2026-02-15 00:14:47.439058 | controller | ok
2026-02-15 00:14:47.470477 | 
2026-02-15 00:14:47.470720 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-15 00:14:47.707420 | controller | ok
2026-02-15 00:14:47.721352 | 
2026-02-15 00:14:47.721492 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-15 00:14:48.263467 | controller | skipping: Conditional result was False
2026-02-15 00:14:48.320288 | 
2026-02-15 00:14:48.320422 | PLAY RECAP
2026-02-15 00:14:48.320486 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-15 00:14:48.320515 | 
2026-02-15 00:14:48.471352 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-15 00:14:48.472328 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-15 00:14:49.090242 | 
2026-02-15 00:14:49.090429 | PLAY [controller]
2026-02-15 00:14:49.112966 | 
2026-02-15 00:14:49.113071 | TASK [Create the /root directory]
2026-02-15 00:14:49.769253 | controller | ok
2026-02-15 00:14:49.782745 | 
2026-02-15 00:14:49.782887 | TASK [Install glibc-langpack-en]
2026-02-15 00:14:54.200658 | controller | ok: Nothing to do
2026-02-15 00:14:54.221259 | 
2026-02-15 00:14:54.221520 | TASK [Ensure controller directory exists]
2026-02-15 00:14:54.432137 | controller | changed
2026-02-15 00:14:54.439100 | 
2026-02-15 00:14:54.439175 | TASK [Install container runtime]
2026-02-15 00:14:54.513995 | controller | ok
2026-02-15 00:14:54.562908 | 
2026-02-15 00:14:54.563102 | LOOP [ensure-podman : Find distribution installation]
2026-02-15 00:14:54.613930 | controller | ok: "/var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-15 00:14:54.630208 | controller | included: /var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-15 00:14:54.637882 | 
2026-02-15 00:14:54.638054 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-15 00:16:00.651323 | controller | changed
2026-02-15 00:16:00.660813 | 
2026-02-15 00:16:00.660909 | TASK [ensure-podman : Fetch podman version]
2026-02-15 00:16:01.228160 | controller | Client:       Podman Engine
2026-02-15 00:16:01.253448 | controller | Version:      4.6.2
2026-02-15 00:16:01.253504 | controller | API Version:  4.6.2
2026-02-15 00:16:01.253517 | controller | Go Version:   go1.19.12
2026-02-15 00:16:01.253542 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-15 00:16:01.253555 | controller | OS/Arch:      linux/amd64
2026-02-15 00:16:01.704534 | controller | ok: Runtime: 0:00:00.194940
2026-02-15 00:16:01.719425 | 
2026-02-15 00:16:01.719592 | TASK [ensure-podman : Print podman version installed]
2026-02-15 00:16:01.770981 | Podman version: Client:       Podman Engine
2026-02-15 00:16:01.771247 | Version:      4.6.2
2026-02-15 00:16:01.771287 | API Version:  4.6.2
2026-02-15 00:16:01.771440 | Go Version:   go1.19.12
2026-02-15 00:16:01.771474 | Built:        Mon Aug 28 19:38:31 2023
2026-02-15 00:16:01.771514 | OS/Arch:      linux/amd64
2026-02-15 00:16:01.780427 | 
2026-02-15 00:16:01.780520 | TASK [ensure-podman : Validate podman engine]
2026-02-15 00:16:02.321041 | controller | skipping: Conditional result was False
2026-02-15 00:16:02.336348 | 
2026-02-15 00:16:02.336502 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-15 00:16:02.364722 | controller | skipping: Conditional result was False
2026-02-15 00:16:02.388653 | 
2026-02-15 00:16:02.388787 | TASK [Ensure python3.8 is present]
2026-02-15 00:16:02.416932 | controller | skipping: Conditional result was False
2026-02-15 00:16:02.427860 | 
2026-02-15 00:16:02.427975 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-15 00:16:02.463700 | controller | ok
2026-02-15 00:16:02.493203 | 
2026-02-15 00:16:02.493345 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-15 00:16:03.960241 | controller | ok: Nothing to do
2026-02-15 00:16:03.970452 | 
2026-02-15 00:16:03.970641 | TASK [our-ensure-python : Also install python3-devel]
2026-02-15 00:16:13.338594 | controller | changed
2026-02-15 00:16:13.356573 | 
2026-02-15 00:16:13.356762 | TASK [Run ensure-virtualenv role]
2026-02-15 00:16:13.382448 | controller | ok
2026-02-15 00:16:13.406864 | 
2026-02-15 00:16:13.406993 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-15 00:16:13.660228 | controller | /usr/bin/virtualenv
2026-02-15 00:16:13.970224 | controller | ok: Runtime: 0:00:00.004536
2026-02-15 00:16:13.983754 | 
2026-02-15 00:16:13.983902 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-15 00:16:14.012702 | controller | skipping: Conditional result was False
2026-02-15 00:16:14.013107 | controller | ok: All items complete
2026-02-15 00:16:14.013147 | 
2026-02-15 00:16:14.041111 | 
2026-02-15 00:16:14.041304 | TASK [Find the full path of the Python interpreter]
2026-02-15 00:16:14.286341 | controller | /usr/bin/python3
2026-02-15 00:16:14.595335 | controller | ok
2026-02-15 00:16:14.611414 | 
2026-02-15 00:16:14.611709 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-15 00:16:15.428330 | controller | created virtual environment CPython3.11.0.final.0-64 in 482ms
2026-02-15 00:16:15.454292 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-15 00:16:15.454327 | 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-15 00:16:15.454339 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-15 00:16:15.454353 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-15 00:16:15.676212 | controller | changed
2026-02-15 00:16:15.689650 | 
2026-02-15 00:16:15.689872 | TASK [Set selinux package]
2026-02-15 00:16:15.738755 | controller | ok
2026-02-15 00:16:15.751001 | 
2026-02-15 00:16:15.751167 | TASK [Set selinux package (Fedora)]
2026-02-15 00:16:15.792158 | controller | ok
2026-02-15 00:16:15.798576 | 
2026-02-15 00:16:15.798705 | TASK [Install selinux into virtualenv]
2026-02-15 00:16:41.229336 | controller | Collecting selinux-please-lie-to-me
2026-02-15 00:16:53.478099 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-15 00:16:53.807886 | controller | Collecting setuptools<50.0.0
2026-02-15 00:16:53.815342 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-15 00:16:53.871046 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.1 MB/s eta 0:00:00
2026-02-15 00:16:53.962429 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-15 00:16:53.964509 | controller |   Attempting uninstall: setuptools
2026-02-15 00:16:53.964547 | controller |     Found existing installation: setuptools 62.6.0
2026-02-15 00:16:54.041550 | controller |     Uninstalling setuptools-62.6.0:
2026-02-15 00:16:54.056489 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-15 00:16:54.430261 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-15 00:17:05.876648 | controller |
2026-02-15 00:17:05.962302 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-15 00:17:05.962337 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-15 00:17:06.397839 | controller | ok: Runtime: 0:00:49.963185
2026-02-15 00:17:06.413055 | 
2026-02-15 00:17:06.413271 | TASK [Install pytest-forked into virtualenv]
2026-02-15 00:17:18.108466 | controller | Collecting pytest-forked
2026-02-15 00:17:28.295938 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-15 00:17:28.338973 | controller | Collecting py
2026-02-15 00:17:28.343339 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-15 00:17:28.367941 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.3 MB/s eta 0:00:00
2026-02-15 00:17:28.486805 | controller | Collecting pytest>=3.10
2026-02-15 00:17:28.494651 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-15 00:17:28.514577 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 23.4 MB/s eta 0:00:00
2026-02-15 00:17:28.555023 | controller | Collecting iniconfig>=1.0.1
2026-02-15 00:17:28.558242 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-15 00:17:28.601063 | controller | Collecting packaging>=22
2026-02-15 00:17:28.605783 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-15 00:17:28.615046 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 10.8 MB/s eta 0:00:00
2026-02-15 00:17:28.648252 | controller | Collecting pluggy<2,>=1.5
2026-02-15 00:17:28.651952 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-15 00:17:28.699020 | controller | Collecting pygments>=2.7.2
2026-02-15 00:17:28.705733 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-15 00:17:28.748742 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 31.8 MB/s eta 0:00:00
2026-02-15 00:17:28.822544 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-15 00:17:30.034814 | 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-15 00:17:30.045563 | controller |
2026-02-15 00:17:30.155371 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-15 00:17:30.155422 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-15 00:17:30.488908 | controller | ok: Runtime: 0:00:23.475229
2026-02-15 00:17:30.500918 | 
2026-02-15 00:17:30.501037 | TASK [Update pip]
2026-02-15 00:17:31.076412 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-15 00:17:43.494703 | controller | Collecting pip
2026-02-15 00:17:55.810080 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-15 00:17:55.905419 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 19.9 MB/s eta 0:00:00
2026-02-15 00:17:55.967905 | controller | Installing collected packages: pip
2026-02-15 00:17:55.968064 | controller |   Attempting uninstall: pip
2026-02-15 00:17:55.970233 | controller |     Found existing installation: pip 22.2.2
2026-02-15 00:17:56.128559 | controller |     Uninstalling pip-22.2.2:
2026-02-15 00:17:56.143418 | controller |       Successfully uninstalled pip-22.2.2
2026-02-15 00:17:56.982159 | controller | Successfully installed pip-26.0.1
2026-02-15 00:17:57.099593 | controller | ok: Runtime: 0:00:26.308516
2026-02-15 00:17:57.107215 | 
2026-02-15 00:17:57.107323 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-15 00:17:57.332476 | controller | changed
2026-02-15 00:17:57.344863 | 
2026-02-15 00:17:57.345032 | TASK [Install ansible into virtualenv]
2026-02-15 00:17:57.929639 | controller | Processing ./src/github.com/ansible/ansible
2026-02-15 00:17:57.932414 | controller |   Installing build dependencies: started
2026-02-15 00:18:20.720652 | controller |   Installing build dependencies: finished with status 'done'
2026-02-15 00:18:20.723166 | controller |   Getting requirements to build wheel: started
2026-02-15 00:18:21.455218 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-15 00:18:21.456765 | controller |   Preparing metadata (pyproject.toml): started
2026-02-15 00:18:21.923364 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-15 00:18:21.929499 | 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-15 00:18:21.935658 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-15 00:18:22.438010 | controller | ERROR
2026-02-15 00:18:22.438385 | controller | {
2026-02-15 00:18:22.438470 | controller |   "delta": "0:00:24.371211",
2026-02-15 00:18:22.438530 | controller |   "end": "2026-02-15 00:18:22.004131",
2026-02-15 00:18:22.438569 | controller |   "msg": "non-zero return code",
2026-02-15 00:18:22.438633 | controller |   "rc": 1,
2026-02-15 00:18:22.438719 | controller |   "start": "2026-02-15 00:17:57.632920"
2026-02-15 00:18:22.438771 | controller | }
failure
2026-02-15 00:18:22.442897 | 
2026-02-15 00:18:22.443017 | PLAY RECAP
2026-02-15 00:18:22.443121 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-15 00:18:22.443175 | 
2026-02-15 00:18:22.607103 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-15 00:18:22.608624 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-15 00:18:23.224220 | 
2026-02-15 00:18:23.224345 | PLAY [all]
2026-02-15 00:18:23.245921 | 
2026-02-15 00:18:23.246059 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-15 00:18:23.686820 | controller | changed: non-zero return code
2026-02-15 00:18:23.694278 | 
2026-02-15 00:18:23.694428 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-15 00:18:23.710027 | controller | skipping: Conditional result was False
2026-02-15 00:18:23.718781 | 
2026-02-15 00:18:23.718951 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-15 00:18:23.743931 | 
2026-02-15 00:18:23.744122 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-15 00:18:23.765858 | 
2026-02-15 00:18:23.766046 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-15 00:18:23.779906 | controller | skipping: Conditional result was False
2026-02-15 00:18:23.789611 | 
2026-02-15 00:18:23.789795 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-15 00:18:23.820417 | 
2026-02-15 00:18:23.820588 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-15 00:18:23.835768 | controller | skipping: Conditional result was False
2026-02-15 00:18:23.842834 | 
2026-02-15 00:18:23.842982 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-15 00:18:23.857435 | controller | skipping: Conditional result was False
2026-02-15 00:18:23.865540 | 
2026-02-15 00:18:23.865658 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-15 00:18:23.879534 | controller | skipping: Conditional result was False
2026-02-15 00:18:23.908867 | 
2026-02-15 00:18:23.908989 | PLAY RECAP
2026-02-15 00:18:23.909028 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-15 00:18:23.909047 | 
2026-02-15 00:18:24.034489 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-15 00:18:24.035424 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-15 00:18:24.614152 | 
2026-02-15 00:18:24.614365 | PLAY [all:!appliance*]
2026-02-15 00:18:24.637914 | 
2026-02-15 00:18:24.638036 | TASK [unregister the node]
2026-02-15 00:18:25.171086 | controller | skipping: Conditional result was False
2026-02-15 00:18:25.184468 | 
2026-02-15 00:18:25.184656 | TASK [include_role : fetch-output]
2026-02-15 00:18:25.246335 | controller | ok
2026-02-15 00:18:25.293473 | 
2026-02-15 00:18:25.293645 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-15 00:18:25.370834 | controller | skipping: Conditional result was False
2026-02-15 00:18:25.380412 | 
2026-02-15 00:18:25.380574 | TASK [fetch-output : Set log path for single node]
2026-02-15 00:18:25.425525 | controller | ok
2026-02-15 00:18:25.433106 | 
2026-02-15 00:18:25.433202 | LOOP [fetch-output : Ensure local output dirs]
2026-02-15 00:18:25.887778 | controller -> localhost | ok: "/var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/logs"
2026-02-15 00:18:26.151146 | controller -> localhost | changed: "/var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/artifacts"
2026-02-15 00:18:26.400816 | controller -> localhost | changed: "/var/lib/zuul/builds/873289252c154a7194275cf1c2f19539/work/docs"
2026-02-15 00:18:26.426534 | 
2026-02-15 00:18:26.426725 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-15 00:18:27.119858 | controller | changed:
2026-02-15 00:18:27.120140 | controller | .d..t...... ./
2026-02-15 00:18:27.120182 | controller | cd+++++++++ controller/
2026-02-15 00:18:27.120228 | controller | changed: All items complete
2026-02-15 00:18:27.120254 | 
2026-02-15 00:18:27.614857 | controller | changed: .d..t...... ./
2026-02-15 00:18:28.152780 | controller | changed: .d..t...... ./
2026-02-15 00:18:28.176908 | 
2026-02-15 00:18:28.177226 | TASK [include_role : fetch-output-openshift]
2026-02-15 00:18:28.207057 | controller | skipping: Conditional result was False
2026-02-15 00:18:28.224740 | 
2026-02-15 00:18:28.225558 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-15 00:18:28.265092 | controller | skipping: Conditional result was False
2026-02-15 00:18:28.281531 | controller | skipping: Conditional result was False
2026-02-15 00:18:28.335944 | 
2026-02-15 00:18:28.336143 | PLAY [localhost]
2026-02-15 00:18:28.359238 | 
2026-02-15 00:18:28.359391 | TASK [Run Zuul manifest role]
2026-02-15 00:18:28.382649 | localhost | ok
2026-02-15 00:18:28.401355 | 
2026-02-15 00:18:28.401476 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-15 00:18:28.798658 | localhost | changed
2026-02-15 00:18:28.808440 | 
2026-02-15 00:18:28.808648 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-15 00:18:28.859942 | localhost | ok
2026-02-15 00:18:28.869273 | 
2026-02-15 00:18:28.869493 | TASK [Set zuul-log-path fact]
2026-02-15 00:18:28.890699 | localhost | ok
2026-02-15 00:18:28.913710 | 
2026-02-15 00:18:28.914039 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-15 00:18:28.946263 | localhost | ok
2026-02-15 00:18:28.956061 | 
2026-02-15 00:18:28.956205 | LOOP [Run upload-logs-swift role]
2026-02-15 00:18:28.992184 | localhost | Output suppressed because no_log was given
2026-02-15 00:18:29.024998 | 
2026-02-15 00:18:29.025143 | TASK [Set zuul-log-path fact]
2026-02-15 00:18:29.061096 | localhost | skipping: Conditional result was False
2026-02-15 00:18:29.067604 | 
2026-02-15 00:18:29.067781 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-15 00:18:29.611370 | localhost -> localhost | ok: Runtime: 0:00:00.011276
2026-02-15 00:18:29.650288 | 
2026-02-15 00:18:29.650436 | TASK [upload-logs-swift : Upload logs to swift]