2025-12-26 00:14:34.234991 | Job console starting...
2025-12-26 00:14:34.256462 | Updating repositories
2025-12-26 00:14:34.795037 | Preparing job workspace
2025-12-26 00:14:38.866672 | Running Ansible setup...
2025-12-26 00:14:43.614350 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-26 00:14:44.232878 | 
2025-12-26 00:14:44.233040 | PLAY [localhost]
2025-12-26 00:14:44.242350 | 
2025-12-26 00:14:44.242424 | TASK [Gathering Facts]
2025-12-26 00:14:45.270472 | localhost | ok
2025-12-26 00:14:45.301804 | 
2025-12-26 00:14:45.302055 | TASK [Setup log path fact]
2025-12-26 00:14:45.325428 | localhost | ok
2025-12-26 00:14:45.349306 | 
2025-12-26 00:14:45.349578 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-26 00:14:45.383380 | localhost | ok
2025-12-26 00:14:45.395334 | 
2025-12-26 00:14:45.395446 | TASK [emit-job-header : Print job information]
2025-12-26 00:14:45.428372 | # Job Information
2025-12-26 00:14:45.428614 | Ansible Version: 2.15.12
2025-12-26 00:14:45.428672 | Job: ansible-test-sanity-docker-devel
2025-12-26 00:14:45.428706 | Pipeline: periodic
2025-12-26 00:14:45.428762 | Executor: ze03.softwarefactory-project.io
2025-12-26 00:14:45.428792 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-26 00:14:45.428822 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/2b1/ansible/2b1908ecace04d3e967bbf7157ea537f/
2025-12-26 00:14:45.428849 | Event ID: 251d181dbd134356bcf2e7a38c8ef353
2025-12-26 00:14:45.434643 | 
2025-12-26 00:14:45.434767 | LOOP [emit-job-header : Print node information]
2025-12-26 00:14:45.559134 | localhost | ok:
2025-12-26 00:14:45.559455 | localhost | # Node Information
2025-12-26 00:14:45.559495 | localhost | Inventory Hostname: controller
2025-12-26 00:14:45.559537 | localhost | Hostname: np0005570835
2025-12-26 00:14:45.559776 | localhost | Username: zuul
2025-12-26 00:14:45.559845 | localhost | Distro: Fedora 37
2025-12-26 00:14:45.559877 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-26 00:14:45.559903 | localhost | Region: ca-ymq-1
2025-12-26 00:14:45.559927 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-26 00:14:45.559951 | localhost | Product Name: OpenStack Nova
2025-12-26 00:14:45.559976 | localhost | Interface IP: 162.253.55.227
2025-12-26 00:14:45.579218 | 
2025-12-26 00:14:45.579451 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-26 00:14:46.066500 | localhost -> localhost | changed
2025-12-26 00:14:46.072642 | 
2025-12-26 00:14:46.072751 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-26 00:14:47.027532 | localhost -> localhost | changed
2025-12-26 00:14:47.060398 | 
2025-12-26 00:14:47.060562 | PLAY [all:!appliance*]
2025-12-26 00:14:47.087939 | 
2025-12-26 00:14:47.088176 | TASK [include_role : start-zuul-console]
2025-12-26 00:14:47.109954 | controller | ok
2025-12-26 00:14:47.125463 | 
2025-12-26 00:14:47.125567 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-26 00:14:47.514195 | controller | ok
2025-12-26 00:14:47.525899 | 
2025-12-26 00:14:47.525994 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-26 00:14:48.443018 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-26 00:14:48.453321 | 
2025-12-26 00:14:48.453451 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-26 00:14:49.001136 | controller | skipping: Conditional result was False
2025-12-26 00:14:49.016265 | 
2025-12-26 00:14:49.016500 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-26 00:14:49.044693 | controller | skipping: Conditional result was False
2025-12-26 00:14:49.060435 | 
2025-12-26 00:14:49.060639 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-26 00:14:49.087290 | controller | skipping: Conditional result was False
2025-12-26 00:14:49.104219 | 
2025-12-26 00:14:49.104425 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-26 00:14:49.142689 | controller | skipping: Conditional result was False
2025-12-26 00:14:49.160356 | 
2025-12-26 00:14:49.160613 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-26 00:14:49.188382 | controller | skipping: Conditional result was False
2025-12-26 00:14:49.204889 | 
2025-12-26 00:14:49.205150 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-26 00:14:49.232280 | controller | skipping: Conditional result was False
2025-12-26 00:14:49.251868 | 
2025-12-26 00:14:49.252040 | TASK [Disable Fedora Modular]
2025-12-26 00:14:49.520320 | controller | changed
2025-12-26 00:14:49.529492 | 
2025-12-26 00:14:49.529618 | TASK [Enable EPEL]
2025-12-26 00:14:49.566872 | controller | skipping: Conditional result was False
2025-12-26 00:14:49.577857 | 
2025-12-26 00:14:49.578004 | TASK [Register the RHEL node]
2025-12-26 00:14:50.138391 | 
2025-12-26 00:14:50.138697 | TASK [Show the subscription-manager status]
2025-12-26 00:14:50.738940 | controller | skipping: Conditional result was False
2025-12-26 00:14:50.754798 | 
2025-12-26 00:14:50.754959 | TASK [Enable EPEL on RHEL]
2025-12-26 00:14:51.312825 | controller | skipping: Conditional result was False
2025-12-26 00:14:51.326900 | 
2025-12-26 00:14:51.327097 | TASK [Install git and tox]
2025-12-26 00:16:13.130348 | controller | changed
2025-12-26 00:16:13.145352 | 
2025-12-26 00:16:13.145537 | TASK [include_role : prepare-workspace]
2025-12-26 00:16:13.181967 | controller | ok
2025-12-26 00:16:13.214370 | 
2025-12-26 00:16:13.214541 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-26 00:16:13.462627 | controller | ok
2025-12-26 00:16:13.471210 | 
2025-12-26 00:16:13.471348 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-26 00:16:26.292115 | controller | Output suppressed because no_log was given
2025-12-26 00:16:26.303954 | 
2025-12-26 00:16:26.304094 | TASK [include_role : prepare-workspace-openshift]
2025-12-26 00:16:26.330324 | controller | skipping: Conditional result was False
2025-12-26 00:16:26.422565 | 
2025-12-26 00:16:26.422694 | PLAY [all:!appliance]
2025-12-26 00:16:26.439380 | 
2025-12-26 00:16:26.439487 | TASK [Run add-build-sshkey role (RSA)]
2025-12-26 00:16:26.473345 | controller | ok
2025-12-26 00:16:26.492681 | 
2025-12-26 00:16:26.492917 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-26 00:16:26.779338 | controller -> localhost | ok
2025-12-26 00:16:26.787649 | 
2025-12-26 00:16:26.787842 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-26 00:16:26.821078 | controller | ok
2025-12-26 00:16:26.839517 | controller | included: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-26 00:16:26.846835 | 
2025-12-26 00:16:26.846934 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-26 00:16:27.274095 | controller -> localhost | Generating public/private rsa key pair.
2025-12-26 00:16:27.274317 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/2b1908ecace04d3e967bbf7157ea537f_id_rsa.
2025-12-26 00:16:27.274348 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/2b1908ecace04d3e967bbf7157ea537f_id_rsa.pub.
2025-12-26 00:16:27.274388 | controller -> localhost | The key fingerprint is:
2025-12-26 00:16:27.274409 | controller -> localhost | SHA256:9F7HHEL7P9YknQjKOlBRe+Xum2IvRZ/tg1s+zGkjY6U zuul-build-sshkey
2025-12-26 00:16:27.274428 | controller -> localhost | The key's randomart image is:
2025-12-26 00:16:27.274450 | controller -> localhost | +---[RSA 2048]----+
2025-12-26 00:16:27.274470 | controller -> localhost | |       ...  ..   |
2025-12-26 00:16:27.274489 | controller -> localhost | |        . ..o.   |
2025-12-26 00:16:27.274506 | controller -> localhost | |       ... oo..  |
2025-12-26 00:16:27.274523 | controller -> localhost | |      ....o o*.o.|
2025-12-26 00:16:27.274539 | controller -> localhost | |     .  So. ooB.=|
2025-12-26 00:16:27.274568 | controller -> localhost | |      . .. ..o Bo|
2025-12-26 00:16:27.274595 | controller -> localhost | |       o  . ..*=+|
2025-12-26 00:16:27.274615 | controller -> localhost | |        .  + E*Oo|
2025-12-26 00:16:27.274635 | controller -> localhost | |          . ===.+|
2025-12-26 00:16:27.274656 | controller -> localhost | +----[SHA256]-----+
2025-12-26 00:16:27.274704 | controller -> localhost | ok: Runtime: 0:00:00.049996
2025-12-26 00:16:27.286016 | 
2025-12-26 00:16:27.286177 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-26 00:16:27.317748 | controller | ok
2025-12-26 00:16:27.329310 | controller | included: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-26 00:16:27.339899 | 
2025-12-26 00:16:27.339991 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-26 00:16:27.364241 | controller | skipping: Conditional result was False
2025-12-26 00:16:27.373003 | 
2025-12-26 00:16:27.373115 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-26 00:16:27.877774 | controller | changed
2025-12-26 00:16:27.887915 | 
2025-12-26 00:16:27.888077 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-26 00:16:28.127642 | controller | ok
2025-12-26 00:16:28.142633 | 
2025-12-26 00:16:28.142885 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-26 00:16:28.801455 | controller | changed
2025-12-26 00:16:28.808187 | 
2025-12-26 00:16:28.808368 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-26 00:16:29.461143 | controller | changed
2025-12-26 00:16:29.471383 | 
2025-12-26 00:16:29.471567 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-26 00:16:29.499676 | controller | skipping: Conditional result was False
2025-12-26 00:16:29.513477 | 
2025-12-26 00:16:29.513626 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-26 00:16:30.030151 | controller -> localhost | changed
2025-12-26 00:16:30.043566 | 
2025-12-26 00:16:30.043686 | TASK [add-build-sshkey : Add back temp key]
2025-12-26 00:16:30.354830 | controller -> localhost | Identity added: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/2b1908ecace04d3e967bbf7157ea537f_id_rsa (zuul-build-sshkey)
2025-12-26 00:16:30.355087 | controller -> localhost | ok: Runtime: 0:00:00.015887
2025-12-26 00:16:30.362103 | 
2025-12-26 00:16:30.362169 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-26 00:16:30.765547 | controller | ok
2025-12-26 00:16:30.775238 | 
2025-12-26 00:16:30.775438 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-26 00:16:30.812123 | controller | skipping: Conditional result was False
2025-12-26 00:16:30.830828 | 
2025-12-26 00:16:30.831019 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-26 00:16:30.869138 | controller | ok
2025-12-26 00:16:30.907005 | 
2025-12-26 00:16:30.907199 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-26 00:16:31.181435 | controller -> localhost | ok
2025-12-26 00:16:31.191351 | 
2025-12-26 00:16:31.191517 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-26 00:16:31.227668 | controller | ok
2025-12-26 00:16:31.244569 | controller | included: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-26 00:16:31.254589 | 
2025-12-26 00:16:31.254782 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-26 00:16:31.627289 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-26 00:16:31.627573 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/2b1908ecace04d3e967bbf7157ea537f_id_ecdsa.
2025-12-26 00:16:31.627607 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/2b1908ecace04d3e967bbf7157ea537f_id_ecdsa.pub.
2025-12-26 00:16:31.627646 | controller -> localhost | The key fingerprint is:
2025-12-26 00:16:31.627669 | controller -> localhost | SHA256:2038RUN4XqK8bQPiE/cUp/Bn/qZ4WnZ+I16N0HKsf5I zuul-build-sshkey
2025-12-26 00:16:31.627693 | controller -> localhost | The key's randomart image is:
2025-12-26 00:16:31.627716 | controller -> localhost | +---[ECDSA 521]---+
2025-12-26 00:16:31.627778 | controller -> localhost | |              .. |
2025-12-26 00:16:31.627804 | controller -> localhost | |            ..+.o|
2025-12-26 00:16:31.627827 | controller -> localhost | |           . +o*o|
2025-12-26 00:16:31.627849 | controller -> localhost | |          o.=o+o+|
2025-12-26 00:16:31.627870 | controller -> localhost | |        S. +=*++.|
2025-12-26 00:16:31.627892 | controller -> localhost | |         ooo.*=oo|
2025-12-26 00:16:31.627913 | controller -> localhost | |        . ..o.=++|
2025-12-26 00:16:31.627934 | controller -> localhost | |             *E+=|
2025-12-26 00:16:31.627957 | controller -> localhost | |            +++=+|
2025-12-26 00:16:31.627978 | controller -> localhost | +----[SHA256]-----+
2025-12-26 00:16:31.628038 | controller -> localhost | ok: Runtime: 0:00:00.014178
2025-12-26 00:16:31.637951 | 
2025-12-26 00:16:31.638151 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-26 00:16:31.670218 | controller | ok
2025-12-26 00:16:31.680022 | controller | included: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-26 00:16:31.690522 | 
2025-12-26 00:16:31.690643 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-26 00:16:31.716348 | controller | skipping: Conditional result was False
2025-12-26 00:16:31.725340 | 
2025-12-26 00:16:31.725514 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-26 00:16:32.005536 | controller | changed
2025-12-26 00:16:32.014174 | 
2025-12-26 00:16:32.014264 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-26 00:16:32.252836 | controller | ok
2025-12-26 00:16:32.261357 | 
2025-12-26 00:16:32.261632 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-26 00:16:32.915546 | controller | changed
2025-12-26 00:16:32.928047 | 
2025-12-26 00:16:32.928212 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-26 00:16:33.558869 | controller | changed
2025-12-26 00:16:33.569349 | 
2025-12-26 00:16:33.569516 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-26 00:16:33.597069 | controller | skipping: Conditional result was False
2025-12-26 00:16:33.610196 | 
2025-12-26 00:16:33.610379 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-26 00:16:33.852172 | controller -> localhost | changed
2025-12-26 00:16:33.913859 | 
2025-12-26 00:16:33.914036 | TASK [add-build-sshkey : Add back temp key]
2025-12-26 00:16:34.217075 | controller -> localhost | Identity added: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/2b1908ecace04d3e967bbf7157ea537f_id_ecdsa (zuul-build-sshkey)
2025-12-26 00:16:34.217451 | controller -> localhost | ok: Runtime: 0:00:00.011764
2025-12-26 00:16:34.228719 | 
2025-12-26 00:16:34.228879 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-26 00:16:34.437509 | controller | ok
2025-12-26 00:16:34.445437 | 
2025-12-26 00:16:34.445665 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-26 00:16:34.471954 | controller | skipping: Conditional result was False
2025-12-26 00:16:34.489338 | 
2025-12-26 00:16:34.489502 | TASK [include_role : remove-zuul-sshkey]
2025-12-26 00:16:34.516590 | controller | skipping: Conditional result was False
2025-12-26 00:16:34.528586 | 
2025-12-26 00:16:34.528792 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-26 00:16:34.775719 | controller | ok: "logs"
2025-12-26 00:16:34.776045 | controller | ok: All items complete
2025-12-26 00:16:34.776073 | 
2025-12-26 00:16:34.962760 | controller | ok: "artifacts"
2025-12-26 00:16:35.164321 | controller | ok: "docs"
2025-12-26 00:16:35.194588 | 
2025-12-26 00:16:35.195032 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-26 00:16:35.434574 | controller | changed: "logs"
2025-12-26 00:16:35.626029 | controller | changed: "artifacts"
2025-12-26 00:16:35.821881 | controller | changed: "docs"
2025-12-26 00:16:35.880244 | 
2025-12-26 00:16:35.880407 | PLAY RECAP
2025-12-26 00:16:35.880470 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-26 00:16:35.880507 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-26 00:16:35.880532 | 
2025-12-26 00:16:36.039616 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-26 00:16:36.040661 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-26 00:16:36.703129 | 
2025-12-26 00:16:36.703250 | PLAY [all]
2025-12-26 00:16:36.725521 | 
2025-12-26 00:16:36.725659 | TASK [Install binary dependencies]
2025-12-26 00:16:36.798423 | controller | ok
2025-12-26 00:16:36.820092 | 
2025-12-26 00:16:36.820284 | TASK [bindep : Include find tasks]
2025-12-26 00:16:36.854492 | controller | ok
2025-12-26 00:16:36.864037 | controller | included: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-26 00:16:36.871244 | 
2025-12-26 00:16:36.871334 | TASK [bindep : Look for bindep.txt]
2025-12-26 00:16:37.260945 | controller | ok
2025-12-26 00:16:37.269275 | 
2025-12-26 00:16:37.269376 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:16:37.286136 | controller | skipping: Conditional result was False
2025-12-26 00:16:37.315842 | 
2025-12-26 00:16:37.316048 | TASK [bindep : Look for other-requirements.txt]
2025-12-26 00:16:37.555433 | controller | ok
2025-12-26 00:16:37.564074 | 
2025-12-26 00:16:37.564342 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:16:37.591410 | controller | skipping: Conditional result was False
2025-12-26 00:16:37.599279 | 
2025-12-26 00:16:37.599373 | TASK [bindep : Look for bindep fallback file]
2025-12-26 00:16:37.624839 | controller | skipping: Conditional result was False
2025-12-26 00:16:37.634078 | 
2025-12-26 00:16:37.634204 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:16:37.659382 | controller | skipping: Conditional result was False
2025-12-26 00:16:37.669950 | 
2025-12-26 00:16:37.670387 | TASK [bindep : Include bindep tasks]
2025-12-26 00:16:37.698193 | controller | skipping: Conditional result was False
2025-12-26 00:16:37.707665 | 
2025-12-26 00:16:37.707908 | TASK [bindep : Include install tasks]
2025-12-26 00:16:37.735136 | controller | skipping: Conditional result was False
2025-12-26 00:16:37.745496 | 
2025-12-26 00:16:37.745713 | LOOP [bindep : Include package tasks]
2025-12-26 00:16:37.811432 | 
2025-12-26 00:16:37.811754 | TASK [Run test-setup role]
2025-12-26 00:16:37.839258 | controller | ok
2025-12-26 00:16:37.859973 | 
2025-12-26 00:16:37.860161 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-26 00:16:38.086003 | controller | ok
2025-12-26 00:16:38.099770 | 
2025-12-26 00:16:38.099907 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-26 00:16:38.648235 | controller | skipping: Conditional result was False
2025-12-26 00:16:38.685310 | 
2025-12-26 00:16:38.685466 | PLAY RECAP
2025-12-26 00:16:38.685523 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-26 00:16:38.685552 | 
2025-12-26 00:16:38.876515 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-26 00:16:38.877535 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-26 00:16:39.594534 | 
2025-12-26 00:16:39.594762 | PLAY [controller]
2025-12-26 00:16:39.616420 | 
2025-12-26 00:16:39.616592 | TASK [Create the /root directory]
2025-12-26 00:16:40.016782 | controller | ok
2025-12-26 00:16:40.022982 | 
2025-12-26 00:16:40.023062 | TASK [Install glibc-langpack-en]
2025-12-26 00:16:44.001288 | controller | ok: Nothing to do
2025-12-26 00:16:44.009540 | 
2025-12-26 00:16:44.009692 | TASK [Ensure controller directory exists]
2025-12-26 00:16:44.235180 | controller | changed
2025-12-26 00:16:44.248338 | 
2025-12-26 00:16:44.248496 | TASK [Install container runtime]
2025-12-26 00:16:44.326094 | controller | ok
2025-12-26 00:16:44.369388 | 
2025-12-26 00:16:44.369569 | LOOP [ensure-podman : Find distribution installation]
2025-12-26 00:16:44.403928 | controller | ok: "/var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-26 00:16:44.414761 | controller | included: /var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-26 00:16:44.422570 | 
2025-12-26 00:16:44.422659 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-26 00:17:49.923632 | controller | changed
2025-12-26 00:17:49.930246 | 
2025-12-26 00:17:49.930319 | TASK [ensure-podman : Fetch podman version]
2025-12-26 00:17:50.455875 | controller | Client:       Podman Engine
2025-12-26 00:17:50.485235 | controller | Version:      4.6.2
2025-12-26 00:17:50.485262 | controller | API Version:  4.6.2
2025-12-26 00:17:50.485272 | controller | Go Version:   go1.19.12
2025-12-26 00:17:50.485290 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-26 00:17:50.485298 | controller | OS/Arch:      linux/amd64
2025-12-26 00:17:50.964928 | controller | ok: Runtime: 0:00:00.197446
2025-12-26 00:17:50.987721 | 
2025-12-26 00:17:50.989812 | TASK [ensure-podman : Print podman version installed]
2025-12-26 00:17:51.045340 | Podman version: Client:       Podman Engine
2025-12-26 00:17:51.048635 | Version:      4.6.2
2025-12-26 00:17:51.048753 | API Version:  4.6.2
2025-12-26 00:17:51.048810 | Go Version:   go1.19.12
2025-12-26 00:17:51.048852 | Built:        Mon Aug 28 19:38:31 2023
2025-12-26 00:17:51.048897 | OS/Arch:      linux/amd64
2025-12-26 00:17:51.060812 | 
2025-12-26 00:17:51.060981 | TASK [ensure-podman : Validate podman engine]
2025-12-26 00:17:51.610648 | controller | skipping: Conditional result was False
2025-12-26 00:17:51.621236 | 
2025-12-26 00:17:51.621422 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-26 00:17:51.638653 | controller | skipping: Conditional result was False
2025-12-26 00:17:51.655617 | 
2025-12-26 00:17:51.655720 | TASK [Ensure python3.8 is present]
2025-12-26 00:17:51.671363 | controller | skipping: Conditional result was False
2025-12-26 00:17:51.680824 | 
2025-12-26 00:17:51.680925 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-26 00:17:51.704117 | controller | ok
2025-12-26 00:17:51.731469 | 
2025-12-26 00:17:51.731582 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-26 00:17:53.043477 | controller | ok: Nothing to do
2025-12-26 00:17:53.060074 | 
2025-12-26 00:17:53.060344 | TASK [our-ensure-python : Also install python3-devel]
2025-12-26 00:18:02.241158 | controller | changed
2025-12-26 00:18:02.258518 | 
2025-12-26 00:18:02.258689 | TASK [Run ensure-virtualenv role]
2025-12-26 00:18:02.288807 | controller | ok
2025-12-26 00:18:02.319877 | 
2025-12-26 00:18:02.320035 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-26 00:18:02.543468 | controller | /usr/bin/virtualenv
2025-12-26 00:18:02.853538 | controller | ok: Runtime: 0:00:00.004402
2025-12-26 00:18:02.861899 | 
2025-12-26 00:18:02.862000 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-26 00:18:02.883272 | controller | skipping: Conditional result was False
2025-12-26 00:18:02.883617 | controller | ok: All items complete
2025-12-26 00:18:02.883657 | 
2025-12-26 00:18:02.903245 | 
2025-12-26 00:18:02.903427 | TASK [Find the full path of the Python interpreter]
2025-12-26 00:18:03.165619 | controller | /usr/bin/python3
2025-12-26 00:18:03.486459 | controller | ok
2025-12-26 00:18:03.492486 | 
2025-12-26 00:18:03.492557 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-26 00:18:04.274825 | controller | created virtual environment CPython3.11.0.final.0-64 in 476ms
2025-12-26 00:18:04.296082 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-26 00:18:04.296140 | 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-26 00:18:04.296152 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-26 00:18:04.296181 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-26 00:18:04.549470 | controller | changed
2025-12-26 00:18:04.558552 | 
2025-12-26 00:18:04.558649 | TASK [Set selinux package]
2025-12-26 00:18:04.598108 | controller | ok
2025-12-26 00:18:04.608602 | 
2025-12-26 00:18:04.608842 | TASK [Set selinux package (Fedora)]
2025-12-26 00:18:04.653616 | controller | ok
2025-12-26 00:18:04.661311 | 
2025-12-26 00:18:04.661412 | TASK [Install selinux into virtualenv]
2025-12-26 00:18:18.226414 | controller | Collecting selinux-please-lie-to-me
2025-12-26 00:18:30.563136 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-26 00:18:30.880107 | controller | Collecting setuptools<50.0.0
2025-12-26 00:18:30.884523 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-26 00:18:30.929181 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 19.4 MB/s eta 0:00:00
2025-12-26 00:18:31.017508 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-26 00:18:31.017724 | controller |   Attempting uninstall: setuptools
2025-12-26 00:18:31.020264 | controller |     Found existing installation: setuptools 62.6.0
2025-12-26 00:18:31.096772 | controller |     Uninstalling setuptools-62.6.0:
2025-12-26 00:18:31.107408 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-26 00:18:31.473534 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-26 00:18:42.921932 | controller |
2025-12-26 00:18:43.000945 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-26 00:18:43.000984 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-26 00:18:43.243390 | controller | ok: Runtime: 0:00:38.124148
2025-12-26 00:18:43.256340 | 
2025-12-26 00:18:43.256494 | TASK [Install pytest-forked into virtualenv]
2025-12-26 00:18:55.173089 | controller | Collecting pytest-forked
2025-12-26 00:19:05.375273 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-26 00:19:05.419918 | controller | Collecting py
2025-12-26 00:19:05.424933 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-26 00:19:05.450540 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.2 MB/s eta 0:00:00
2025-12-26 00:19:05.565123 | controller | Collecting pytest>=3.10
2025-12-26 00:19:05.573116 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-26 00:19:05.595688 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 24.0 MB/s eta 0:00:00
2025-12-26 00:19:05.632999 | controller | Collecting iniconfig>=1.0.1
2025-12-26 00:19:05.637629 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-26 00:19:05.682347 | controller | Collecting packaging>=22
2025-12-26 00:19:05.685709 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-26 00:19:05.691258 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 20.0 MB/s eta 0:00:00
2025-12-26 00:19:05.720683 | controller | Collecting pluggy<2,>=1.5
2025-12-26 00:19:05.724070 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-26 00:19:05.771150 | controller | Collecting pygments>=2.7.2
2025-12-26 00:19:05.774835 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-26 00:19:05.800896 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 59.8 MB/s eta 0:00:00
2025-12-26 00:19:05.869301 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-26 00:19:06.920105 | 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-26 00:19:06.928691 | controller |
2025-12-26 00:19:07.000012 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-26 00:19:07.000070 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-26 00:19:07.321090 | controller | ok: Runtime: 0:00:23.505453
2025-12-26 00:19:07.334349 | 
2025-12-26 00:19:07.334496 | TASK [Update pip]
2025-12-26 00:19:07.870432 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-26 00:19:44.203057 | controller | Collecting pip
2025-12-26 00:19:56.380184 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-26 00:19:56.446962 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 29.0 MB/s eta 0:00:00
2025-12-26 00:19:56.511197 | controller | Installing collected packages: pip
2025-12-26 00:19:56.511413 | controller |   Attempting uninstall: pip
2025-12-26 00:19:56.513550 | controller |     Found existing installation: pip 22.2.2
2025-12-26 00:19:56.647698 | controller |     Uninstalling pip-22.2.2:
2025-12-26 00:19:56.662658 | controller |       Successfully uninstalled pip-22.2.2
2025-12-26 00:19:57.552809 | controller | Successfully installed pip-25.3
2025-12-26 00:19:57.917111 | controller | ok: Runtime: 0:00:50.067614
2025-12-26 00:19:57.927506 | 
2025-12-26 00:19:57.927659 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-26 00:19:58.157700 | controller | changed
2025-12-26 00:19:58.166438 | 
2025-12-26 00:19:58.166566 | TASK [Install ansible into virtualenv]
2025-12-26 00:19:58.732159 | controller | Processing ./src/github.com/ansible/ansible
2025-12-26 00:19:58.734694 | controller |   Installing build dependencies: started
2025-12-26 00:20:35.877148 | controller |   Installing build dependencies: finished with status 'done'
2025-12-26 00:20:35.878389 | controller |   Getting requirements to build wheel: started
2025-12-26 00:20:36.630196 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-26 00:20:36.631622 | controller |   Preparing metadata (pyproject.toml): started
2025-12-26 00:20:37.110495 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-26 00:20:37.115811 | 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-26 00:20:37.119446 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-26 00:20:37.279786 | controller | ERROR
2025-12-26 00:20:37.280081 | controller | {
2025-12-26 00:20:37.280142 | controller |   "delta": "0:00:38.750337",
2025-12-26 00:20:37.280183 | controller |   "end": "2025-12-26 00:20:37.187121",
2025-12-26 00:20:37.280223 | controller |   "msg": "non-zero return code",
2025-12-26 00:20:37.280281 | controller |   "rc": 1,
2025-12-26 00:20:37.280599 | controller |   "start": "2025-12-26 00:19:58.436784"
2025-12-26 00:20:37.280649 | controller | }
failure
2025-12-26 00:20:37.283859 | 
2025-12-26 00:20:37.283968 | PLAY RECAP
2025-12-26 00:20:37.284059 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-26 00:20:37.284102 | 
2025-12-26 00:20:37.527180 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-26 00:20:37.529810 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-26 00:20:38.130555 | 
2025-12-26 00:20:38.130705 | PLAY [all]
2025-12-26 00:20:38.152604 | 
2025-12-26 00:20:38.152744 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-26 00:20:38.423545 | controller | changed: non-zero return code
2025-12-26 00:20:38.432839 | 
2025-12-26 00:20:38.433045 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-26 00:20:38.450264 | controller | skipping: Conditional result was False
2025-12-26 00:20:38.460506 | 
2025-12-26 00:20:38.460774 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-26 00:20:38.484931 | 
2025-12-26 00:20:38.485141 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-26 00:20:38.506005 | 
2025-12-26 00:20:38.506379 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-26 00:20:38.520337 | controller | skipping: Conditional result was False
2025-12-26 00:20:38.528968 | 
2025-12-26 00:20:38.529095 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-26 00:20:38.550479 | 
2025-12-26 00:20:38.550690 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-26 00:20:38.565755 | controller | skipping: Conditional result was False
2025-12-26 00:20:38.573602 | 
2025-12-26 00:20:38.573777 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-26 00:20:38.588183 | controller | skipping: Conditional result was False
2025-12-26 00:20:38.595357 | 
2025-12-26 00:20:38.595456 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-26 00:20:38.609280 | controller | skipping: Conditional result was False
2025-12-26 00:20:38.638080 | 
2025-12-26 00:20:38.638234 | PLAY RECAP
2025-12-26 00:20:38.638286 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-26 00:20:38.638361 | 
2025-12-26 00:20:38.801013 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-26 00:20:38.803185 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-26 00:20:39.460378 | 
2025-12-26 00:20:39.460552 | PLAY [all:!appliance*]
2025-12-26 00:20:39.484116 | 
2025-12-26 00:20:39.484246 | TASK [unregister the node]
2025-12-26 00:20:40.018624 | controller | skipping: Conditional result was False
2025-12-26 00:20:40.034451 | 
2025-12-26 00:20:40.034796 | TASK [include_role : fetch-output]
2025-12-26 00:20:40.088520 | controller | ok
2025-12-26 00:20:40.133562 | 
2025-12-26 00:20:40.133825 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-26 00:20:40.211183 | controller | skipping: Conditional result was False
2025-12-26 00:20:40.225436 | 
2025-12-26 00:20:40.225601 | TASK [fetch-output : Set log path for single node]
2025-12-26 00:20:40.275610 | controller | ok
2025-12-26 00:20:40.287850 | 
2025-12-26 00:20:40.287991 | LOOP [fetch-output : Ensure local output dirs]
2025-12-26 00:20:40.745222 | controller -> localhost | ok: "/var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/logs"
2025-12-26 00:20:41.014209 | controller -> localhost | changed: "/var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/artifacts"
2025-12-26 00:20:41.278501 | controller -> localhost | changed: "/var/lib/zuul/builds/2b1908ecace04d3e967bbf7157ea537f/work/docs"
2025-12-26 00:20:41.301854 | 
2025-12-26 00:20:41.302106 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-26 00:20:42.044817 | controller | changed:
2025-12-26 00:20:42.045110 | controller | .d..t...... ./
2025-12-26 00:20:42.045152 | controller | cd+++++++++ controller/
2025-12-26 00:20:42.045209 | controller | changed: All items complete
2025-12-26 00:20:42.045240 | 
2025-12-26 00:20:42.578089 | controller | changed: .d..t...... ./
2025-12-26 00:20:43.117376 | controller | changed: .d..t...... ./
2025-12-26 00:20:43.141866 | 
2025-12-26 00:20:43.142057 | TASK [include_role : fetch-output-openshift]
2025-12-26 00:20:43.169282 | controller | skipping: Conditional result was False
2025-12-26 00:20:43.180494 | 
2025-12-26 00:20:43.180656 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-26 00:20:43.227358 | controller | skipping: Conditional result was False
2025-12-26 00:20:43.239117 | controller | skipping: Conditional result was False
2025-12-26 00:20:43.288612 | 
2025-12-26 00:20:43.288795 | PLAY [localhost]
2025-12-26 00:20:43.310163 | 
2025-12-26 00:20:43.310330 | TASK [Run Zuul manifest role]
2025-12-26 00:20:43.332897 | localhost | ok
2025-12-26 00:20:43.347852 | 
2025-12-26 00:20:43.347930 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-26 00:20:43.837630 | localhost | changed
2025-12-26 00:20:43.842326 | 
2025-12-26 00:20:43.842391 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-26 00:20:43.872631 | localhost | ok
2025-12-26 00:20:43.880886 | 
2025-12-26 00:20:43.880972 | TASK [Set zuul-log-path fact]
2025-12-26 00:20:43.901532 | localhost | ok
2025-12-26 00:20:43.920062 | 
2025-12-26 00:20:43.920231 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-26 00:20:43.952207 | localhost | ok
2025-12-26 00:20:43.960629 | 
2025-12-26 00:20:43.960715 | LOOP [Run upload-logs-swift role]
2025-12-26 00:20:43.999006 | localhost | Output suppressed because no_log was given
2025-12-26 00:20:44.025541 | 
2025-12-26 00:20:44.025671 | TASK [Set zuul-log-path fact]
2025-12-26 00:20:44.061178 | localhost | skipping: Conditional result was False
2025-12-26 00:20:44.068316 | 
2025-12-26 00:20:44.068427 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-26 00:20:44.607701 | localhost -> localhost | ok: Runtime: 0:00:00.007885
2025-12-26 00:20:44.663939 | 
2025-12-26 00:20:44.664131 | TASK [upload-logs-swift : Upload logs to swift]