2025-10-28 00:12:20.989946 | Job console starting...
2025-10-28 00:12:21.001406 | Updating repositories
2025-10-28 00:12:21.162479 | Preparing job workspace
2025-10-28 00:12:24.976465 | Running Ansible setup...
2025-10-28 00:12:32.401801 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-28 00:12:33.017376 | 
2025-10-28 00:12:33.017531 | PLAY [localhost]
2025-10-28 00:12:33.027119 | 
2025-10-28 00:12:33.027268 | TASK [Gathering Facts]
2025-10-28 00:12:34.057921 | localhost | ok
2025-10-28 00:12:34.075565 | 
2025-10-28 00:12:34.075742 | TASK [Setup log path fact]
2025-10-28 00:12:34.096401 | localhost | ok
2025-10-28 00:12:34.112833 | 
2025-10-28 00:12:34.113007 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-28 00:12:34.143397 | localhost | ok
2025-10-28 00:12:34.153137 | 
2025-10-28 00:12:34.153291 | TASK [emit-job-header : Print job information]
2025-10-28 00:12:34.193428 | # Job Information
2025-10-28 00:12:34.193746 | Ansible Version: 2.15.12
2025-10-28 00:12:34.193799 | Job: ansible-test-sanity-docker-milestone
2025-10-28 00:12:34.193832 | Pipeline: periodic
2025-10-28 00:12:34.193860 | Executor: ze01.softwarefactory-project.io
2025-10-28 00:12:34.193880 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-28 00:12:34.193902 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b7a/ansible/b7a3306129df4a7e858ee19165e867cd/
2025-10-28 00:12:34.193923 | Event ID: 46587db61ba7453d8a762a51c1f23ac3
2025-10-28 00:12:34.197961 | 
2025-10-28 00:12:34.198052 | LOOP [emit-job-header : Print node information]
2025-10-28 00:12:34.309617 | localhost | ok:
2025-10-28 00:12:34.309795 | localhost | # Node Information
2025-10-28 00:12:34.309822 | localhost | Inventory Hostname: controller
2025-10-28 00:12:34.309841 | localhost | Hostname: np0005504205
2025-10-28 00:12:34.309860 | localhost | Username: zuul
2025-10-28 00:12:34.309881 | localhost | Distro: Fedora 37
2025-10-28 00:12:34.309899 | localhost | Provider: ansible-vexxhost-ams1
2025-10-28 00:12:34.309916 | localhost | Region: ams1
2025-10-28 00:12:34.309932 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-28 00:12:34.309948 | localhost | Product Name: OpenStack Nova
2025-10-28 00:12:34.309964 | localhost | Interface IP: 38.129.16.228
2025-10-28 00:12:34.325760 | 
2025-10-28 00:12:34.325960 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-28 00:12:34.856862 | localhost -> localhost | changed
2025-10-28 00:12:34.862692 | 
2025-10-28 00:12:34.862794 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-28 00:12:35.794213 | localhost -> localhost | changed
2025-10-28 00:12:35.835485 | 
2025-10-28 00:12:35.835610 | PLAY [all:!appliance*]
2025-10-28 00:12:35.865001 | 
2025-10-28 00:12:35.865165 | TASK [include_role : start-zuul-console]
2025-10-28 00:12:35.885063 | controller | ok
2025-10-28 00:12:35.900559 | 
2025-10-28 00:12:35.900686 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-28 00:12:36.934638 | controller | ok
2025-10-28 00:12:36.958357 | 
2025-10-28 00:12:36.958558 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-28 00:12:39.184500 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-28 00:12:39.191964 | 
2025-10-28 00:12:39.192087 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-28 00:12:39.547895 | controller | skipping: Conditional result was False
2025-10-28 00:12:39.554893 | 
2025-10-28 00:12:39.554964 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-28 00:12:39.590494 | controller | skipping: Conditional result was False
2025-10-28 00:12:39.598138 | 
2025-10-28 00:12:39.598222 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-28 00:12:39.633264 | controller | skipping: Conditional result was False
2025-10-28 00:12:39.640678 | 
2025-10-28 00:12:39.640758 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-28 00:12:39.665810 | controller | skipping: Conditional result was False
2025-10-28 00:12:39.673008 | 
2025-10-28 00:12:39.673144 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-28 00:12:39.697499 | controller | skipping: Conditional result was False
2025-10-28 00:12:39.705068 | 
2025-10-28 00:12:39.705191 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-28 00:12:39.730198 | controller | skipping: Conditional result was False
2025-10-28 00:12:39.741916 | 
2025-10-28 00:12:39.742087 | TASK [Disable Fedora Modular]
2025-10-28 00:12:40.766917 | controller | changed
2025-10-28 00:12:40.773280 | 
2025-10-28 00:12:40.773352 | TASK [Enable EPEL]
2025-10-28 00:12:40.799782 | controller | skipping: Conditional result was False
2025-10-28 00:12:40.806620 | 
2025-10-28 00:12:40.806694 | TASK [Register the RHEL node]
2025-10-28 00:12:41.216684 | 
2025-10-28 00:12:41.216937 | TASK [Show the subscription-manager status]
2025-10-28 00:12:41.601525 | controller | skipping: Conditional result was False
2025-10-28 00:12:41.609270 | 
2025-10-28 00:12:41.609393 | TASK [Enable EPEL on RHEL]
2025-10-28 00:12:41.974150 | controller | skipping: Conditional result was False
2025-10-28 00:12:41.983988 | 
2025-10-28 00:12:41.984184 | TASK [Install git and tox]
2025-10-28 00:14:31.209843 | controller | changed
2025-10-28 00:14:31.227614 | 
2025-10-28 00:14:31.227840 | TASK [include_role : prepare-workspace]
2025-10-28 00:14:31.255121 | controller | ok
2025-10-28 00:14:31.291877 | 
2025-10-28 00:14:31.292103 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-28 00:14:32.078212 | controller | ok
2025-10-28 00:14:32.088822 | 
2025-10-28 00:14:32.089032 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-28 00:14:47.904107 | controller | Output suppressed because no_log was given
2025-10-28 00:14:47.916182 | 
2025-10-28 00:14:47.916326 | TASK [include_role : prepare-workspace-openshift]
2025-10-28 00:14:47.946042 | controller | skipping: Conditional result was False
2025-10-28 00:14:47.975918 | 
2025-10-28 00:14:47.976060 | PLAY [all:!appliance]
2025-10-28 00:14:48.001963 | 
2025-10-28 00:14:48.002153 | TASK [Run add-build-sshkey role (RSA)]
2025-10-28 00:14:48.035782 | controller | ok
2025-10-28 00:14:48.055995 | 
2025-10-28 00:14:48.056200 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-28 00:14:48.351717 | controller -> localhost | ok
2025-10-28 00:14:48.370637 | 
2025-10-28 00:14:48.370889 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-28 00:14:48.410739 | controller | ok
2025-10-28 00:14:48.437980 | controller | included: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-28 00:14:48.447114 | 
2025-10-28 00:14:48.447300 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-28 00:14:49.111076 | controller -> localhost | Generating public/private rsa key pair.
2025-10-28 00:14:49.111375 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/b7a3306129df4a7e858ee19165e867cd_id_rsa.
2025-10-28 00:14:49.111413 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/b7a3306129df4a7e858ee19165e867cd_id_rsa.pub.
2025-10-28 00:14:49.111439 | controller -> localhost | The key fingerprint is:
2025-10-28 00:14:49.111467 | controller -> localhost | SHA256:pK/5PUnO6sGfrU9F89MGHWRaxH5ByRGz2ybJyjdHEVg zuul-build-sshkey
2025-10-28 00:14:49.111495 | controller -> localhost | The key's randomart image is:
2025-10-28 00:14:49.111518 | controller -> localhost | +---[RSA 2048]----+
2025-10-28 00:14:49.111540 | controller -> localhost | |              OE+|
2025-10-28 00:14:49.111566 | controller -> localhost | |             .+*=|
2025-10-28 00:14:49.111591 | controller -> localhost | |        .    .=oo|
2025-10-28 00:14:49.111617 | controller -> localhost | |       o     o **|
2025-10-28 00:14:49.111641 | controller -> localhost | |      . S     =oO|
2025-10-28 00:14:49.111682 | controller -> localhost | |       o  .. o =.|
2025-10-28 00:14:49.111714 | controller -> localhost | |        ++ .+ o .|
2025-10-28 00:14:49.111737 | controller -> localhost | |       o +=+ . o |
2025-10-28 00:14:49.111762 | controller -> localhost | |      oo+.=+o    |
2025-10-28 00:14:49.111793 | controller -> localhost | +----[SHA256]-----+
2025-10-28 00:14:49.111873 | controller -> localhost | ok: Runtime: 0:00:00.235518
2025-10-28 00:14:49.122548 | 
2025-10-28 00:14:49.122667 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-28 00:14:49.159547 | controller | ok
2025-10-28 00:14:49.174956 | controller | included: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-28 00:14:49.189791 | 
2025-10-28 00:14:49.189957 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-28 00:14:49.215336 | controller | skipping: Conditional result was False
2025-10-28 00:14:49.224280 | 
2025-10-28 00:14:49.224401 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-28 00:14:50.274549 | controller | changed
2025-10-28 00:14:50.281582 | 
2025-10-28 00:14:50.281671 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-28 00:14:50.899842 | controller | ok
2025-10-28 00:14:50.906415 | 
2025-10-28 00:14:50.906500 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-28 00:14:53.842511 | controller | changed
2025-10-28 00:14:53.855529 | 
2025-10-28 00:14:53.855675 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-28 00:14:56.782716 | controller | changed
2025-10-28 00:14:56.791529 | 
2025-10-28 00:14:56.791678 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-28 00:14:56.829977 | controller | skipping: Conditional result was False
2025-10-28 00:14:56.839793 | 
2025-10-28 00:14:56.839961 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-28 00:14:57.320547 | controller -> localhost | changed
2025-10-28 00:14:57.334331 | 
2025-10-28 00:14:57.334473 | TASK [add-build-sshkey : Add back temp key]
2025-10-28 00:14:57.668796 | controller -> localhost | Identity added: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/b7a3306129df4a7e858ee19165e867cd_id_rsa (zuul-build-sshkey)
2025-10-28 00:14:57.669280 | controller -> localhost | ok: Runtime: 0:00:00.016230
2025-10-28 00:14:57.683412 | 
2025-10-28 00:14:57.683629 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-28 00:14:58.604566 | controller | ok
2025-10-28 00:14:58.614759 | 
2025-10-28 00:14:58.614956 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-28 00:14:58.641630 | controller | skipping: Conditional result was False
2025-10-28 00:14:58.661468 | 
2025-10-28 00:14:58.661659 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-28 00:14:58.698175 | controller | ok
2025-10-28 00:14:58.731573 | 
2025-10-28 00:14:58.731790 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-28 00:14:59.065761 | controller -> localhost | ok
2025-10-28 00:14:59.077076 | 
2025-10-28 00:14:59.077193 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-28 00:14:59.120844 | controller | ok
2025-10-28 00:14:59.141218 | controller | included: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-28 00:14:59.152415 | 
2025-10-28 00:14:59.152537 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-28 00:14:59.488058 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-28 00:14:59.488465 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/b7a3306129df4a7e858ee19165e867cd_id_ecdsa.
2025-10-28 00:14:59.488509 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/b7a3306129df4a7e858ee19165e867cd_id_ecdsa.pub.
2025-10-28 00:14:59.488548 | controller -> localhost | The key fingerprint is:
2025-10-28 00:14:59.488574 | controller -> localhost | SHA256:7g1nBikX2inGXXZUVrlLGGg0Cbpla1HqQ12qN8H1BPc zuul-build-sshkey
2025-10-28 00:14:59.488597 | controller -> localhost | The key's randomart image is:
2025-10-28 00:14:59.488620 | controller -> localhost | +---[ECDSA 521]---+
2025-10-28 00:14:59.488643 | controller -> localhost | |         .o++=++o|
2025-10-28 00:14:59.488666 | controller -> localhost | |        . ===o+..|
2025-10-28 00:14:59.488687 | controller -> localhost | |       ..*+=. o.E|
2025-10-28 00:14:59.488714 | controller -> localhost | |     . +**+... o |
2025-10-28 00:14:59.488743 | controller -> localhost | |      *.S* o  . .|
2025-10-28 00:14:59.488770 | controller -> localhost | |     . =..o .  . |
2025-10-28 00:14:59.488794 | controller -> localhost | |        o +      |
2025-10-28 00:14:59.488816 | controller -> localhost | |       . *       |
2025-10-28 00:14:59.488837 | controller -> localhost | |        . .      |
2025-10-28 00:14:59.488859 | controller -> localhost | +----[SHA256]-----+
2025-10-28 00:14:59.488937 | controller -> localhost | ok: Runtime: 0:00:00.015741
2025-10-28 00:14:59.497208 | 
2025-10-28 00:14:59.497347 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-28 00:14:59.529828 | controller | ok
2025-10-28 00:14:59.538837 | controller | included: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-28 00:14:59.549322 | 
2025-10-28 00:14:59.549468 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-28 00:14:59.584825 | controller | skipping: Conditional result was False
2025-10-28 00:14:59.595789 | 
2025-10-28 00:14:59.595958 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-28 00:15:00.482485 | controller | changed
2025-10-28 00:15:00.502683 | 
2025-10-28 00:15:00.502944 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-28 00:15:01.149153 | controller | ok
2025-10-28 00:15:01.164405 | 
2025-10-28 00:15:01.164576 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-28 00:15:04.098785 | controller | changed
2025-10-28 00:15:04.105765 | 
2025-10-28 00:15:04.105879 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-28 00:15:07.024509 | controller | changed
2025-10-28 00:15:07.031982 | 
2025-10-28 00:15:07.032220 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-28 00:15:07.068023 | controller | skipping: Conditional result was False
2025-10-28 00:15:07.075588 | 
2025-10-28 00:15:07.075709 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-28 00:15:07.362742 | controller -> localhost | changed
2025-10-28 00:15:07.380939 | 
2025-10-28 00:15:07.381187 | TASK [add-build-sshkey : Add back temp key]
2025-10-28 00:15:07.729904 | controller -> localhost | Identity added: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/b7a3306129df4a7e858ee19165e867cd_id_ecdsa (zuul-build-sshkey)
2025-10-28 00:15:07.730266 | controller -> localhost | ok: Runtime: 0:00:00.009539
2025-10-28 00:15:07.737539 | 
2025-10-28 00:15:07.737612 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-28 00:15:08.418125 | controller | ok
2025-10-28 00:15:08.432817 | 
2025-10-28 00:15:08.433609 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-28 00:15:08.465381 | controller | skipping: Conditional result was False
2025-10-28 00:15:08.494780 | 
2025-10-28 00:15:08.494951 | TASK [include_role : remove-zuul-sshkey]
2025-10-28 00:15:08.521301 | controller | skipping: Conditional result was False
2025-10-28 00:15:08.532618 | 
2025-10-28 00:15:08.532823 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-28 00:15:09.166271 | controller | ok: "logs"
2025-10-28 00:15:09.166687 | controller | ok: All items complete
2025-10-28 00:15:09.166729 | 
2025-10-28 00:15:09.765224 | controller | ok: "artifacts"
2025-10-28 00:15:10.347639 | controller | ok: "docs"
2025-10-28 00:15:10.365153 | 
2025-10-28 00:15:10.365313 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-28 00:15:10.980093 | controller | changed: "logs"
2025-10-28 00:15:11.561976 | controller | changed: "artifacts"
2025-10-28 00:15:12.146619 | controller | changed: "docs"
2025-10-28 00:15:12.203937 | 
2025-10-28 00:15:12.204153 | PLAY RECAP
2025-10-28 00:15:12.204226 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-28 00:15:12.204264 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-28 00:15:12.204290 | 
2025-10-28 00:15:12.384980 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-28 00:15:12.386823 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-28 00:15:13.022612 | 
2025-10-28 00:15:13.022765 | PLAY [all]
2025-10-28 00:15:13.046758 | 
2025-10-28 00:15:13.046931 | TASK [Install binary dependencies]
2025-10-28 00:15:13.101095 | controller | ok
2025-10-28 00:15:13.121075 | 
2025-10-28 00:15:13.121185 | TASK [bindep : Include find tasks]
2025-10-28 00:15:13.153918 | controller | ok
2025-10-28 00:15:13.165950 | controller | included: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-28 00:15:13.175795 | 
2025-10-28 00:15:13.175879 | TASK [bindep : Look for bindep.txt]
2025-10-28 00:15:14.100616 | controller | ok
2025-10-28 00:15:14.109591 | 
2025-10-28 00:15:14.109766 | TASK [bindep : Define bindep_file fact]
2025-10-28 00:15:14.127218 | controller | skipping: Conditional result was False
2025-10-28 00:15:14.136937 | 
2025-10-28 00:15:14.137122 | TASK [bindep : Look for other-requirements.txt]
2025-10-28 00:15:14.722924 | controller | ok
2025-10-28 00:15:14.730793 | 
2025-10-28 00:15:14.730920 | TASK [bindep : Define bindep_file fact]
2025-10-28 00:15:14.779379 | controller | skipping: Conditional result was False
2025-10-28 00:15:14.788925 | 
2025-10-28 00:15:14.789136 | TASK [bindep : Look for bindep fallback file]
2025-10-28 00:15:14.825854 | controller | skipping: Conditional result was False
2025-10-28 00:15:14.834848 | 
2025-10-28 00:15:14.835005 | TASK [bindep : Define bindep_file fact]
2025-10-28 00:15:14.860571 | controller | skipping: Conditional result was False
2025-10-28 00:15:14.870051 | 
2025-10-28 00:15:14.870192 | TASK [bindep : Include bindep tasks]
2025-10-28 00:15:14.907293 | controller | skipping: Conditional result was False
2025-10-28 00:15:14.914225 | 
2025-10-28 00:15:14.914333 | TASK [bindep : Include install tasks]
2025-10-28 00:15:14.949975 | controller | skipping: Conditional result was False
2025-10-28 00:15:14.959369 | 
2025-10-28 00:15:14.959533 | LOOP [bindep : Include package tasks]
2025-10-28 00:15:15.034873 | 
2025-10-28 00:15:15.035121 | TASK [Run test-setup role]
2025-10-28 00:15:15.056692 | controller | ok
2025-10-28 00:15:15.078102 | 
2025-10-28 00:15:15.078291 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-28 00:15:15.764833 | controller | ok
2025-10-28 00:15:15.773904 | 
2025-10-28 00:15:15.774058 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-28 00:15:16.137154 | controller | skipping: Conditional result was False
2025-10-28 00:15:16.169172 | 
2025-10-28 00:15:16.169325 | PLAY RECAP
2025-10-28 00:15:16.169375 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-28 00:15:16.169397 | 
2025-10-28 00:15:16.350496 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-28 00:15:16.351480 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-28 00:15:17.037171 | 
2025-10-28 00:15:17.037373 | PLAY [controller]
2025-10-28 00:15:17.061546 | 
2025-10-28 00:15:17.061731 | TASK [Create the /root directory]
2025-10-28 00:15:18.375680 | controller | ok
2025-10-28 00:15:18.385301 | 
2025-10-28 00:15:18.385425 | TASK [Install glibc-langpack-en]
2025-10-28 00:15:25.552056 | controller | ok: Nothing to do
2025-10-28 00:15:25.563916 | 
2025-10-28 00:15:25.564107 | TASK [Ensure controller directory exists]
2025-10-28 00:15:26.363768 | controller | changed
2025-10-28 00:15:26.373158 | 
2025-10-28 00:15:26.373308 | TASK [Install container runtime]
2025-10-28 00:15:26.431832 | controller | ok
2025-10-28 00:15:26.483158 | 
2025-10-28 00:15:26.483302 | LOOP [ensure-podman : Find distribution installation]
2025-10-28 00:15:26.507799 | controller | ok: "/var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-28 00:15:26.519834 | controller | included: /var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-28 00:15:26.529704 | 
2025-10-28 00:15:26.529809 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-28 00:17:13.717736 | controller | changed
2025-10-28 00:17:13.731210 | 
2025-10-28 00:17:13.731391 | TASK [ensure-podman : Fetch podman version]
2025-10-28 00:17:14.850093 | controller | Client:       Podman Engine
2025-10-28 00:17:14.850193 | controller | Version:      4.6.2
2025-10-28 00:17:14.850239 | controller | API Version:  4.6.2
2025-10-28 00:17:14.850281 | controller | Go Version:   go1.19.12
2025-10-28 00:17:14.850539 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-28 00:17:14.850585 | controller | OS/Arch:      linux/amd64
2025-10-28 00:17:15.104560 | controller | ok: Runtime: 0:00:00.243294
2025-10-28 00:17:15.110995 | 
2025-10-28 00:17:15.111096 | TASK [ensure-podman : Print podman version installed]
2025-10-28 00:17:15.141235 | Podman version: Client:       Podman Engine
2025-10-28 00:17:15.141404 | Version:      4.6.2
2025-10-28 00:17:15.141434 | API Version:  4.6.2
2025-10-28 00:17:15.141455 | Go Version:   go1.19.12
2025-10-28 00:17:15.141474 | Built:        Mon Aug 28 19:38:31 2023
2025-10-28 00:17:15.141494 | OS/Arch:      linux/amd64
2025-10-28 00:17:15.147298 | 
2025-10-28 00:17:15.147375 | TASK [ensure-podman : Validate podman engine]
2025-10-28 00:17:15.499508 | controller | skipping: Conditional result was False
2025-10-28 00:17:15.507078 | 
2025-10-28 00:17:15.507238 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-28 00:17:15.521939 | controller | skipping: Conditional result was False
2025-10-28 00:17:15.535420 | 
2025-10-28 00:17:15.535582 | TASK [Ensure python3.8 is present]
2025-10-28 00:17:15.550690 | controller | skipping: Conditional result was False
2025-10-28 00:17:15.558755 | 
2025-10-28 00:17:15.558911 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-28 00:17:15.581225 | controller | ok
2025-10-28 00:17:15.603248 | 
2025-10-28 00:17:15.603380 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-28 00:17:18.600683 | controller | ok: Nothing to do
2025-10-28 00:17:18.613798 | 
2025-10-28 00:17:18.613952 | TASK [our-ensure-python : Also install python3-devel]
2025-10-28 00:17:31.896262 | controller | changed
2025-10-28 00:17:31.940367 | 
2025-10-28 00:17:31.940559 | TASK [Run ensure-virtualenv role]
2025-10-28 00:17:31.963820 | controller | ok
2025-10-28 00:17:31.993870 | 
2025-10-28 00:17:31.994043 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-28 00:17:32.716364 | controller | /usr/bin/virtualenv
2025-10-28 00:17:32.852572 | controller | ok: Runtime: 0:00:00.005424
2025-10-28 00:17:32.866521 | 
2025-10-28 00:17:32.866708 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-28 00:17:32.894903 | controller | skipping: Conditional result was False
2025-10-28 00:17:32.895255 | controller | ok: All items complete
2025-10-28 00:17:32.895294 | 
2025-10-28 00:17:32.918308 | 
2025-10-28 00:17:32.918436 | TASK [Find the full path of the Python interpreter]
2025-10-28 00:17:33.532356 | controller | /usr/bin/python3
2025-10-28 00:17:33.811382 | controller | ok
2025-10-28 00:17:33.820266 | 
2025-10-28 00:17:33.820409 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-28 00:17:35.412294 | controller | created virtual environment CPython3.11.0.final.0-64 in 804ms
2025-10-28 00:17:35.458974 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-28 00:17:35.459000 | 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-10-28 00:17:35.459024 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-28 00:17:35.459042 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-28 00:17:35.691819 | controller | changed
2025-10-28 00:17:35.701246 | 
2025-10-28 00:17:35.701405 | TASK [Set selinux package]
2025-10-28 00:17:35.735306 | controller | ok
2025-10-28 00:17:35.743466 | 
2025-10-28 00:17:35.743626 | TASK [Set selinux package (Fedora)]
2025-10-28 00:17:35.775603 | controller | ok
2025-10-28 00:17:35.782111 | 
2025-10-28 00:17:35.782273 | TASK [Install selinux into virtualenv]
2025-10-28 00:17:38.202116 | controller | Collecting selinux-please-lie-to-me
2025-10-28 00:17:38.257911 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-28 00:17:38.698033 | controller | Collecting setuptools<50.0.0
2025-10-28 00:17:38.703127 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-28 00:17:38.768999 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 12.9 MB/s eta 0:00:00
2025-10-28 00:17:38.902616 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-28 00:17:38.902939 | controller |   Attempting uninstall: setuptools
2025-10-28 00:17:38.906525 | controller |     Found existing installation: setuptools 62.6.0
2025-10-28 00:17:38.997950 | controller |     Uninstalling setuptools-62.6.0:
2025-10-28 00:17:39.010373 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-28 00:17:39.626838 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-28 00:17:39.840622 | controller |
2025-10-28 00:17:40.065005 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-10-28 00:17:40.065058 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-28 00:17:40.667521 | controller | ok: Runtime: 0:00:03.538940
2025-10-28 00:17:40.680982 | 
2025-10-28 00:17:40.681175 | TASK [Install pytest-forked into virtualenv]
2025-10-28 00:17:42.021988 | controller | Collecting pytest-forked
2025-10-28 00:17:42.075741 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-28 00:17:42.129162 | controller | Collecting py
2025-10-28 00:17:42.133576 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-28 00:17:42.164276 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.2 MB/s eta 0:00:00
2025-10-28 00:17:42.309990 | controller | Collecting pytest>=3.10
2025-10-28 00:17:42.314153 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-28 00:17:42.335564 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 19.9 MB/s eta 0:00:00
2025-10-28 00:17:42.381656 | controller | Collecting iniconfig>=1
2025-10-28 00:17:42.386175 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-10-28 00:17:42.447656 | controller | Collecting packaging>=20
2025-10-28 00:17:42.451465 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-28 00:17:42.460813 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.6 MB/s eta 0:00:00
2025-10-28 00:17:42.498113 | controller | Collecting pluggy<2,>=1.5
2025-10-28 00:17:42.501867 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-28 00:17:42.567208 | controller | Collecting pygments>=2.7.2
2025-10-28 00:17:42.571200 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-28 00:17:42.595374 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 57.8 MB/s eta 0:00:00
2025-10-28 00:17:42.692410 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-28 00:17:44.552661 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0
2025-10-28 00:17:44.571535 | controller |
2025-10-28 00:17:44.772622 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-10-28 00:17:44.772657 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-28 00:17:45.065181 | controller | ok: Runtime: 0:00:03.344775
2025-10-28 00:17:45.072208 | 
2025-10-28 00:17:45.072300 | TASK [Update pip]
2025-10-28 00:17:46.286834 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-28 00:17:46.531319 | controller | Collecting pip
2025-10-28 00:17:46.606107 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-10-28 00:17:46.679359 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 26.1 MB/s eta 0:00:00
2025-10-28 00:17:46.819042 | controller | Installing collected packages: pip
2025-10-28 00:17:46.819261 | controller |   Attempting uninstall: pip
2025-10-28 00:17:46.826778 | controller |     Found existing installation: pip 22.2.2
2025-10-28 00:17:47.117179 | controller |     Uninstalling pip-22.2.2:
2025-10-28 00:17:47.141059 | controller |       Successfully uninstalled pip-22.2.2
2025-10-28 00:17:48.822909 | controller | Successfully installed pip-25.3
2025-10-28 00:17:49.450487 | controller | ok: Runtime: 0:00:03.264633
2025-10-28 00:17:49.459560 | 
2025-10-28 00:17:49.459685 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-28 00:17:50.295695 | controller | changed
2025-10-28 00:17:50.305259 | 
2025-10-28 00:17:50.305404 | TASK [Install ansible into virtualenv]
2025-10-28 00:17:51.428518 | controller | Processing ./src/github.com/ansible/ansible
2025-10-28 00:17:51.433276 | controller |   Installing build dependencies: started
2025-10-28 00:17:53.138948 | controller |   Installing build dependencies: finished with status 'done'
2025-10-28 00:17:53.143341 | controller |   Getting requirements to build wheel: started
2025-10-28 00:17:54.458762 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-28 00:17:54.460078 | controller |   Preparing metadata (pyproject.toml): started
2025-10-28 00:17:55.214915 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-28 00:17:55.218832 | 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-10-28 00:17:55.222450 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-28 00:17:55.685790 | controller | ERROR
2025-10-28 00:17:55.686156 | controller | {
2025-10-28 00:17:55.686226 | controller |   "delta": "0:00:04.463324",
2025-10-28 00:17:55.686270 | controller |   "end": "2025-10-28 00:17:55.366990",
2025-10-28 00:17:55.686307 | controller |   "msg": "non-zero return code",
2025-10-28 00:17:55.686358 | controller |   "rc": 1,
2025-10-28 00:17:55.686428 | controller |   "start": "2025-10-28 00:17:50.903666"
2025-10-28 00:17:55.686465 | controller | }
failure
2025-10-28 00:17:55.688858 | 
2025-10-28 00:17:55.688947 | PLAY RECAP
2025-10-28 00:17:55.689070 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-28 00:17:55.689123 | 
2025-10-28 00:17:55.837481 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-28 00:17:55.839515 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-28 00:17:56.489965 | 
2025-10-28 00:17:56.490144 | PLAY [all]
2025-10-28 00:17:56.514617 | 
2025-10-28 00:17:56.514765 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-28 00:17:58.334444 | controller | changed: non-zero return code
2025-10-28 00:17:58.345729 | 
2025-10-28 00:17:58.346007 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-28 00:17:58.375607 | controller | skipping: Conditional result was False
2025-10-28 00:17:58.385571 | 
2025-10-28 00:17:58.385813 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-28 00:17:58.425751 | 
2025-10-28 00:17:58.426115 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-28 00:17:58.465654 | 
2025-10-28 00:17:58.465974 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-28 00:17:58.493050 | controller | skipping: Conditional result was False
2025-10-28 00:17:58.500948 | 
2025-10-28 00:17:58.501093 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-28 00:17:58.533350 | 
2025-10-28 00:17:58.533561 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-28 00:17:58.558608 | controller | skipping: Conditional result was False
2025-10-28 00:17:58.565042 | 
2025-10-28 00:17:58.565138 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-28 00:17:58.589542 | controller | skipping: Conditional result was False
2025-10-28 00:17:58.596262 | 
2025-10-28 00:17:58.596352 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-28 00:17:58.621206 | controller | skipping: Conditional result was False
2025-10-28 00:17:58.669066 | 
2025-10-28 00:17:58.669238 | PLAY RECAP
2025-10-28 00:17:58.669305 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-28 00:17:58.669345 | 
2025-10-28 00:17:58.799395 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-28 00:17:58.800603 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-28 00:17:59.506194 | 
2025-10-28 00:17:59.506343 | PLAY [all:!appliance*]
2025-10-28 00:17:59.531138 | 
2025-10-28 00:17:59.531306 | TASK [unregister the node]
2025-10-28 00:17:59.886668 | controller | skipping: Conditional result was False
2025-10-28 00:17:59.895928 | 
2025-10-28 00:17:59.896152 | TASK [include_role : fetch-output]
2025-10-28 00:17:59.930716 | controller | ok
2025-10-28 00:17:59.961296 | 
2025-10-28 00:17:59.961475 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-28 00:18:00.008994 | controller | skipping: Conditional result was False
2025-10-28 00:18:00.018892 | 
2025-10-28 00:18:00.019111 | TASK [fetch-output : Set log path for single node]
2025-10-28 00:18:00.054180 | controller | ok
2025-10-28 00:18:00.062908 | 
2025-10-28 00:18:00.063097 | LOOP [fetch-output : Ensure local output dirs]
2025-10-28 00:18:00.504552 | controller -> localhost | ok: "/var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/logs"
2025-10-28 00:18:00.784718 | controller -> localhost | changed: "/var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/artifacts"
2025-10-28 00:18:01.033713 | controller -> localhost | changed: "/var/lib/zuul/builds/b7a3306129df4a7e858ee19165e867cd/work/docs"
2025-10-28 00:18:01.047069 | 
2025-10-28 00:18:01.047238 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-28 00:18:03.304773 | controller | changed:
2025-10-28 00:18:03.305110 | controller | .d..t...... ./
2025-10-28 00:18:03.305151 | controller | cd+++++++++ controller/
2025-10-28 00:18:03.305205 | controller | changed: All items complete
2025-10-28 00:18:03.305236 | 
2025-10-28 00:18:05.382290 | controller | changed: .d..t...... ./
2025-10-28 00:18:07.483348 | controller | changed: .d..t...... ./
2025-10-28 00:18:07.503129 | 
2025-10-28 00:18:07.503280 | TASK [include_role : fetch-output-openshift]
2025-10-28 00:18:07.528539 | controller | skipping: Conditional result was False
2025-10-28 00:18:07.539190 | 
2025-10-28 00:18:07.539368 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-28 00:18:07.591805 | controller | skipping: Conditional result was False
2025-10-28 00:18:07.604095 | controller | skipping: Conditional result was False
2025-10-28 00:18:07.644573 | 
2025-10-28 00:18:07.644766 | PLAY [localhost]
2025-10-28 00:18:07.664130 | 
2025-10-28 00:18:07.664268 | TASK [Run Zuul manifest role]
2025-10-28 00:18:07.684734 | localhost | ok
2025-10-28 00:18:07.700818 | 
2025-10-28 00:18:07.700921 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-28 00:18:08.100461 | localhost | changed
2025-10-28 00:18:08.108750 | 
2025-10-28 00:18:08.108904 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-28 00:18:08.142575 | localhost | ok
2025-10-28 00:18:08.159350 | 
2025-10-28 00:18:08.159485 | TASK [Set zuul-log-path fact]
2025-10-28 00:18:08.221158 | localhost | ok
2025-10-28 00:18:08.236638 | 
2025-10-28 00:18:08.236915 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-28 00:18:08.265372 | localhost | ok
2025-10-28 00:18:08.274328 | 
2025-10-28 00:18:08.274456 | LOOP [Run upload-logs-swift role]
2025-10-28 00:18:08.309263 | localhost | Output suppressed because no_log was given
2025-10-28 00:18:08.344768 | 
2025-10-28 00:18:08.345034 | TASK [Set zuul-log-path fact]
2025-10-28 00:18:08.370816 | localhost | skipping: Conditional result was False
2025-10-28 00:18:08.377130 | 
2025-10-28 00:18:08.377275 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-28 00:18:08.800098 | localhost -> localhost | ok: Runtime: 0:00:00.005276
2025-10-28 00:18:08.805713 | 
2025-10-28 00:18:08.805794 | TASK [upload-logs-swift : Upload logs to swift]