2025-12-27 00:21:23.044221 | Job console starting...
2025-12-27 00:21:23.059442 | Updating repositories
2025-12-27 00:21:23.182787 | Preparing job workspace
2025-12-27 00:21:26.489938 | Running Ansible setup...
2025-12-27 00:21:31.703265 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-27 00:21:32.304747 | 
2025-12-27 00:21:32.304903 | PLAY [localhost]
2025-12-27 00:21:32.313973 | 
2025-12-27 00:21:32.314043 | TASK [Gathering Facts]
2025-12-27 00:21:33.330657 | localhost | ok
2025-12-27 00:21:33.358880 | 
2025-12-27 00:21:33.358995 | TASK [Setup log path fact]
2025-12-27 00:21:33.388225 | localhost | ok
2025-12-27 00:21:33.406217 | 
2025-12-27 00:21:33.406313 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-27 00:21:33.436758 | localhost | ok
2025-12-27 00:21:33.446700 | 
2025-12-27 00:21:33.446774 | TASK [emit-job-header : Print job information]
2025-12-27 00:21:33.477201 | # Job Information
2025-12-27 00:21:33.477376 | Ansible Version: 2.15.12
2025-12-27 00:21:33.477408 | Job: ansible-test-sanity-docker-milestone
2025-12-27 00:21:33.477428 | Pipeline: periodic
2025-12-27 00:21:33.477446 | Executor: ze02.softwarefactory-project.io
2025-12-27 00:21:33.477464 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-27 00:21:33.477484 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/134/ansible/13462208ccb1421e80ae5eb856f3642b/
2025-12-27 00:21:33.477503 | Event ID: 88cebac4610b4a578de9ac934b821521
2025-12-27 00:21:33.481447 | 
2025-12-27 00:21:33.481513 | LOOP [emit-job-header : Print node information]
2025-12-27 00:21:33.592069 | localhost | ok:
2025-12-27 00:21:33.592500 | localhost | # Node Information
2025-12-27 00:21:33.592527 | localhost | Inventory Hostname: controller
2025-12-27 00:21:33.592547 | localhost | Hostname: np0005571279
2025-12-27 00:21:33.592567 | localhost | Username: zuul
2025-12-27 00:21:33.592591 | localhost | Distro: Fedora 37
2025-12-27 00:21:33.592610 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-27 00:21:33.592628 | localhost | Region: ca-ymq-1
2025-12-27 00:21:33.592645 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-27 00:21:33.592686 | localhost | Product Name: OpenStack Nova
2025-12-27 00:21:33.592710 | localhost | Interface IP: 162.253.55.209
2025-12-27 00:21:33.618728 | 
2025-12-27 00:21:33.618949 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-27 00:21:34.086387 | localhost -> localhost | changed
2025-12-27 00:21:34.098559 | 
2025-12-27 00:21:34.098775 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-27 00:21:35.173200 | localhost -> localhost | changed
2025-12-27 00:21:35.200511 | 
2025-12-27 00:21:35.200706 | PLAY [all:!appliance*]
2025-12-27 00:21:35.221773 | 
2025-12-27 00:21:35.221917 | TASK [include_role : start-zuul-console]
2025-12-27 00:21:35.245334 | controller | ok
2025-12-27 00:21:35.262624 | 
2025-12-27 00:21:35.262786 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-27 00:21:35.672538 | controller | ok
2025-12-27 00:21:35.685905 | 
2025-12-27 00:21:35.696840 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-27 00:21:37.162327 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-27 00:21:37.179168 | 
2025-12-27 00:21:37.179325 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-27 00:21:37.723788 | controller | skipping: Conditional result was False
2025-12-27 00:21:37.739132 | 
2025-12-27 00:21:37.739329 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-27 00:21:37.778493 | controller | skipping: Conditional result was False
2025-12-27 00:21:37.787891 | 
2025-12-27 00:21:37.788102 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-27 00:21:37.818140 | controller | skipping: Conditional result was False
2025-12-27 00:21:37.846452 | 
2025-12-27 00:21:37.847234 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-27 00:21:37.877333 | controller | skipping: Conditional result was False
2025-12-27 00:21:37.888277 | 
2025-12-27 00:21:37.888391 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-27 00:21:37.914827 | controller | skipping: Conditional result was False
2025-12-27 00:21:37.925495 | 
2025-12-27 00:21:37.925620 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-27 00:21:37.951592 | controller | skipping: Conditional result was False
2025-12-27 00:21:37.973203 | 
2025-12-27 00:21:37.973373 | TASK [Disable Fedora Modular]
2025-12-27 00:21:38.225128 | controller | changed
2025-12-27 00:21:38.233790 | 
2025-12-27 00:21:38.233882 | TASK [Enable EPEL]
2025-12-27 00:21:38.260187 | controller | skipping: Conditional result was False
2025-12-27 00:21:38.272969 | 
2025-12-27 00:21:38.273073 | TASK [Register the RHEL node]
2025-12-27 00:21:38.832495 | 
2025-12-27 00:21:38.832829 | TASK [Show the subscription-manager status]
2025-12-27 00:21:39.414281 | controller | skipping: Conditional result was False
2025-12-27 00:21:39.424219 | 
2025-12-27 00:21:39.424315 | TASK [Enable EPEL on RHEL]
2025-12-27 00:21:39.969183 | controller | skipping: Conditional result was False
2025-12-27 00:21:39.984939 | 
2025-12-27 00:21:39.985546 | TASK [Install git and tox]
2025-12-27 00:23:04.721218 | controller | changed
2025-12-27 00:23:04.734935 | 
2025-12-27 00:23:04.735103 | TASK [include_role : prepare-workspace]
2025-12-27 00:23:04.777365 | controller | ok
2025-12-27 00:23:04.815057 | 
2025-12-27 00:23:04.815156 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-27 00:23:05.071768 | controller | ok
2025-12-27 00:23:05.088846 | 
2025-12-27 00:23:05.089133 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-27 00:23:17.739334 | controller | Output suppressed because no_log was given
2025-12-27 00:23:17.750649 | 
2025-12-27 00:23:17.750804 | TASK [include_role : prepare-workspace-openshift]
2025-12-27 00:23:17.767733 | controller | skipping: Conditional result was False
2025-12-27 00:23:17.827708 | 
2025-12-27 00:23:17.827790 | PLAY [all:!appliance]
2025-12-27 00:23:17.843027 | 
2025-12-27 00:23:17.843089 | TASK [Run add-build-sshkey role (RSA)]
2025-12-27 00:23:17.864655 | controller | ok
2025-12-27 00:23:17.880138 | 
2025-12-27 00:23:17.880212 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-27 00:23:18.146271 | controller -> localhost | ok
2025-12-27 00:23:18.155531 | 
2025-12-27 00:23:18.155603 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-27 00:23:18.177509 | controller | ok
2025-12-27 00:23:18.193616 | controller | included: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-27 00:23:18.200262 | 
2025-12-27 00:23:18.200359 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-27 00:23:18.722987 | controller -> localhost | Generating public/private rsa key pair.
2025-12-27 00:23:18.723442 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/13462208ccb1421e80ae5eb856f3642b_id_rsa.
2025-12-27 00:23:18.723508 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/13462208ccb1421e80ae5eb856f3642b_id_rsa.pub.
2025-12-27 00:23:18.723556 | controller -> localhost | The key fingerprint is:
2025-12-27 00:23:18.723601 | controller -> localhost | SHA256:f8Bv9xmb1i3yhFlzdEmRLH8DWKiD5TZoDjgKdcdIEY4 zuul-build-sshkey
2025-12-27 00:23:18.723645 | controller -> localhost | The key's randomart image is:
2025-12-27 00:23:18.723739 | controller -> localhost | +---[RSA 2048]----+
2025-12-27 00:23:18.723785 | controller -> localhost | |   .+=      +..oo|
2025-12-27 00:23:18.723828 | controller -> localhost | |  .oo o  . o o.o.|
2025-12-27 00:23:18.723869 | controller -> localhost | | .E.o.  = .   +.o|
2025-12-27 00:23:18.723909 | controller -> localhost | |.  o . + B     +o|
2025-12-27 00:23:18.723948 | controller -> localhost | |. . . + S =   o +|
2025-12-27 00:23:18.724007 | controller -> localhost | | .     . . o + o |
2025-12-27 00:23:18.724057 | controller -> localhost | |          . * o.o|
2025-12-27 00:23:18.724101 | controller -> localhost | |           o.o.oB|
2025-12-27 00:23:18.724141 | controller -> localhost | |             oo=.|
2025-12-27 00:23:18.724189 | controller -> localhost | +----[SHA256]-----+
2025-12-27 00:23:18.724297 | controller -> localhost | ok: Runtime: 0:00:00.154450
2025-12-27 00:23:18.739611 | 
2025-12-27 00:23:18.739828 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-27 00:23:18.777575 | controller | ok
2025-12-27 00:23:18.792566 | controller | included: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-27 00:23:18.804586 | 
2025-12-27 00:23:18.804694 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-27 00:23:18.832188 | controller | skipping: Conditional result was False
2025-12-27 00:23:18.841798 | 
2025-12-27 00:23:18.841891 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-27 00:23:19.308467 | controller | changed
2025-12-27 00:23:19.321574 | 
2025-12-27 00:23:19.321797 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-27 00:23:19.577055 | controller | ok
2025-12-27 00:23:19.605050 | 
2025-12-27 00:23:19.605236 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-27 00:23:20.242910 | controller | changed
2025-12-27 00:23:20.255539 | 
2025-12-27 00:23:20.255701 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-27 00:23:20.906256 | controller | changed
2025-12-27 00:23:20.912304 | 
2025-12-27 00:23:20.912371 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-27 00:23:20.937810 | controller | skipping: Conditional result was False
2025-12-27 00:23:20.944774 | 
2025-12-27 00:23:20.944847 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-27 00:23:21.419069 | controller -> localhost | changed
2025-12-27 00:23:21.432943 | 
2025-12-27 00:23:21.433022 | TASK [add-build-sshkey : Add back temp key]
2025-12-27 00:23:21.754891 | controller -> localhost | Identity added: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/13462208ccb1421e80ae5eb856f3642b_id_rsa (zuul-build-sshkey)
2025-12-27 00:23:21.755376 | controller -> localhost | ok: Runtime: 0:00:00.014373
2025-12-27 00:23:21.773851 | 
2025-12-27 00:23:21.774055 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-27 00:23:22.193612 | controller | ok
2025-12-27 00:23:22.208802 | 
2025-12-27 00:23:22.209007 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-27 00:23:22.237205 | controller | skipping: Conditional result was False
2025-12-27 00:23:22.253996 | 
2025-12-27 00:23:22.254146 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-27 00:23:22.280753 | controller | ok
2025-12-27 00:23:22.311133 | 
2025-12-27 00:23:22.311347 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-27 00:23:22.612877 | controller -> localhost | ok
2025-12-27 00:23:22.630452 | 
2025-12-27 00:23:22.630715 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-27 00:23:22.675054 | controller | ok
2025-12-27 00:23:22.687447 | controller | included: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-27 00:23:22.694374 | 
2025-12-27 00:23:22.694472 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-27 00:23:23.040629 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-27 00:23:23.041165 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/13462208ccb1421e80ae5eb856f3642b_id_ecdsa.
2025-12-27 00:23:23.041226 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/13462208ccb1421e80ae5eb856f3642b_id_ecdsa.pub.
2025-12-27 00:23:23.041287 | controller -> localhost | The key fingerprint is:
2025-12-27 00:23:23.041330 | controller -> localhost | SHA256:vGNpxVrj/lWdgtWgv/FK+WFXx0LVLRxzL84FLgZ5PdY zuul-build-sshkey
2025-12-27 00:23:23.041370 | controller -> localhost | The key's randomart image is:
2025-12-27 00:23:23.041409 | controller -> localhost | +---[ECDSA 521]---+
2025-12-27 00:23:23.041447 | controller -> localhost | |          .. ++o=|
2025-12-27 00:23:23.041485 | controller -> localhost | |          ..o.O=E|
2025-12-27 00:23:23.041522 | controller -> localhost | |           ooo++o|
2025-12-27 00:23:23.041559 | controller -> localhost | |       . . .+= +o|
2025-12-27 00:23:23.041597 | controller -> localhost | |        S =. ++.*|
2025-12-27 00:23:23.041634 | controller -> localhost | |         B .  *oo|
2025-12-27 00:23:23.041706 | controller -> localhost | |        B .  +.+.|
2025-12-27 00:23:23.041753 | controller -> localhost | |       o o  ..+ o|
2025-12-27 00:23:23.041791 | controller -> localhost | |          .... . |
2025-12-27 00:23:23.041828 | controller -> localhost | +----[SHA256]-----+
2025-12-27 00:23:23.041930 | controller -> localhost | ok: Runtime: 0:00:00.010133
2025-12-27 00:23:23.058232 | 
2025-12-27 00:23:23.058444 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-27 00:23:23.113730 | controller | ok
2025-12-27 00:23:23.125766 | controller | included: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-27 00:23:23.139024 | 
2025-12-27 00:23:23.139154 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-27 00:23:23.166276 | controller | skipping: Conditional result was False
2025-12-27 00:23:23.176367 | 
2025-12-27 00:23:23.176473 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-27 00:23:23.458145 | controller | changed
2025-12-27 00:23:23.468069 | 
2025-12-27 00:23:23.468263 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-27 00:23:23.712331 | controller | ok
2025-12-27 00:23:23.727964 | 
2025-12-27 00:23:23.728158 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-27 00:23:24.371836 | controller | changed
2025-12-27 00:23:24.381098 | 
2025-12-27 00:23:24.381199 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-27 00:23:25.033019 | controller | changed
2025-12-27 00:23:25.049589 | 
2025-12-27 00:23:25.049879 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-27 00:23:25.080789 | controller | skipping: Conditional result was False
2025-12-27 00:23:25.097700 | 
2025-12-27 00:23:25.098016 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-27 00:23:25.432788 | controller -> localhost | changed
2025-12-27 00:23:25.505253 | 
2025-12-27 00:23:25.505426 | TASK [add-build-sshkey : Add back temp key]
2025-12-27 00:23:25.836044 | controller -> localhost | Identity added: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/13462208ccb1421e80ae5eb856f3642b_id_ecdsa (zuul-build-sshkey)
2025-12-27 00:23:25.836447 | controller -> localhost | ok: Runtime: 0:00:00.008828
2025-12-27 00:23:25.850844 | 
2025-12-27 00:23:25.850987 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-27 00:23:26.080829 | controller | ok
2025-12-27 00:23:26.101461 | 
2025-12-27 00:23:26.101866 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-27 00:23:26.131560 | controller | skipping: Conditional result was False
2025-12-27 00:23:26.159702 | 
2025-12-27 00:23:26.159908 | TASK [include_role : remove-zuul-sshkey]
2025-12-27 00:23:26.176865 | controller | skipping: Conditional result was False
2025-12-27 00:23:26.187435 | 
2025-12-27 00:23:26.187587 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-27 00:23:26.431644 | controller | ok: "logs"
2025-12-27 00:23:26.432324 | controller | ok: All items complete
2025-12-27 00:23:26.432392 | 
2025-12-27 00:23:26.636926 | controller | ok: "artifacts"
2025-12-27 00:23:26.845323 | controller | ok: "docs"
2025-12-27 00:23:26.861424 | 
2025-12-27 00:23:26.861595 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-27 00:23:27.102379 | controller | changed: "logs"
2025-12-27 00:23:27.300124 | controller | changed: "artifacts"
2025-12-27 00:23:27.518788 | controller | changed: "docs"
2025-12-27 00:23:27.551326 | 
2025-12-27 00:23:27.551570 | PLAY RECAP
2025-12-27 00:23:27.551626 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-27 00:23:27.551653 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-27 00:23:27.551696 | 
2025-12-27 00:23:27.736357 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-27 00:23:27.737854 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-27 00:23:28.399099 | 
2025-12-27 00:23:28.399270 | PLAY [all]
2025-12-27 00:23:28.422517 | 
2025-12-27 00:23:28.422633 | TASK [Install binary dependencies]
2025-12-27 00:23:28.487784 | controller | ok
2025-12-27 00:23:28.516732 | 
2025-12-27 00:23:28.516852 | TASK [bindep : Include find tasks]
2025-12-27 00:23:28.550125 | controller | ok
2025-12-27 00:23:28.558263 | controller | included: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-27 00:23:28.564812 | 
2025-12-27 00:23:28.564876 | TASK [bindep : Look for bindep.txt]
2025-12-27 00:23:28.931311 | controller | ok
2025-12-27 00:23:28.944174 | 
2025-12-27 00:23:28.944322 | TASK [bindep : Define bindep_file fact]
2025-12-27 00:23:28.973450 | controller | skipping: Conditional result was False
2025-12-27 00:23:28.988643 | 
2025-12-27 00:23:28.988828 | TASK [bindep : Look for other-requirements.txt]
2025-12-27 00:23:29.226062 | controller | ok
2025-12-27 00:23:29.238289 | 
2025-12-27 00:23:29.238431 | TASK [bindep : Define bindep_file fact]
2025-12-27 00:23:29.277927 | controller | skipping: Conditional result was False
2025-12-27 00:23:29.292050 | 
2025-12-27 00:23:29.292201 | TASK [bindep : Look for bindep fallback file]
2025-12-27 00:23:29.321315 | controller | skipping: Conditional result was False
2025-12-27 00:23:29.347634 | 
2025-12-27 00:23:29.347821 | TASK [bindep : Define bindep_file fact]
2025-12-27 00:23:29.375227 | controller | skipping: Conditional result was False
2025-12-27 00:23:29.385207 | 
2025-12-27 00:23:29.385295 | TASK [bindep : Include bindep tasks]
2025-12-27 00:23:29.421971 | controller | skipping: Conditional result was False
2025-12-27 00:23:29.431072 | 
2025-12-27 00:23:29.431160 | TASK [bindep : Include install tasks]
2025-12-27 00:23:29.477358 | controller | skipping: Conditional result was False
2025-12-27 00:23:29.491354 | 
2025-12-27 00:23:29.491497 | LOOP [bindep : Include package tasks]
2025-12-27 00:23:29.586699 | 
2025-12-27 00:23:29.587010 | TASK [Run test-setup role]
2025-12-27 00:23:29.621318 | controller | ok
2025-12-27 00:23:29.647975 | 
2025-12-27 00:23:29.648067 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-27 00:23:29.874566 | controller | ok
2025-12-27 00:23:29.889270 | 
2025-12-27 00:23:29.889370 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-27 00:23:30.437643 | controller | skipping: Conditional result was False
2025-12-27 00:23:30.496367 | 
2025-12-27 00:23:30.496502 | PLAY RECAP
2025-12-27 00:23:30.496561 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-27 00:23:30.496589 | 
2025-12-27 00:23:30.634913 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-27 00:23:30.635825 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-27 00:23:31.312928 | 
2025-12-27 00:23:31.313125 | PLAY [controller]
2025-12-27 00:23:31.340959 | 
2025-12-27 00:23:31.341149 | TASK [Create the /root directory]
2025-12-27 00:23:31.775472 | controller | ok
2025-12-27 00:23:31.782006 | 
2025-12-27 00:23:31.782087 | TASK [Install glibc-langpack-en]
2025-12-27 00:23:35.725841 | controller | ok: Nothing to do
2025-12-27 00:23:35.739571 | 
2025-12-27 00:23:35.739788 | TASK [Ensure controller directory exists]
2025-12-27 00:23:35.977103 | controller | changed
2025-12-27 00:23:35.992428 | 
2025-12-27 00:23:35.992600 | TASK [Install container runtime]
2025-12-27 00:23:36.067353 | controller | ok
2025-12-27 00:23:36.129553 | 
2025-12-27 00:23:36.129731 | LOOP [ensure-podman : Find distribution installation]
2025-12-27 00:23:36.170519 | controller | ok: "/var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-27 00:23:36.192580 | controller | included: /var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-27 00:23:36.207939 | 
2025-12-27 00:23:36.208100 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-27 00:24:42.691421 | controller | changed
2025-12-27 00:24:42.701684 | 
2025-12-27 00:24:42.701780 | TASK [ensure-podman : Fetch podman version]
2025-12-27 00:24:43.282809 | controller | Client:       Podman Engine
2025-12-27 00:24:43.313971 | controller | Version:      4.6.2
2025-12-27 00:24:43.313999 | controller | API Version:  4.6.2
2025-12-27 00:24:43.314007 | controller | Go Version:   go1.19.12
2025-12-27 00:24:43.314024 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-27 00:24:43.314034 | controller | OS/Arch:      linux/amd64
2025-12-27 00:24:43.747872 | controller | ok: Runtime: 0:00:00.212191
2025-12-27 00:24:43.763354 | 
2025-12-27 00:24:43.763550 | TASK [ensure-podman : Print podman version installed]
2025-12-27 00:24:43.801291 | Podman version: Client:       Podman Engine
2025-12-27 00:24:43.801490 | Version:      4.6.2
2025-12-27 00:24:43.801519 | API Version:  4.6.2
2025-12-27 00:24:43.801540 | Go Version:   go1.19.12
2025-12-27 00:24:43.801558 | Built:        Mon Aug 28 19:38:31 2023
2025-12-27 00:24:43.801577 | OS/Arch:      linux/amd64
2025-12-27 00:24:43.807956 | 
2025-12-27 00:24:43.808028 | TASK [ensure-podman : Validate podman engine]
2025-12-27 00:24:44.348126 | controller | skipping: Conditional result was False
2025-12-27 00:24:44.369191 | 
2025-12-27 00:24:44.369376 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-27 00:24:44.401255 | controller | skipping: Conditional result was False
2025-12-27 00:24:44.418114 | 
2025-12-27 00:24:44.418257 | TASK [Ensure python3.8 is present]
2025-12-27 00:24:44.445979 | controller | skipping: Conditional result was False
2025-12-27 00:24:44.457497 | 
2025-12-27 00:24:44.457590 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-27 00:24:44.484313 | controller | ok
2025-12-27 00:24:44.511231 | 
2025-12-27 00:24:44.511302 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-27 00:24:46.015412 | controller | ok: Nothing to do
2025-12-27 00:24:46.029293 | 
2025-12-27 00:24:46.029467 | TASK [our-ensure-python : Also install python3-devel]
2025-12-27 00:24:54.677739 | controller | changed
2025-12-27 00:24:54.694568 | 
2025-12-27 00:24:54.694701 | TASK [Run ensure-virtualenv role]
2025-12-27 00:24:54.718795 | controller | ok
2025-12-27 00:24:54.749153 | 
2025-12-27 00:24:54.749364 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-27 00:24:55.004497 | controller | /usr/bin/virtualenv
2025-12-27 00:24:55.325252 | controller | ok: Runtime: 0:00:00.003464
2025-12-27 00:24:55.340117 | 
2025-12-27 00:24:55.340277 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-27 00:24:55.379910 | controller | skipping: Conditional result was False
2025-12-27 00:24:55.380535 | controller | ok: All items complete
2025-12-27 00:24:55.380606 | 
2025-12-27 00:24:55.418313 | 
2025-12-27 00:24:55.418526 | TASK [Find the full path of the Python interpreter]
2025-12-27 00:24:55.649487 | controller | /usr/bin/python3
2025-12-27 00:24:55.972062 | controller | ok
2025-12-27 00:24:55.985059 | 
2025-12-27 00:24:55.985212 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-27 00:24:56.809533 | controller | created virtual environment CPython3.11.0.final.0-64 in 448ms
2025-12-27 00:24:56.825864 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-27 00:24:56.825904 | 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-27 00:24:56.825914 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-27 00:24:56.825930 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-27 00:24:57.047047 | controller | changed
2025-12-27 00:24:57.061276 | 
2025-12-27 00:24:57.061467 | TASK [Set selinux package]
2025-12-27 00:24:57.104853 | controller | ok
2025-12-27 00:24:57.116958 | 
2025-12-27 00:24:57.117106 | TASK [Set selinux package (Fedora)]
2025-12-27 00:24:57.175074 | controller | ok
2025-12-27 00:24:57.183546 | 
2025-12-27 00:24:57.183714 | TASK [Install selinux into virtualenv]
2025-12-27 00:25:34.626065 | controller | Collecting selinux-please-lie-to-me
2025-12-27 00:25:46.869629 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-27 00:25:47.182977 | controller | Collecting setuptools<50.0.0
2025-12-27 00:25:47.188775 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-27 00:25:47.240429 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 17.5 MB/s eta 0:00:00
2025-12-27 00:25:47.324122 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-27 00:25:47.324368 | controller |   Attempting uninstall: setuptools
2025-12-27 00:25:47.326838 | controller |     Found existing installation: setuptools 62.6.0
2025-12-27 00:25:47.386260 | controller |     Uninstalling setuptools-62.6.0:
2025-12-27 00:25:47.394338 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-27 00:25:47.741144 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-27 00:26:07.900972 | controller |
2025-12-27 00:26:07.983448 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-27 00:26:07.983492 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-27 00:26:08.283379 | controller | ok: Runtime: 0:01:10.567964
2025-12-27 00:26:08.297445 | 
2025-12-27 00:26:08.297594 | TASK [Install pytest-forked into virtualenv]
2025-12-27 00:26:18.207403 | controller | Collecting pytest-forked
2025-12-27 00:26:30.451798 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-27 00:26:30.499223 | controller | Collecting py
2025-12-27 00:26:30.503905 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-27 00:26:30.529742 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.2 MB/s eta 0:00:00
2025-12-27 00:26:30.645987 | controller | Collecting pytest>=3.10
2025-12-27 00:26:30.650911 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-27 00:26:30.665329 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 33.4 MB/s eta 0:00:00
2025-12-27 00:26:30.705178 | controller | Collecting iniconfig>=1.0.1
2025-12-27 00:26:30.708876 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-27 00:26:30.752610 | controller | Collecting packaging>=22
2025-12-27 00:26:30.758050 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-27 00:26:30.767048 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.8 MB/s eta 0:00:00
2025-12-27 00:26:30.804094 | controller | Collecting pluggy<2,>=1.5
2025-12-27 00:26:30.810719 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-27 00:26:30.867414 | controller | Collecting pygments>=2.7.2
2025-12-27 00:26:30.873045 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-27 00:26:30.892547 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 69.9 MB/s eta 0:00:00
2025-12-27 00:26:30.963778 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-27 00:26:32.044434 | 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-27 00:26:32.053456 | controller |
2025-12-27 00:26:32.130905 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-27 00:26:32.130953 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-27 00:26:32.362442 | controller | ok: Runtime: 0:00:23.586617
2025-12-27 00:26:32.376721 | 
2025-12-27 00:26:32.376914 | TASK [Update pip]
2025-12-27 00:26:32.918839 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-27 00:26:42.837006 | controller | Collecting pip
2025-12-27 00:26:55.030290 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-27 00:26:55.122289 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 20.5 MB/s eta 0:00:00
2025-12-27 00:26:55.188007 | controller | Installing collected packages: pip
2025-12-27 00:26:55.188252 | controller |   Attempting uninstall: pip
2025-12-27 00:26:55.190510 | controller |     Found existing installation: pip 22.2.2
2025-12-27 00:26:55.335954 | controller |     Uninstalling pip-22.2.2:
2025-12-27 00:26:55.351538 | controller |       Successfully uninstalled pip-22.2.2
2025-12-27 00:26:56.183727 | controller | Successfully installed pip-25.3
2025-12-27 00:26:56.450384 | controller | ok: Runtime: 0:00:23.635353
2025-12-27 00:26:56.465546 | 
2025-12-27 00:26:56.465811 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-27 00:26:56.723379 | controller | changed
2025-12-27 00:26:56.736494 | 
2025-12-27 00:26:56.736754 | TASK [Install ansible into virtualenv]
2025-12-27 00:26:57.269027 | controller | Processing ./src/github.com/ansible/ansible
2025-12-27 00:26:57.272377 | controller |   Installing build dependencies: started
2025-12-27 00:27:29.906862 | controller |   Installing build dependencies: finished with status 'done'
2025-12-27 00:27:29.907562 | controller |   Getting requirements to build wheel: started
2025-12-27 00:27:30.659919 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-27 00:27:30.661299 | controller |   Preparing metadata (pyproject.toml): started
2025-12-27 00:27:31.157860 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-27 00:27:31.160531 | 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-27 00:27:31.163121 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-27 00:27:31.308871 | controller | ERROR
2025-12-27 00:27:31.309143 | controller | {
2025-12-27 00:27:31.309174 | controller |   "delta": "0:00:34.238730",
2025-12-27 00:27:31.309198 | controller |   "end": "2025-12-27 00:27:31.225962",
2025-12-27 00:27:31.309222 | controller |   "msg": "non-zero return code",
2025-12-27 00:27:31.309255 | controller |   "rc": 1,
2025-12-27 00:27:31.309275 | controller |   "start": "2025-12-27 00:26:56.987232"
2025-12-27 00:27:31.309293 | controller | }
failure
2025-12-27 00:27:31.311136 | 
2025-12-27 00:27:31.311231 | PLAY RECAP
2025-12-27 00:27:31.311276 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-27 00:27:31.311294 | 
2025-12-27 00:27:31.427845 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-27 00:27:31.429225 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-27 00:27:32.049510 | 
2025-12-27 00:27:32.049872 | PLAY [all]
2025-12-27 00:27:32.071505 | 
2025-12-27 00:27:32.071593 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-27 00:27:32.326785 | controller | changed: non-zero return code
2025-12-27 00:27:32.333005 | 
2025-12-27 00:27:32.333082 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-27 00:27:32.359122 | controller | skipping: Conditional result was False
2025-12-27 00:27:32.366106 | 
2025-12-27 00:27:32.366185 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-27 00:27:32.410448 | 
2025-12-27 00:27:32.410842 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-27 00:27:32.455385 | 
2025-12-27 00:27:32.455839 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-27 00:27:32.474539 | controller | skipping: Conditional result was False
2025-12-27 00:27:32.494615 | 
2025-12-27 00:27:32.494823 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-27 00:27:32.523604 | 
2025-12-27 00:27:32.524067 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-27 00:27:32.540711 | controller | skipping: Conditional result was False
2025-12-27 00:27:32.551151 | 
2025-12-27 00:27:32.551252 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-27 00:27:32.567925 | controller | skipping: Conditional result was False
2025-12-27 00:27:32.578081 | 
2025-12-27 00:27:32.578181 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-27 00:27:32.594024 | controller | skipping: Conditional result was False
2025-12-27 00:27:32.632432 | 
2025-12-27 00:27:32.632573 | PLAY RECAP
2025-12-27 00:27:32.632621 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-27 00:27:32.632641 | 
2025-12-27 00:27:32.785886 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-27 00:27:32.788001 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-27 00:27:33.343367 | 
2025-12-27 00:27:33.343528 | PLAY [all:!appliance*]
2025-12-27 00:27:33.365872 | 
2025-12-27 00:27:33.366040 | TASK [unregister the node]
2025-12-27 00:27:33.897116 | controller | skipping: Conditional result was False
2025-12-27 00:27:33.909606 | 
2025-12-27 00:27:33.909809 | TASK [include_role : fetch-output]
2025-12-27 00:27:33.961288 | controller | ok
2025-12-27 00:27:33.995307 | 
2025-12-27 00:27:33.995463 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-27 00:27:34.072745 | controller | skipping: Conditional result was False
2025-12-27 00:27:34.081799 | 
2025-12-27 00:27:34.081900 | TASK [fetch-output : Set log path for single node]
2025-12-27 00:27:34.128035 | controller | ok
2025-12-27 00:27:34.136989 | 
2025-12-27 00:27:34.137096 | LOOP [fetch-output : Ensure local output dirs]
2025-12-27 00:27:34.612262 | controller -> localhost | ok: "/var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/logs"
2025-12-27 00:27:34.835454 | controller -> localhost | changed: "/var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/artifacts"
2025-12-27 00:27:35.097787 | controller -> localhost | changed: "/var/lib/zuul/builds/13462208ccb1421e80ae5eb856f3642b/work/docs"
2025-12-27 00:27:35.124192 | 
2025-12-27 00:27:35.124548 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-27 00:27:35.860914 | controller | changed:
2025-12-27 00:27:35.861436 | controller | .d..t...... ./
2025-12-27 00:27:35.861513 | controller | cd+++++++++ controller/
2025-12-27 00:27:35.861604 | controller | changed: All items complete
2025-12-27 00:27:35.861693 | 
2025-12-27 00:27:36.438295 | controller | changed: .d..t...... ./
2025-12-27 00:27:36.908119 | controller | changed: .d..t...... ./
2025-12-27 00:27:36.940604 | 
2025-12-27 00:27:36.940788 | TASK [include_role : fetch-output-openshift]
2025-12-27 00:27:36.968621 | controller | skipping: Conditional result was False
2025-12-27 00:27:36.977860 | 
2025-12-27 00:27:36.977964 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-27 00:27:37.012620 | controller | skipping: Conditional result was False
2025-12-27 00:27:37.025044 | controller | skipping: Conditional result was False
2025-12-27 00:27:37.073402 | 
2025-12-27 00:27:37.073530 | PLAY [localhost]
2025-12-27 00:27:37.090585 | 
2025-12-27 00:27:37.090763 | TASK [Run Zuul manifest role]
2025-12-27 00:27:37.121973 | localhost | ok
2025-12-27 00:27:37.142258 | 
2025-12-27 00:27:37.142378 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-27 00:27:37.587283 | localhost | changed
2025-12-27 00:27:37.598020 | 
2025-12-27 00:27:37.598203 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-27 00:27:37.646239 | localhost | ok
2025-12-27 00:27:37.666119 | 
2025-12-27 00:27:37.666258 | TASK [Set zuul-log-path fact]
2025-12-27 00:27:37.703243 | localhost | ok
2025-12-27 00:27:37.732137 | 
2025-12-27 00:27:37.732235 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-27 00:27:37.774894 | localhost | ok
2025-12-27 00:27:37.786358 | 
2025-12-27 00:27:37.786438 | LOOP [Run upload-logs-swift role]
2025-12-27 00:27:37.842424 | localhost | Output suppressed because no_log was given
2025-12-27 00:27:37.877158 | 
2025-12-27 00:27:37.877256 | TASK [Set zuul-log-path fact]
2025-12-27 00:27:37.913020 | localhost | skipping: Conditional result was False
2025-12-27 00:27:37.920402 | 
2025-12-27 00:27:37.920488 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-27 00:27:38.435654 | localhost -> localhost | ok: Runtime: 0:00:00.006130
2025-12-27 00:27:38.490850 | 
2025-12-27 00:27:38.491025 | TASK [upload-logs-swift : Upload logs to swift]