2025-12-23 00:14:17.192573 | Job console starting...
2025-12-23 00:14:17.203191 | Updating repositories
2025-12-23 00:14:17.324543 | Preparing job workspace
2025-12-23 00:14:21.100775 | Running Ansible setup...
2025-12-23 00:14:25.988941 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-23 00:14:26.653746 | 
2025-12-23 00:14:26.653933 | PLAY [localhost]
2025-12-23 00:14:26.663349 | 
2025-12-23 00:14:26.663463 | TASK [Gathering Facts]
2025-12-23 00:14:27.724253 | localhost | ok
2025-12-23 00:14:27.752569 | 
2025-12-23 00:14:27.752778 | TASK [Setup log path fact]
2025-12-23 00:14:27.778494 | localhost | ok
2025-12-23 00:14:27.803940 | 
2025-12-23 00:14:27.804078 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-23 00:14:27.848161 | localhost | ok
2025-12-23 00:14:27.863260 | 
2025-12-23 00:14:27.863445 | TASK [emit-job-header : Print job information]
2025-12-23 00:14:27.918897 | # Job Information
2025-12-23 00:14:27.919138 | Ansible Version: 2.15.12
2025-12-23 00:14:27.919189 | Job: ansible-test-sanity-docker-milestone
2025-12-23 00:14:27.919221 | Pipeline: periodic
2025-12-23 00:14:27.919247 | Executor: ze01.softwarefactory-project.io
2025-12-23 00:14:27.919274 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-23 00:14:27.919307 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/2ca/ansible/2ca242e4ecc246a8acce276bf61cf2b5/
2025-12-23 00:14:27.919334 | Event ID: 53716c5a236c4d5eab91d4bd51d64c9b
2025-12-23 00:14:27.925630 | 
2025-12-23 00:14:27.925743 | LOOP [emit-job-header : Print node information]
2025-12-23 00:14:28.046242 | localhost | ok:
2025-12-23 00:14:28.046402 | localhost | # Node Information
2025-12-23 00:14:28.046428 | localhost | Inventory Hostname: controller
2025-12-23 00:14:28.046447 | localhost | Hostname: np0005569182
2025-12-23 00:14:28.046466 | localhost | Username: zuul
2025-12-23 00:14:28.046488 | localhost | Distro: Fedora 37
2025-12-23 00:14:28.046505 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-23 00:14:28.046522 | localhost | Region: ca-ymq-1
2025-12-23 00:14:28.046538 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-23 00:14:28.046554 | localhost | Product Name: OpenStack Nova
2025-12-23 00:14:28.046570 | localhost | Interface IP: 162.253.55.231
2025-12-23 00:14:28.072486 | 
2025-12-23 00:14:28.072681 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-23 00:14:28.517725 | localhost -> localhost | changed
2025-12-23 00:14:28.529197 | 
2025-12-23 00:14:28.529336 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-23 00:14:29.445317 | localhost -> localhost | changed
2025-12-23 00:14:29.490116 | 
2025-12-23 00:14:29.490222 | PLAY [all:!appliance*]
2025-12-23 00:14:29.514929 | 
2025-12-23 00:14:29.515101 | TASK [include_role : start-zuul-console]
2025-12-23 00:14:29.536630 | controller | ok
2025-12-23 00:14:29.551811 | 
2025-12-23 00:14:29.551913 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-23 00:14:29.941283 | controller | ok
2025-12-23 00:14:29.958607 | 
2025-12-23 00:14:29.958789 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-23 00:14:31.023262 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-23 00:14:31.033193 | 
2025-12-23 00:14:31.033313 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-23 00:14:31.567436 | controller | skipping: Conditional result was False
2025-12-23 00:14:31.576458 | 
2025-12-23 00:14:31.576639 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-23 00:14:31.601376 | controller | skipping: Conditional result was False
2025-12-23 00:14:31.609997 | 
2025-12-23 00:14:31.610172 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-23 00:14:31.635748 | controller | skipping: Conditional result was False
2025-12-23 00:14:31.642547 | 
2025-12-23 00:14:31.642750 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-23 00:14:31.667142 | controller | skipping: Conditional result was False
2025-12-23 00:14:31.674927 | 
2025-12-23 00:14:31.675035 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-23 00:14:31.709567 | controller | skipping: Conditional result was False
2025-12-23 00:14:31.716664 | 
2025-12-23 00:14:31.716749 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-23 00:14:31.742177 | controller | skipping: Conditional result was False
2025-12-23 00:14:31.755041 | 
2025-12-23 00:14:31.755172 | TASK [Disable Fedora Modular]
2025-12-23 00:14:32.006667 | controller | changed
2025-12-23 00:14:32.020117 | 
2025-12-23 00:14:32.020263 | TASK [Enable EPEL]
2025-12-23 00:14:32.046924 | controller | skipping: Conditional result was False
2025-12-23 00:14:32.053511 | 
2025-12-23 00:14:32.053583 | TASK [Register the RHEL node]
2025-12-23 00:14:32.600231 | 
2025-12-23 00:14:32.600406 | TASK [Show the subscription-manager status]
2025-12-23 00:14:33.170792 | controller | skipping: Conditional result was False
2025-12-23 00:14:33.181212 | 
2025-12-23 00:14:33.181361 | TASK [Enable EPEL on RHEL]
2025-12-23 00:14:33.731384 | controller | skipping: Conditional result was False
2025-12-23 00:14:33.741181 | 
2025-12-23 00:14:33.741309 | TASK [Install git and tox]
2025-12-23 00:15:57.544292 | controller | changed
2025-12-23 00:15:57.558443 | 
2025-12-23 00:15:57.558600 | TASK [include_role : prepare-workspace]
2025-12-23 00:15:57.593780 | controller | ok
2025-12-23 00:15:57.613925 | 
2025-12-23 00:15:57.614008 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-23 00:15:57.864845 | controller | ok
2025-12-23 00:15:57.874108 | 
2025-12-23 00:15:57.874222 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-23 00:16:10.450823 | controller | Output suppressed because no_log was given
2025-12-23 00:16:10.489772 | 
2025-12-23 00:16:10.489882 | TASK [include_role : prepare-workspace-openshift]
2025-12-23 00:16:10.517045 | controller | skipping: Conditional result was False
2025-12-23 00:16:10.539629 | 
2025-12-23 00:16:10.539731 | PLAY [all:!appliance]
2025-12-23 00:16:10.556284 | 
2025-12-23 00:16:10.556373 | TASK [Run add-build-sshkey role (RSA)]
2025-12-23 00:16:10.575510 | controller | ok
2025-12-23 00:16:10.589753 | 
2025-12-23 00:16:10.589845 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-23 00:16:10.859769 | controller -> localhost | ok
2025-12-23 00:16:10.868813 | 
2025-12-23 00:16:10.868909 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-23 00:16:10.911759 | controller | ok
2025-12-23 00:16:10.932542 | controller | included: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-23 00:16:10.940702 | 
2025-12-23 00:16:10.940788 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-23 00:16:11.404147 | controller -> localhost | Generating public/private rsa key pair.
2025-12-23 00:16:11.404354 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/2ca242e4ecc246a8acce276bf61cf2b5_id_rsa.
2025-12-23 00:16:11.404385 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/2ca242e4ecc246a8acce276bf61cf2b5_id_rsa.pub.
2025-12-23 00:16:11.404407 | controller -> localhost | The key fingerprint is:
2025-12-23 00:16:11.404429 | controller -> localhost | SHA256:vi2KvNiISB5B2EBNRU4A/rhnmaL4SMzdh+VkIIDJyXs zuul-build-sshkey
2025-12-23 00:16:11.404449 | controller -> localhost | The key's randomart image is:
2025-12-23 00:16:11.404469 | controller -> localhost | +---[RSA 2048]----+
2025-12-23 00:16:11.404489 | controller -> localhost | |*==o++           |
2025-12-23 00:16:11.404510 | controller -> localhost | |=*..o            |
2025-12-23 00:16:11.404530 | controller -> localhost | |.oo. o           |
2025-12-23 00:16:11.404550 | controller -> localhost | |..oE. .          |
2025-12-23 00:16:11.404571 | controller -> localhost | | o..   +S        |
2025-12-23 00:16:11.404601 | controller -> localhost | |o + + *.         |
2025-12-23 00:16:11.404625 | controller -> localhost | | O * o o.        |
2025-12-23 00:16:11.404647 | controller -> localhost | |Bo== .. .o       |
2025-12-23 00:16:11.404668 | controller -> localhost | |*o+ =......      |
2025-12-23 00:16:11.404691 | controller -> localhost | +----[SHA256]-----+
2025-12-23 00:16:11.404736 | controller -> localhost | ok: Runtime: 0:00:00.051606
2025-12-23 00:16:11.411822 | 
2025-12-23 00:16:11.411892 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-23 00:16:11.452583 | controller | ok
2025-12-23 00:16:11.473139 | controller | included: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-23 00:16:11.482532 | 
2025-12-23 00:16:11.482818 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-23 00:16:11.497505 | controller | skipping: Conditional result was False
2025-12-23 00:16:11.505083 | 
2025-12-23 00:16:11.505187 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-23 00:16:11.980584 | controller | changed
2025-12-23 00:16:11.987466 | 
2025-12-23 00:16:11.987604 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-23 00:16:12.219115 | controller | ok
2025-12-23 00:16:12.231507 | 
2025-12-23 00:16:12.231665 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-23 00:16:12.894334 | controller | changed
2025-12-23 00:16:12.901948 | 
2025-12-23 00:16:12.902084 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-23 00:16:13.541660 | controller | changed
2025-12-23 00:16:13.549064 | 
2025-12-23 00:16:13.549196 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-23 00:16:13.575007 | controller | skipping: Conditional result was False
2025-12-23 00:16:13.582793 | 
2025-12-23 00:16:13.582923 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-23 00:16:13.977512 | controller -> localhost | changed
2025-12-23 00:16:14.007671 | 
2025-12-23 00:16:14.007811 | TASK [add-build-sshkey : Add back temp key]
2025-12-23 00:16:14.279444 | controller -> localhost | Identity added: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/2ca242e4ecc246a8acce276bf61cf2b5_id_rsa (zuul-build-sshkey)
2025-12-23 00:16:14.279737 | controller -> localhost | ok: Runtime: 0:00:00.009536
2025-12-23 00:16:14.287979 | 
2025-12-23 00:16:14.288124 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-23 00:16:14.665591 | controller | ok
2025-12-23 00:16:14.678546 | 
2025-12-23 00:16:14.678687 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-23 00:16:14.705656 | controller | skipping: Conditional result was False
2025-12-23 00:16:14.734808 | 
2025-12-23 00:16:14.734958 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-23 00:16:14.775449 | controller | ok
2025-12-23 00:16:14.803649 | 
2025-12-23 00:16:14.803778 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-23 00:16:15.077387 | controller -> localhost | ok
2025-12-23 00:16:15.086996 | 
2025-12-23 00:16:15.087164 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-23 00:16:15.126955 | controller | ok
2025-12-23 00:16:15.138654 | controller | included: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-23 00:16:15.144959 | 
2025-12-23 00:16:15.145052 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-23 00:16:15.516567 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-23 00:16:15.516924 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/2ca242e4ecc246a8acce276bf61cf2b5_id_ecdsa.
2025-12-23 00:16:15.516975 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/2ca242e4ecc246a8acce276bf61cf2b5_id_ecdsa.pub.
2025-12-23 00:16:15.517054 | controller -> localhost | The key fingerprint is:
2025-12-23 00:16:15.517098 | controller -> localhost | SHA256:mtX0N8FWpRiCUotNbnr1H5otrHHhZY2PpWo5jb3UQlU zuul-build-sshkey
2025-12-23 00:16:15.517130 | controller -> localhost | The key's randomart image is:
2025-12-23 00:16:15.517162 | controller -> localhost | +---[ECDSA 521]---+
2025-12-23 00:16:15.517196 | controller -> localhost | |       .o.. .   E|
2025-12-23 00:16:15.517228 | controller -> localhost | |      .=.. . + o.|
2025-12-23 00:16:15.517261 | controller -> localhost | |      ..= o . = .|
2025-12-23 00:16:15.517292 | controller -> localhost | |       o + o . = |
2025-12-23 00:16:15.517320 | controller -> localhost | |      . S . + O o|
2025-12-23 00:16:15.517346 | controller -> localhost | |       =   o @ O |
2025-12-23 00:16:15.517370 | controller -> localhost | |      o   . B=B o|
2025-12-23 00:16:15.517393 | controller -> localhost | |           +=+o. |
2025-12-23 00:16:15.517417 | controller -> localhost | |          ...... |
2025-12-23 00:16:15.517440 | controller -> localhost | +----[SHA256]-----+
2025-12-23 00:16:15.517504 | controller -> localhost | ok: Runtime: 0:00:00.013319
2025-12-23 00:16:15.530323 | 
2025-12-23 00:16:15.530562 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-23 00:16:15.570652 | controller | ok
2025-12-23 00:16:15.585101 | controller | included: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-23 00:16:15.601540 | 
2025-12-23 00:16:15.601692 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-23 00:16:15.626696 | controller | skipping: Conditional result was False
2025-12-23 00:16:15.634092 | 
2025-12-23 00:16:15.634161 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-23 00:16:15.914778 | controller | changed
2025-12-23 00:16:15.929444 | 
2025-12-23 00:16:15.929672 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-23 00:16:16.175595 | controller | ok
2025-12-23 00:16:16.191126 | 
2025-12-23 00:16:16.191286 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-23 00:16:16.843868 | controller | changed
2025-12-23 00:16:16.851193 | 
2025-12-23 00:16:16.851272 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-23 00:16:17.537862 | controller | changed
2025-12-23 00:16:17.548065 | 
2025-12-23 00:16:17.548197 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-23 00:16:17.574005 | controller | skipping: Conditional result was False
2025-12-23 00:16:17.627350 | 
2025-12-23 00:16:17.627596 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-23 00:16:17.878600 | controller -> localhost | changed
2025-12-23 00:16:17.891044 | 
2025-12-23 00:16:17.891174 | TASK [add-build-sshkey : Add back temp key]
2025-12-23 00:16:18.216713 | controller -> localhost | Identity added: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/2ca242e4ecc246a8acce276bf61cf2b5_id_ecdsa (zuul-build-sshkey)
2025-12-23 00:16:18.216999 | controller -> localhost | ok: Runtime: 0:00:00.014371
2025-12-23 00:16:18.224249 | 
2025-12-23 00:16:18.224311 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-23 00:16:18.459441 | controller | ok
2025-12-23 00:16:18.471142 | 
2025-12-23 00:16:18.471334 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-23 00:16:18.519632 | controller | skipping: Conditional result was False
2025-12-23 00:16:18.537675 | 
2025-12-23 00:16:18.537870 | TASK [include_role : remove-zuul-sshkey]
2025-12-23 00:16:18.563542 | controller | skipping: Conditional result was False
2025-12-23 00:16:18.571514 | 
2025-12-23 00:16:18.571691 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-23 00:16:18.805074 | controller | ok: "logs"
2025-12-23 00:16:18.805344 | controller | ok: All items complete
2025-12-23 00:16:18.805371 | 
2025-12-23 00:16:18.985739 | controller | ok: "artifacts"
2025-12-23 00:16:19.188590 | controller | ok: "docs"
2025-12-23 00:16:19.204537 | 
2025-12-23 00:16:19.204769 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-23 00:16:19.460614 | controller | changed: "logs"
2025-12-23 00:16:19.657985 | controller | changed: "artifacts"
2025-12-23 00:16:19.844286 | controller | changed: "docs"
2025-12-23 00:16:19.895089 | 
2025-12-23 00:16:19.895252 | PLAY RECAP
2025-12-23 00:16:19.895361 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-23 00:16:19.895417 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-23 00:16:19.895449 | 
2025-12-23 00:16:20.095693 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-23 00:16:20.096617 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-23 00:16:20.792505 | 
2025-12-23 00:16:20.792701 | PLAY [all]
2025-12-23 00:16:20.830630 | 
2025-12-23 00:16:20.830840 | TASK [Install binary dependencies]
2025-12-23 00:16:20.903937 | controller | ok
2025-12-23 00:16:20.927040 | 
2025-12-23 00:16:20.927310 | TASK [bindep : Include find tasks]
2025-12-23 00:16:20.960222 | controller | ok
2025-12-23 00:16:20.971007 | controller | included: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-23 00:16:20.977554 | 
2025-12-23 00:16:20.977629 | TASK [bindep : Look for bindep.txt]
2025-12-23 00:16:21.363211 | controller | ok
2025-12-23 00:16:21.371725 | 
2025-12-23 00:16:21.371818 | TASK [bindep : Define bindep_file fact]
2025-12-23 00:16:21.398117 | controller | skipping: Conditional result was False
2025-12-23 00:16:21.405202 | 
2025-12-23 00:16:21.405340 | TASK [bindep : Look for other-requirements.txt]
2025-12-23 00:16:21.618642 | controller | ok
2025-12-23 00:16:21.635474 | 
2025-12-23 00:16:21.635687 | TASK [bindep : Define bindep_file fact]
2025-12-23 00:16:21.661678 | controller | skipping: Conditional result was False
2025-12-23 00:16:21.668482 | 
2025-12-23 00:16:21.668558 | TASK [bindep : Look for bindep fallback file]
2025-12-23 00:16:21.695925 | controller | skipping: Conditional result was False
2025-12-23 00:16:21.703769 | 
2025-12-23 00:16:21.703860 | TASK [bindep : Define bindep_file fact]
2025-12-23 00:16:21.733117 | controller | skipping: Conditional result was False
2025-12-23 00:16:21.741139 | 
2025-12-23 00:16:21.741224 | TASK [bindep : Include bindep tasks]
2025-12-23 00:16:21.776421 | controller | skipping: Conditional result was False
2025-12-23 00:16:21.784716 | 
2025-12-23 00:16:21.784879 | TASK [bindep : Include install tasks]
2025-12-23 00:16:21.821517 | controller | skipping: Conditional result was False
2025-12-23 00:16:21.831425 | 
2025-12-23 00:16:21.831637 | LOOP [bindep : Include package tasks]
2025-12-23 00:16:21.925481 | 
2025-12-23 00:16:21.925718 | TASK [Run test-setup role]
2025-12-23 00:16:21.948834 | controller | ok
2025-12-23 00:16:21.966981 | 
2025-12-23 00:16:21.967098 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-23 00:16:22.179721 | controller | ok
2025-12-23 00:16:22.196802 | 
2025-12-23 00:16:22.196955 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-23 00:16:22.736639 | controller | skipping: Conditional result was False
2025-12-23 00:16:22.794687 | 
2025-12-23 00:16:22.794825 | PLAY RECAP
2025-12-23 00:16:22.794880 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-23 00:16:22.794908 | 
2025-12-23 00:16:22.901425 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-23 00:16:22.902277 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-23 00:16:23.517049 | 
2025-12-23 00:16:23.517189 | PLAY [controller]
2025-12-23 00:16:23.539499 | 
2025-12-23 00:16:23.539633 | TASK [Create the /root directory]
2025-12-23 00:16:23.929041 | controller | ok
2025-12-23 00:16:23.934811 | 
2025-12-23 00:16:23.934890 | TASK [Install glibc-langpack-en]
2025-12-23 00:16:27.887931 | controller | ok: Nothing to do
2025-12-23 00:16:27.896891 | 
2025-12-23 00:16:27.897032 | TASK [Ensure controller directory exists]
2025-12-23 00:16:28.094940 | controller | changed
2025-12-23 00:16:28.104971 | 
2025-12-23 00:16:28.105147 | TASK [Install container runtime]
2025-12-23 00:16:28.176999 | controller | ok
2025-12-23 00:16:28.239799 | 
2025-12-23 00:16:28.239918 | LOOP [ensure-podman : Find distribution installation]
2025-12-23 00:16:28.286996 | controller | ok: "/var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-23 00:16:28.304399 | controller | included: /var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-23 00:16:28.310948 | 
2025-12-23 00:16:28.311029 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-23 00:17:33.334903 | controller | changed
2025-12-23 00:17:33.349621 | 
2025-12-23 00:17:33.349794 | TASK [ensure-podman : Fetch podman version]
2025-12-23 00:17:33.890976 | controller | Client:       Podman Engine
2025-12-23 00:17:33.915842 | controller | Version:      4.6.2
2025-12-23 00:17:33.915874 | controller | API Version:  4.6.2
2025-12-23 00:17:33.915885 | controller | Go Version:   go1.19.12
2025-12-23 00:17:33.915907 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-23 00:17:33.915966 | controller | OS/Arch:      linux/amd64
2025-12-23 00:17:34.402472 | controller | ok: Runtime: 0:00:00.178509
2025-12-23 00:17:34.416706 | 
2025-12-23 00:17:34.417007 | TASK [ensure-podman : Print podman version installed]
2025-12-23 00:17:34.458264 | Podman version: Client:       Podman Engine
2025-12-23 00:17:34.458529 | Version:      4.6.2
2025-12-23 00:17:34.458594 | API Version:  4.6.2
2025-12-23 00:17:34.458639 | Go Version:   go1.19.12
2025-12-23 00:17:34.458682 | Built:        Mon Aug 28 19:38:31 2023
2025-12-23 00:17:34.458726 | OS/Arch:      linux/amd64
2025-12-23 00:17:34.472319 | 
2025-12-23 00:17:34.472469 | TASK [ensure-podman : Validate podman engine]
2025-12-23 00:17:35.020209 | controller | skipping: Conditional result was False
2025-12-23 00:17:35.035619 | 
2025-12-23 00:17:35.035785 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-23 00:17:35.062845 | controller | skipping: Conditional result was False
2025-12-23 00:17:35.088220 | 
2025-12-23 00:17:35.088398 | TASK [Ensure python3.8 is present]
2025-12-23 00:17:35.115696 | controller | skipping: Conditional result was False
2025-12-23 00:17:35.130893 | 
2025-12-23 00:17:35.131113 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-23 00:17:35.159235 | controller | ok
2025-12-23 00:17:35.193095 | 
2025-12-23 00:17:35.193226 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-23 00:17:36.702652 | controller | ok: Nothing to do
2025-12-23 00:17:36.711913 | 
2025-12-23 00:17:36.712075 | TASK [our-ensure-python : Also install python3-devel]
2025-12-23 00:17:46.207731 | controller | changed
2025-12-23 00:17:46.232803 | 
2025-12-23 00:17:46.232985 | TASK [Run ensure-virtualenv role]
2025-12-23 00:17:46.255895 | controller | ok
2025-12-23 00:17:46.286412 | 
2025-12-23 00:17:46.286533 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-23 00:17:46.536532 | controller | /usr/bin/virtualenv
2025-12-23 00:17:46.820434 | controller | ok: Runtime: 0:00:00.005127
2025-12-23 00:17:46.831802 | 
2025-12-23 00:17:46.832271 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-23 00:17:46.862836 | controller | skipping: Conditional result was False
2025-12-23 00:17:46.863232 | controller | ok: All items complete
2025-12-23 00:17:46.863290 | 
2025-12-23 00:17:46.885448 | 
2025-12-23 00:17:46.885761 | TASK [Find the full path of the Python interpreter]
2025-12-23 00:17:47.097642 | controller | /usr/bin/python3
2025-12-23 00:17:47.429558 | controller | ok
2025-12-23 00:17:47.443311 | 
2025-12-23 00:17:47.443471 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-23 00:17:48.234178 | controller | created virtual environment CPython3.11.0.final.0-64 in 409ms
2025-12-23 00:17:48.248675 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-23 00:17:48.248713 | 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-23 00:17:48.248723 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-23 00:17:48.248737 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-23 00:17:48.502270 | controller | changed
2025-12-23 00:17:48.517269 | 
2025-12-23 00:17:48.517404 | TASK [Set selinux package]
2025-12-23 00:17:48.549069 | controller | ok
2025-12-23 00:17:48.560944 | 
2025-12-23 00:17:48.561104 | TASK [Set selinux package (Fedora)]
2025-12-23 00:17:48.615813 | controller | ok
2025-12-23 00:17:48.623204 | 
2025-12-23 00:17:48.623290 | TASK [Install selinux into virtualenv]
2025-12-23 00:18:38.033489 | controller | Collecting selinux-please-lie-to-me
2025-12-23 00:18:50.359193 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-23 00:18:50.660439 | controller | Collecting setuptools<50.0.0
2025-12-23 00:18:50.665948 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-23 00:18:50.710178 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 20.4 MB/s eta 0:00:00
2025-12-23 00:18:50.791285 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-23 00:18:50.791528 | controller |   Attempting uninstall: setuptools
2025-12-23 00:18:50.793930 | controller |     Found existing installation: setuptools 62.6.0
2025-12-23 00:18:50.853546 | controller |     Uninstalling setuptools-62.6.0:
2025-12-23 00:18:50.861542 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-23 00:18:51.195658 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-23 00:19:02.729839 | controller |
2025-12-23 00:19:02.808356 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-23 00:19:02.808396 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-23 00:19:03.192851 | controller | ok: Runtime: 0:01:13.954077
2025-12-23 00:19:03.201358 | 
2025-12-23 00:19:03.201433 | TASK [Install pytest-forked into virtualenv]
2025-12-23 00:19:15.000885 | controller | Collecting pytest-forked
2025-12-23 00:19:27.235730 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-23 00:19:27.281936 | controller | Collecting py
2025-12-23 00:19:27.286972 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-23 00:19:27.311648 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.4 MB/s eta 0:00:00
2025-12-23 00:19:27.415405 | controller | Collecting pytest>=3.10
2025-12-23 00:19:27.427878 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-23 00:19:27.452062 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 17.4 MB/s eta 0:00:00
2025-12-23 00:19:27.489726 | controller | Collecting iniconfig>=1.0.1
2025-12-23 00:19:27.493820 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-23 00:19:27.535756 | controller | Collecting packaging>=22
2025-12-23 00:19:27.539672 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-23 00:19:27.545623 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 14.6 MB/s eta 0:00:00
2025-12-23 00:19:27.577881 | controller | Collecting pluggy<2,>=1.5
2025-12-23 00:19:27.583549 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-23 00:19:27.635051 | controller | Collecting pygments>=2.7.2
2025-12-23 00:19:27.639498 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-23 00:19:27.669478 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 47.2 MB/s eta 0:00:00
2025-12-23 00:19:27.738903 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-23 00:19:28.785598 | 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-23 00:19:28.794322 | controller |
2025-12-23 00:19:28.868177 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-23 00:19:28.868229 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-23 00:19:29.241117 | controller | ok: Runtime: 0:00:25.477610
2025-12-23 00:19:29.254380 | 
2025-12-23 00:19:29.254535 | TASK [Update pip]
2025-12-23 00:19:29.780384 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-23 00:20:03.475741 | controller | Collecting pip
2025-12-23 00:20:27.613475 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-23 00:20:27.675773 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 30.8 MB/s eta 0:00:00
2025-12-23 00:20:27.739263 | controller | Installing collected packages: pip
2025-12-23 00:20:27.739466 | controller |   Attempting uninstall: pip
2025-12-23 00:20:27.741558 | controller |     Found existing installation: pip 22.2.2
2025-12-23 00:20:27.878602 | controller |     Uninstalling pip-22.2.2:
2025-12-23 00:20:27.893371 | controller |       Successfully uninstalled pip-22.2.2
2025-12-23 00:20:28.693998 | controller | Successfully installed pip-25.3
2025-12-23 00:20:28.834620 | controller | ok: Runtime: 0:00:59.271908
2025-12-23 00:20:28.847236 | 
2025-12-23 00:20:28.847415 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-23 00:20:29.055734 | controller | changed
2025-12-23 00:20:29.064477 | 
2025-12-23 00:20:29.064557 | TASK [Install ansible into virtualenv]
2025-12-23 00:20:29.593187 | controller | Processing ./src/github.com/ansible/ansible
2025-12-23 00:20:29.596500 | controller |   Installing build dependencies: started
2025-12-23 00:21:18.772937 | controller |   Installing build dependencies: finished with status 'done'
2025-12-23 00:21:18.773512 | controller |   Getting requirements to build wheel: started
2025-12-23 00:21:19.510199 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-23 00:21:19.511343 | controller |   Preparing metadata (pyproject.toml): started
2025-12-23 00:21:19.975197 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-23 00:21:19.980386 | 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-23 00:21:19.985181 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-23 00:21:20.163070 | controller | ERROR
2025-12-23 00:21:20.163324 | controller | {
2025-12-23 00:21:20.163387 | controller |   "delta": "0:00:50.725523",
2025-12-23 00:21:20.163430 | controller |   "end": "2025-12-23 00:21:20.045777",
2025-12-23 00:21:20.163467 | controller |   "msg": "non-zero return code",
2025-12-23 00:21:20.163520 | controller |   "rc": 1,
2025-12-23 00:21:20.163556 | controller |   "start": "2025-12-23 00:20:29.320254"
2025-12-23 00:21:20.163591 | controller | }
failure
2025-12-23 00:21:20.166824 | 
2025-12-23 00:21:20.166930 | PLAY RECAP
2025-12-23 00:21:20.167053 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-23 00:21:20.167108 | 
2025-12-23 00:21:20.299926 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-23 00:21:20.300952 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-23 00:21:20.918124 | 
2025-12-23 00:21:20.918236 | PLAY [all]
2025-12-23 00:21:20.940314 | 
2025-12-23 00:21:20.940413 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-23 00:21:21.209183 | controller | changed: non-zero return code
2025-12-23 00:21:21.215957 | 
2025-12-23 00:21:21.216115 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-23 00:21:21.241940 | controller | skipping: Conditional result was False
2025-12-23 00:21:21.256279 | 
2025-12-23 00:21:21.256493 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-23 00:21:21.305558 | 
2025-12-23 00:21:21.305852 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-23 00:21:21.343623 | 
2025-12-23 00:21:21.343844 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-23 00:21:21.360984 | controller | skipping: Conditional result was False
2025-12-23 00:21:21.373591 | 
2025-12-23 00:21:21.373749 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-23 00:21:21.405890 | 
2025-12-23 00:21:21.406683 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-23 00:21:21.435320 | controller | skipping: Conditional result was False
2025-12-23 00:21:21.443478 | 
2025-12-23 00:21:21.443582 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-23 00:21:21.469870 | controller | skipping: Conditional result was False
2025-12-23 00:21:21.479502 | 
2025-12-23 00:21:21.479597 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-23 00:21:21.506041 | controller | skipping: Conditional result was False
2025-12-23 00:21:21.544937 | 
2025-12-23 00:21:21.545114 | PLAY RECAP
2025-12-23 00:21:21.545182 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-23 00:21:21.545214 | 
2025-12-23 00:21:21.675607 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-23 00:21:21.676604 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-23 00:21:22.288608 | 
2025-12-23 00:21:22.288727 | PLAY [all:!appliance*]
2025-12-23 00:21:22.311348 | 
2025-12-23 00:21:22.311449 | TASK [unregister the node]
2025-12-23 00:21:22.842768 | controller | skipping: Conditional result was False
2025-12-23 00:21:22.850875 | 
2025-12-23 00:21:22.850977 | TASK [include_role : fetch-output]
2025-12-23 00:21:22.900225 | controller | ok
2025-12-23 00:21:22.942815 | 
2025-12-23 00:21:22.942973 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-23 00:21:23.019209 | controller | skipping: Conditional result was False
2025-12-23 00:21:23.028840 | 
2025-12-23 00:21:23.028968 | TASK [fetch-output : Set log path for single node]
2025-12-23 00:21:23.073129 | controller | ok
2025-12-23 00:21:23.081245 | 
2025-12-23 00:21:23.081365 | LOOP [fetch-output : Ensure local output dirs]
2025-12-23 00:21:23.501399 | controller -> localhost | ok: "/var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/logs"
2025-12-23 00:21:23.724136 | controller -> localhost | changed: "/var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/artifacts"
2025-12-23 00:21:23.971434 | controller -> localhost | changed: "/var/lib/zuul/builds/2ca242e4ecc246a8acce276bf61cf2b5/work/docs"
2025-12-23 00:21:23.992300 | 
2025-12-23 00:21:23.992511 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-23 00:21:24.671318 | controller | changed:
2025-12-23 00:21:24.671658 | controller | .d..t...... ./
2025-12-23 00:21:24.671722 | controller | cd+++++++++ controller/
2025-12-23 00:21:24.671793 | controller | changed: All items complete
2025-12-23 00:21:24.671839 | 
2025-12-23 00:21:25.147349 | controller | changed: .d..t...... ./
2025-12-23 00:21:25.658240 | controller | changed: .d..t...... ./
2025-12-23 00:21:25.685507 | 
2025-12-23 00:21:25.685633 | TASK [include_role : fetch-output-openshift]
2025-12-23 00:21:25.709560 | controller | skipping: Conditional result was False
2025-12-23 00:21:25.726428 | 
2025-12-23 00:21:25.726697 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-23 00:21:25.754194 | controller | skipping: Conditional result was False
2025-12-23 00:21:25.762174 | controller | skipping: Conditional result was False
2025-12-23 00:21:25.793938 | 
2025-12-23 00:21:25.794080 | PLAY [localhost]
2025-12-23 00:21:25.807327 | 
2025-12-23 00:21:25.807438 | TASK [Run Zuul manifest role]
2025-12-23 00:21:25.826711 | localhost | ok
2025-12-23 00:21:25.841998 | 
2025-12-23 00:21:25.842138 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-23 00:21:26.281330 | localhost | changed
2025-12-23 00:21:26.286037 | 
2025-12-23 00:21:26.286111 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-23 00:21:26.313853 | localhost | ok
2025-12-23 00:21:26.322100 | 
2025-12-23 00:21:26.322188 | TASK [Set zuul-log-path fact]
2025-12-23 00:21:26.344437 | localhost | ok
2025-12-23 00:21:26.369871 | 
2025-12-23 00:21:26.369986 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-23 00:21:26.398946 | localhost | ok
2025-12-23 00:21:26.406890 | 
2025-12-23 00:21:26.406993 | LOOP [Run upload-logs-swift role]
2025-12-23 00:21:26.441760 | localhost | Output suppressed because no_log was given
2025-12-23 00:21:26.467122 | 
2025-12-23 00:21:26.467256 | TASK [Set zuul-log-path fact]
2025-12-23 00:21:26.491614 | localhost | skipping: Conditional result was False
2025-12-23 00:21:26.497016 | 
2025-12-23 00:21:26.497131 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-23 00:21:26.899506 | localhost -> localhost | ok: Runtime: 0:00:00.005840
2025-12-23 00:21:26.906089 | 
2025-12-23 00:21:26.906178 | TASK [upload-logs-swift : Upload logs to swift]