2025-12-21 00:28:59.430780 | Job console starting...
2025-12-21 00:28:59.441845 | Updating repositories
2025-12-21 00:28:59.607980 | Preparing job workspace
2025-12-21 00:29:03.351765 | Running Ansible setup...
2025-12-21 00:29:08.168862 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-21 00:29:08.905921 | 
2025-12-21 00:29:08.906120 | PLAY [localhost]
2025-12-21 00:29:08.915481 | 
2025-12-21 00:29:08.915556 | TASK [Gathering Facts]
2025-12-21 00:29:10.022026 | localhost | ok
2025-12-21 00:29:10.044276 | 
2025-12-21 00:29:10.044475 | TASK [Setup log path fact]
2025-12-21 00:29:10.074502 | localhost | ok
2025-12-21 00:29:10.087839 | 
2025-12-21 00:29:10.087982 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-21 00:29:10.129136 | localhost | ok
2025-12-21 00:29:10.137900 | 
2025-12-21 00:29:10.137989 | TASK [emit-job-header : Print job information]
2025-12-21 00:29:10.186443 | # Job Information
2025-12-21 00:29:10.186716 | Ansible Version: 2.15.12
2025-12-21 00:29:10.186756 | Job: ansible-test-sanity-docker-milestone
2025-12-21 00:29:10.186782 | Pipeline: periodic
2025-12-21 00:29:10.186802 | Executor: ze04.softwarefactory-project.io
2025-12-21 00:29:10.186822 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-21 00:29:10.186880 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/49c/ansible/49c23c09237b42c8ae21939b508d18b1/
2025-12-21 00:29:10.186905 | Event ID: 0af00ed07cf843cab66474a277299bb1
2025-12-21 00:29:10.190972 | 
2025-12-21 00:29:10.191037 | LOOP [emit-job-header : Print node information]
2025-12-21 00:29:10.303600 | localhost | ok:
2025-12-21 00:29:10.303851 | localhost | # Node Information
2025-12-21 00:29:10.303881 | localhost | Inventory Hostname: controller
2025-12-21 00:29:10.303902 | localhost | Hostname: np0005568097
2025-12-21 00:29:10.303922 | localhost | Username: zuul
2025-12-21 00:29:10.303942 | localhost | Distro: Fedora 37
2025-12-21 00:29:10.303960 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-21 00:29:10.303978 | localhost | Region: ca-ymq-1
2025-12-21 00:29:10.303995 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-21 00:29:10.304012 | localhost | Product Name: OpenStack Nova
2025-12-21 00:29:10.304028 | localhost | Interface IP: 162.253.55.58
2025-12-21 00:29:10.315013 | 
2025-12-21 00:29:10.315096 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-21 00:29:10.707724 | localhost -> localhost | changed
2025-12-21 00:29:10.714611 | 
2025-12-21 00:29:10.714722 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-21 00:29:11.609508 | localhost -> localhost | changed
2025-12-21 00:29:11.630220 | 
2025-12-21 00:29:11.630343 | PLAY [all:!appliance*]
2025-12-21 00:29:11.646164 | 
2025-12-21 00:29:11.646245 | TASK [include_role : start-zuul-console]
2025-12-21 00:29:11.665668 | controller | ok
2025-12-21 00:29:11.679718 | 
2025-12-21 00:29:11.679862 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-21 00:29:12.067921 | controller | ok
2025-12-21 00:29:12.091296 | 
2025-12-21 00:29:12.091463 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-21 00:29:13.303212 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-21 00:29:13.309601 | 
2025-12-21 00:29:13.309671 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-21 00:29:13.885023 | controller | skipping: Conditional result was False
2025-12-21 00:29:13.899200 | 
2025-12-21 00:29:13.899363 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-21 00:29:13.938754 | controller | skipping: Conditional result was False
2025-12-21 00:29:13.954154 | 
2025-12-21 00:29:13.954331 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-21 00:29:13.992806 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.008333 | 
2025-12-21 00:29:14.008474 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-21 00:29:14.047658 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.057225 | 
2025-12-21 00:29:14.057320 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-21 00:29:14.082610 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.095383 | 
2025-12-21 00:29:14.095482 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-21 00:29:14.119690 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.131997 | 
2025-12-21 00:29:14.132079 | TASK [Disable Fedora Modular]
2025-12-21 00:29:14.369265 | controller | changed
2025-12-21 00:29:14.382986 | 
2025-12-21 00:29:14.383130 | TASK [Enable EPEL]
2025-12-21 00:29:14.401524 | controller | skipping: Conditional result was False
2025-12-21 00:29:14.408734 | 
2025-12-21 00:29:14.408859 | TASK [Register the RHEL node]
2025-12-21 00:29:14.956148 | 
2025-12-21 00:29:14.956641 | TASK [Show the subscription-manager status]
2025-12-21 00:29:15.548320 | controller | skipping: Conditional result was False
2025-12-21 00:29:15.556062 | 
2025-12-21 00:29:15.556136 | TASK [Enable EPEL on RHEL]
2025-12-21 00:29:16.088607 | controller | skipping: Conditional result was False
2025-12-21 00:29:16.104005 | 
2025-12-21 00:29:16.104221 | TASK [Install git and tox]
2025-12-21 00:30:37.292879 | controller | changed
2025-12-21 00:30:37.310492 | 
2025-12-21 00:30:37.310654 | TASK [include_role : prepare-workspace]
2025-12-21 00:30:37.353025 | controller | ok
2025-12-21 00:30:37.395605 | 
2025-12-21 00:30:37.395748 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-21 00:30:37.640810 | controller | ok
2025-12-21 00:30:37.657000 | 
2025-12-21 00:30:37.657163 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-21 00:30:49.628799 | controller | Output suppressed because no_log was given
2025-12-21 00:30:49.643543 | 
2025-12-21 00:30:49.643656 | TASK [include_role : prepare-workspace-openshift]
2025-12-21 00:30:49.675991 | controller | skipping: Conditional result was False
2025-12-21 00:30:49.755624 | 
2025-12-21 00:30:49.755790 | PLAY [all:!appliance]
2025-12-21 00:30:49.772375 | 
2025-12-21 00:30:49.772442 | TASK [Run add-build-sshkey role (RSA)]
2025-12-21 00:30:49.803360 | controller | ok
2025-12-21 00:30:49.819411 | 
2025-12-21 00:30:49.819477 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-21 00:30:50.099922 | controller -> localhost | ok
2025-12-21 00:30:50.114137 | 
2025-12-21 00:30:50.114308 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-21 00:30:50.155060 | controller | ok
2025-12-21 00:30:50.185132 | controller | included: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-21 00:30:50.194050 | 
2025-12-21 00:30:50.194140 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-21 00:30:50.663310 | controller -> localhost | Generating public/private rsa key pair.
2025-12-21 00:30:50.663822 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/49c23c09237b42c8ae21939b508d18b1_id_rsa.
2025-12-21 00:30:50.663891 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/49c23c09237b42c8ae21939b508d18b1_id_rsa.pub.
2025-12-21 00:30:50.663939 | controller -> localhost | The key fingerprint is:
2025-12-21 00:30:50.663985 | controller -> localhost | SHA256:vNN+s1hvYD5hriaAeLMN2pe3mAkoNiQvdf9+whrz/mQ zuul-build-sshkey
2025-12-21 00:30:50.664032 | controller -> localhost | The key's randomart image is:
2025-12-21 00:30:50.664077 | controller -> localhost | +---[RSA 2048]----+
2025-12-21 00:30:50.664125 | controller -> localhost | |                 |
2025-12-21 00:30:50.664186 | controller -> localhost | |                 |
2025-12-21 00:30:50.664231 | controller -> localhost | |                 |
2025-12-21 00:30:50.664274 | controller -> localhost | |       .         |
2025-12-21 00:30:50.664314 | controller -> localhost | |......  S        |
2025-12-21 00:30:50.664375 | controller -> localhost | |oo.o=..  o  =    |
2025-12-21 00:30:50.664425 | controller -> localhost | |ooo+.=++o E=.o   |
2025-12-21 00:30:50.664469 | controller -> localhost | |.oo o.+O==oo*..  |
2025-12-21 00:30:50.664550 | controller -> localhost | |     .==*B=o.=.  |
2025-12-21 00:30:50.664599 | controller -> localhost | +----[SHA256]-----+
2025-12-21 00:30:50.664751 | controller -> localhost | ok: Runtime: 0:00:00.042552
2025-12-21 00:30:50.682869 | 
2025-12-21 00:30:50.683073 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-21 00:30:50.726177 | controller | ok
2025-12-21 00:30:50.750420 | controller | included: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-21 00:30:50.763706 | 
2025-12-21 00:30:50.763804 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-21 00:30:50.791862 | controller | skipping: Conditional result was False
2025-12-21 00:30:50.801789 | 
2025-12-21 00:30:50.801909 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-21 00:30:51.243210 | controller | changed
2025-12-21 00:30:51.256611 | 
2025-12-21 00:30:51.256807 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-21 00:30:51.500495 | controller | ok
2025-12-21 00:30:51.509171 | 
2025-12-21 00:30:51.509266 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-21 00:30:52.151066 | controller | changed
2025-12-21 00:30:52.164219 | 
2025-12-21 00:30:52.164363 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-21 00:30:52.820183 | controller | changed
2025-12-21 00:30:52.834911 | 
2025-12-21 00:30:52.835105 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-21 00:30:52.865348 | controller | skipping: Conditional result was False
2025-12-21 00:30:52.881066 | 
2025-12-21 00:30:52.881232 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-21 00:30:53.329414 | controller -> localhost | changed
2025-12-21 00:30:53.349755 | 
2025-12-21 00:30:53.349985 | TASK [add-build-sshkey : Add back temp key]
2025-12-21 00:30:53.723173 | controller -> localhost | Identity added: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/49c23c09237b42c8ae21939b508d18b1_id_rsa (zuul-build-sshkey)
2025-12-21 00:30:53.723470 | controller -> localhost | ok: Runtime: 0:00:00.015109
2025-12-21 00:30:53.732823 | 
2025-12-21 00:30:53.732929 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-21 00:30:54.099439 | controller | ok
2025-12-21 00:30:54.112795 | 
2025-12-21 00:30:54.112948 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-21 00:30:54.150276 | controller | skipping: Conditional result was False
2025-12-21 00:30:54.177331 | 
2025-12-21 00:30:54.177485 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-21 00:30:54.216370 | controller | ok
2025-12-21 00:30:54.245632 | 
2025-12-21 00:30:54.245747 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-21 00:30:54.524858 | controller -> localhost | ok
2025-12-21 00:30:54.531459 | 
2025-12-21 00:30:54.531531 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-21 00:30:54.552324 | controller | ok
2025-12-21 00:30:54.563280 | controller | included: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-21 00:30:54.569700 | 
2025-12-21 00:30:54.569764 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-21 00:30:54.869242 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-21 00:30:54.869596 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/49c23c09237b42c8ae21939b508d18b1_id_ecdsa.
2025-12-21 00:30:54.869659 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/49c23c09237b42c8ae21939b508d18b1_id_ecdsa.pub.
2025-12-21 00:30:54.869764 | controller -> localhost | The key fingerprint is:
2025-12-21 00:30:54.869813 | controller -> localhost | SHA256:vFQ+wyxh80aI1WZutQp7F0XNdkICgB28shdpXTOV1g8 zuul-build-sshkey
2025-12-21 00:30:54.869856 | controller -> localhost | The key's randomart image is:
2025-12-21 00:30:54.869897 | controller -> localhost | +---[ECDSA 521]---+
2025-12-21 00:30:54.869937 | controller -> localhost | |       +++...++= |
2025-12-21 00:30:54.869979 | controller -> localhost | |      .oo.+ =.E *|
2025-12-21 00:30:54.870020 | controller -> localhost | |      . =Boo * +o|
2025-12-21 00:30:54.870058 | controller -> localhost | |      .o*X+ o   .|
2025-12-21 00:30:54.870096 | controller -> localhost | |       +S=O. .   |
2025-12-21 00:30:54.870133 | controller -> localhost | |      ..o+oo.    |
2025-12-21 00:30:54.870171 | controller -> localhost | |       ... .     |
2025-12-21 00:30:54.870208 | controller -> localhost | |                 |
2025-12-21 00:30:54.870245 | controller -> localhost | |                 |
2025-12-21 00:30:54.870283 | controller -> localhost | +----[SHA256]-----+
2025-12-21 00:30:54.870378 | controller -> localhost | ok: Runtime: 0:00:00.014617
2025-12-21 00:30:54.886311 | 
2025-12-21 00:30:54.886487 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-21 00:30:54.926042 | controller | ok
2025-12-21 00:30:54.944043 | controller | included: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-21 00:30:54.956528 | 
2025-12-21 00:30:54.956618 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-21 00:30:54.982036 | controller | skipping: Conditional result was False
2025-12-21 00:30:54.991206 | 
2025-12-21 00:30:54.991299 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-21 00:30:55.266783 | controller | changed
2025-12-21 00:30:55.281399 | 
2025-12-21 00:30:55.281577 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-21 00:30:55.518917 | controller | ok
2025-12-21 00:30:55.528029 | 
2025-12-21 00:30:55.528124 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-21 00:30:56.170724 | controller | changed
2025-12-21 00:30:56.184986 | 
2025-12-21 00:30:56.185144 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-21 00:30:56.821137 | controller | changed
2025-12-21 00:30:56.828771 | 
2025-12-21 00:30:56.828842 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-21 00:30:56.864121 | controller | skipping: Conditional result was False
2025-12-21 00:30:56.870961 | 
2025-12-21 00:30:56.871031 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-21 00:30:57.129465 | controller -> localhost | changed
2025-12-21 00:30:57.141983 | 
2025-12-21 00:30:57.142138 | TASK [add-build-sshkey : Add back temp key]
2025-12-21 00:30:57.471602 | controller -> localhost | Identity added: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/49c23c09237b42c8ae21939b508d18b1_id_ecdsa (zuul-build-sshkey)
2025-12-21 00:30:57.471863 | controller -> localhost | ok: Runtime: 0:00:00.009603
2025-12-21 00:30:57.478764 | 
2025-12-21 00:30:57.478832 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-21 00:30:57.743313 | controller | ok
2025-12-21 00:30:57.751729 | 
2025-12-21 00:30:57.751825 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-21 00:30:57.777740 | controller | skipping: Conditional result was False
2025-12-21 00:30:57.795260 | 
2025-12-21 00:30:57.795356 | TASK [include_role : remove-zuul-sshkey]
2025-12-21 00:30:57.821736 | controller | skipping: Conditional result was False
2025-12-21 00:30:57.831848 | 
2025-12-21 00:30:57.831943 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-21 00:30:58.073519 | controller | ok: "logs"
2025-12-21 00:30:58.074401 | controller | ok: All items complete
2025-12-21 00:30:58.074473 | 
2025-12-21 00:30:58.271028 | controller | ok: "artifacts"
2025-12-21 00:30:58.462477 | controller | ok: "docs"
2025-12-21 00:30:58.480981 | 
2025-12-21 00:30:58.481078 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-21 00:30:58.740923 | controller | changed: "logs"
2025-12-21 00:30:58.934936 | controller | changed: "artifacts"
2025-12-21 00:30:59.143527 | controller | changed: "docs"
2025-12-21 00:30:59.205160 | 
2025-12-21 00:30:59.205319 | PLAY RECAP
2025-12-21 00:30:59.205402 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-21 00:30:59.205456 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-21 00:30:59.205495 | 
2025-12-21 00:30:59.347669 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-21 00:30:59.349602 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-21 00:30:59.956417 | 
2025-12-21 00:30:59.956541 | PLAY [all]
2025-12-21 00:30:59.980263 | 
2025-12-21 00:30:59.980436 | TASK [Install binary dependencies]
2025-12-21 00:31:00.024475 | controller | ok
2025-12-21 00:31:00.049956 | 
2025-12-21 00:31:00.050108 | TASK [bindep : Include find tasks]
2025-12-21 00:31:00.081453 | controller | ok
2025-12-21 00:31:00.090065 | controller | included: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-21 00:31:00.097076 | 
2025-12-21 00:31:00.097147 | TASK [bindep : Look for bindep.txt]
2025-12-21 00:31:00.440139 | controller | ok
2025-12-21 00:31:00.455191 | 
2025-12-21 00:31:00.455408 | TASK [bindep : Define bindep_file fact]
2025-12-21 00:31:00.485240 | controller | skipping: Conditional result was False
2025-12-21 00:31:00.504276 | 
2025-12-21 00:31:00.504493 | TASK [bindep : Look for other-requirements.txt]
2025-12-21 00:31:00.725471 | controller | ok
2025-12-21 00:31:00.733172 | 
2025-12-21 00:31:00.733268 | TASK [bindep : Define bindep_file fact]
2025-12-21 00:31:00.758373 | controller | skipping: Conditional result was False
2025-12-21 00:31:00.765918 | 
2025-12-21 00:31:00.766008 | TASK [bindep : Look for bindep fallback file]
2025-12-21 00:31:00.790657 | controller | skipping: Conditional result was False
2025-12-21 00:31:00.797981 | 
2025-12-21 00:31:00.798051 | TASK [bindep : Define bindep_file fact]
2025-12-21 00:31:00.821958 | controller | skipping: Conditional result was False
2025-12-21 00:31:00.829499 | 
2025-12-21 00:31:00.829579 | TASK [bindep : Include bindep tasks]
2025-12-21 00:31:00.854355 | controller | skipping: Conditional result was False
2025-12-21 00:31:00.860572 | 
2025-12-21 00:31:00.860641 | TASK [bindep : Include install tasks]
2025-12-21 00:31:00.884799 | controller | skipping: Conditional result was False
2025-12-21 00:31:00.891451 | 
2025-12-21 00:31:00.891523 | LOOP [bindep : Include package tasks]
2025-12-21 00:31:00.947246 | 
2025-12-21 00:31:00.947418 | TASK [Run test-setup role]
2025-12-21 00:31:00.971607 | controller | ok
2025-12-21 00:31:00.996953 | 
2025-12-21 00:31:00.997057 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-21 00:31:01.217084 | controller | ok
2025-12-21 00:31:01.230262 | 
2025-12-21 00:31:01.230400 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-21 00:31:01.780775 | controller | skipping: Conditional result was False
2025-12-21 00:31:01.839052 | 
2025-12-21 00:31:01.839237 | PLAY RECAP
2025-12-21 00:31:01.839301 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-21 00:31:01.839331 | 
2025-12-21 00:31:02.013466 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-21 00:31:02.015312 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-21 00:31:02.608229 | 
2025-12-21 00:31:02.608371 | PLAY [controller]
2025-12-21 00:31:02.628540 | 
2025-12-21 00:31:02.628634 | TASK [Create the /root directory]
2025-12-21 00:31:03.034117 | controller | ok
2025-12-21 00:31:03.047197 | 
2025-12-21 00:31:03.047356 | TASK [Install glibc-langpack-en]
2025-12-21 00:31:06.872088 | controller | ok: Nothing to do
2025-12-21 00:31:06.886475 | 
2025-12-21 00:31:06.886638 | TASK [Ensure controller directory exists]
2025-12-21 00:31:07.104727 | controller | changed
2025-12-21 00:31:07.112465 | 
2025-12-21 00:31:07.112874 | TASK [Install container runtime]
2025-12-21 00:31:07.191309 | controller | ok
2025-12-21 00:31:07.243475 | 
2025-12-21 00:31:07.243668 | LOOP [ensure-podman : Find distribution installation]
2025-12-21 00:31:07.297277 | controller | ok: "/var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-21 00:31:07.311486 | controller | included: /var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-21 00:31:07.318171 | 
2025-12-21 00:31:07.318316 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-21 00:32:11.602338 | controller | changed
2025-12-21 00:32:11.611303 | 
2025-12-21 00:32:11.611433 | TASK [ensure-podman : Fetch podman version]
2025-12-21 00:32:12.137052 | controller | Client:       Podman Engine
2025-12-21 00:32:12.167026 | controller | Version:      4.6.2
2025-12-21 00:32:12.167064 | controller | API Version:  4.6.2
2025-12-21 00:32:12.167077 | controller | Go Version:   go1.19.12
2025-12-21 00:32:12.167101 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-21 00:32:12.167113 | controller | OS/Arch:      linux/amd64
2025-12-21 00:32:12.658179 | controller | ok: Runtime: 0:00:00.201179
2025-12-21 00:32:12.671748 | 
2025-12-21 00:32:12.671841 | TASK [ensure-podman : Print podman version installed]
2025-12-21 00:32:12.715265 | Podman version: Client:       Podman Engine
2025-12-21 00:32:12.715475 | Version:      4.6.2
2025-12-21 00:32:12.715515 | API Version:  4.6.2
2025-12-21 00:32:12.715543 | Go Version:   go1.19.12
2025-12-21 00:32:12.715568 | Built:        Mon Aug 28 19:38:31 2023
2025-12-21 00:32:12.715595 | OS/Arch:      linux/amd64
2025-12-21 00:32:12.723474 | 
2025-12-21 00:32:12.723582 | TASK [ensure-podman : Validate podman engine]
2025-12-21 00:32:13.264569 | controller | skipping: Conditional result was False
2025-12-21 00:32:13.279125 | 
2025-12-21 00:32:13.279282 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-21 00:32:13.306921 | controller | skipping: Conditional result was False
2025-12-21 00:32:13.336558 | 
2025-12-21 00:32:13.336813 | TASK [Ensure python3.8 is present]
2025-12-21 00:32:13.366485 | controller | skipping: Conditional result was False
2025-12-21 00:32:13.374949 | 
2025-12-21 00:32:13.375036 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-21 00:32:13.399211 | controller | ok
2025-12-21 00:32:13.430123 | 
2025-12-21 00:32:13.430306 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-21 00:32:14.963196 | controller | ok: Nothing to do
2025-12-21 00:32:14.975984 | 
2025-12-21 00:32:14.976128 | TASK [our-ensure-python : Also install python3-devel]
2025-12-21 00:32:23.492508 | controller | changed
2025-12-21 00:32:23.517454 | 
2025-12-21 00:32:23.517618 | TASK [Run ensure-virtualenv role]
2025-12-21 00:32:23.542077 | controller | ok
2025-12-21 00:32:23.573502 | 
2025-12-21 00:32:23.573660 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-21 00:32:23.814675 | controller | /usr/bin/virtualenv
2025-12-21 00:32:24.109832 | controller | ok: Runtime: 0:00:00.006345
2025-12-21 00:32:24.125402 | 
2025-12-21 00:32:24.125611 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-21 00:32:24.159177 | controller | skipping: Conditional result was False
2025-12-21 00:32:24.159474 | controller | ok: All items complete
2025-12-21 00:32:24.159500 | 
2025-12-21 00:32:24.191979 | 
2025-12-21 00:32:24.192256 | TASK [Find the full path of the Python interpreter]
2025-12-21 00:32:24.474553 | controller | /usr/bin/python3
2025-12-21 00:32:24.785984 | controller | ok
2025-12-21 00:32:24.798519 | 
2025-12-21 00:32:24.798737 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-21 00:32:25.739030 | controller | created virtual environment CPython3.11.0.final.0-64 in 469ms
2025-12-21 00:32:25.754832 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-21 00:32:25.754847 | 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-21 00:32:25.754861 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-21 00:32:25.754875 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-21 00:32:25.852628 | controller | changed
2025-12-21 00:32:25.867171 | 
2025-12-21 00:32:25.867319 | TASK [Set selinux package]
2025-12-21 00:32:25.909446 | controller | ok
2025-12-21 00:32:25.922468 | 
2025-12-21 00:32:25.922625 | TASK [Set selinux package (Fedora)]
2025-12-21 00:32:25.974093 | controller | ok
2025-12-21 00:32:25.981755 | 
2025-12-21 00:32:25.981845 | TASK [Install selinux into virtualenv]
2025-12-21 00:33:03.439105 | controller | Collecting selinux-please-lie-to-me
2025-12-21 00:33:15.791433 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-21 00:33:16.087747 | controller | Collecting setuptools<50.0.0
2025-12-21 00:33:16.101330 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-21 00:33:16.143056 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.7 MB/s eta 0:00:00
2025-12-21 00:33:16.223632 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-21 00:33:16.223848 | controller |   Attempting uninstall: setuptools
2025-12-21 00:33:16.226231 | controller |     Found existing installation: setuptools 62.6.0
2025-12-21 00:33:16.284416 | controller |     Uninstalling setuptools-62.6.0:
2025-12-21 00:33:16.292282 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-21 00:33:16.628690 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-21 00:33:30.104706 | controller |
2025-12-21 00:33:30.185458 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-21 00:33:30.185513 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-21 00:33:30.565294 | controller | ok: Runtime: 0:01:03.964072
2025-12-21 00:33:30.578282 | 
2025-12-21 00:33:30.578418 | TASK [Install pytest-forked into virtualenv]
2025-12-21 00:33:50.597960 | controller | Collecting pytest-forked
2025-12-21 00:34:02.836718 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-21 00:34:02.890368 | controller | Collecting py
2025-12-21 00:34:02.893664 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-21 00:34:02.921900 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.8 MB/s eta 0:00:00
2025-12-21 00:34:03.028821 | controller | Collecting pytest>=3.10
2025-12-21 00:34:03.033392 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-21 00:34:03.063049 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 13.8 MB/s eta 0:00:00
2025-12-21 00:34:03.098423 | controller | Collecting iniconfig>=1.0.1
2025-12-21 00:34:03.101887 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-21 00:34:03.146073 | controller | Collecting packaging>=22
2025-12-21 00:34:03.149038 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-21 00:34:03.157364 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 10.0 MB/s eta 0:00:00
2025-12-21 00:34:03.194203 | controller | Collecting pluggy<2,>=1.5
2025-12-21 00:34:03.197293 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-21 00:34:03.245852 | controller | Collecting pygments>=2.7.2
2025-12-21 00:34:03.249034 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-21 00:34:03.277565 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 46.9 MB/s eta 0:00:00
2025-12-21 00:34:03.345618 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-21 00:34:04.410269 | 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-21 00:34:04.419124 | controller |
2025-12-21 00:34:04.485998 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-21 00:34:04.486034 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-21 00:34:04.651645 | controller | ok: Runtime: 0:00:33.665017
2025-12-21 00:34:04.664292 | 
2025-12-21 00:34:04.664425 | TASK [Update pip]
2025-12-21 00:34:05.186929 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-21 00:34:15.259406 | controller | Collecting pip
2025-12-21 00:34:39.401216 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-21 00:34:39.461052 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 32.7 MB/s eta 0:00:00
2025-12-21 00:34:39.524130 | controller | Installing collected packages: pip
2025-12-21 00:34:39.524359 | controller |   Attempting uninstall: pip
2025-12-21 00:34:39.526475 | controller |     Found existing installation: pip 22.2.2
2025-12-21 00:34:39.666773 | controller |     Uninstalling pip-22.2.2:
2025-12-21 00:34:39.681724 | controller |       Successfully uninstalled pip-22.2.2
2025-12-21 00:34:40.498399 | controller | Successfully installed pip-25.3
2025-12-21 00:34:40.731088 | controller | ok: Runtime: 0:00:35.685644
2025-12-21 00:34:40.744049 | 
2025-12-21 00:34:40.744184 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-21 00:34:40.979463 | controller | changed
2025-12-21 00:34:40.990815 | 
2025-12-21 00:34:40.990902 | TASK [Install ansible into virtualenv]
2025-12-21 00:34:41.497777 | controller | Processing ./src/github.com/ansible/ansible
2025-12-21 00:34:41.501162 | controller |   Installing build dependencies: started
2025-12-21 00:35:16.636438 | controller |   Installing build dependencies: finished with status 'done'
2025-12-21 00:35:16.637587 | controller |   Getting requirements to build wheel: started
2025-12-21 00:35:17.381391 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-21 00:35:17.383081 | controller |   Preparing metadata (pyproject.toml): started
2025-12-21 00:35:17.842690 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-21 00:35:17.847902 | 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-21 00:35:17.851359 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-21 00:35:18.051577 | controller | ERROR
2025-12-21 00:35:18.051825 | controller | {
2025-12-21 00:35:18.051892 | controller |   "delta": "0:00:36.707965",
2025-12-21 00:35:18.051922 | controller |   "end": "2025-12-21 00:35:17.926431",
2025-12-21 00:35:18.051946 | controller |   "msg": "non-zero return code",
2025-12-21 00:35:18.051980 | controller |   "rc": 1,
2025-12-21 00:35:18.052004 | controller |   "start": "2025-12-21 00:34:41.218466"
2025-12-21 00:35:18.052032 | controller | }
failure
2025-12-21 00:35:18.055633 | 
2025-12-21 00:35:18.055725 | PLAY RECAP
2025-12-21 00:35:18.055804 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-21 00:35:18.055845 | 
2025-12-21 00:35:18.185035 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-21 00:35:18.186249 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-21 00:35:18.771878 | 
2025-12-21 00:35:18.771999 | PLAY [all]
2025-12-21 00:35:18.794292 | 
2025-12-21 00:35:18.794390 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-21 00:35:19.060158 | controller | changed: non-zero return code
2025-12-21 00:35:19.066901 | 
2025-12-21 00:35:19.067004 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-21 00:35:19.094111 | controller | skipping: Conditional result was False
2025-12-21 00:35:19.110023 | 
2025-12-21 00:35:19.110187 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-21 00:35:19.154239 | 
2025-12-21 00:35:19.154538 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-21 00:35:19.206391 | 
2025-12-21 00:35:19.206738 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-21 00:35:19.233626 | controller | skipping: Conditional result was False
2025-12-21 00:35:19.244308 | 
2025-12-21 00:35:19.244415 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-21 00:35:19.279087 | 
2025-12-21 00:35:19.279324 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-21 00:35:19.304901 | controller | skipping: Conditional result was False
2025-12-21 00:35:19.313782 | 
2025-12-21 00:35:19.313904 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-21 00:35:19.340108 | controller | skipping: Conditional result was False
2025-12-21 00:35:19.349174 | 
2025-12-21 00:35:19.349301 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-21 00:35:19.375438 | controller | skipping: Conditional result was False
2025-12-21 00:35:19.412551 | 
2025-12-21 00:35:19.412632 | PLAY RECAP
2025-12-21 00:35:19.412691 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-21 00:35:19.412715 | 
2025-12-21 00:35:19.558888 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-21 00:35:19.560223 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-21 00:35:20.236867 | 
2025-12-21 00:35:20.237049 | PLAY [all:!appliance*]
2025-12-21 00:35:20.260482 | 
2025-12-21 00:35:20.260741 | TASK [unregister the node]
2025-12-21 00:35:20.794054 | controller | skipping: Conditional result was False
2025-12-21 00:35:20.808583 | 
2025-12-21 00:35:20.808887 | TASK [include_role : fetch-output]
2025-12-21 00:35:20.849906 | controller | ok
2025-12-21 00:35:20.888051 | 
2025-12-21 00:35:20.888190 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-21 00:35:20.934296 | controller | skipping: Conditional result was False
2025-12-21 00:35:20.947983 | 
2025-12-21 00:35:20.948135 | TASK [fetch-output : Set log path for single node]
2025-12-21 00:35:21.008638 | controller | ok
2025-12-21 00:35:21.017584 | 
2025-12-21 00:35:21.017749 | LOOP [fetch-output : Ensure local output dirs]
2025-12-21 00:35:21.497891 | controller -> localhost | ok: "/var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/logs"
2025-12-21 00:35:21.793095 | controller -> localhost | changed: "/var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/artifacts"
2025-12-21 00:35:22.084564 | controller -> localhost | changed: "/var/lib/zuul/builds/49c23c09237b42c8ae21939b508d18b1/work/docs"
2025-12-21 00:35:22.098216 | 
2025-12-21 00:35:22.098408 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-21 00:35:22.849217 | controller | changed:
2025-12-21 00:35:22.849437 | controller | .d..t...... ./
2025-12-21 00:35:22.849465 | controller | cd+++++++++ controller/
2025-12-21 00:35:22.849496 | controller | changed: All items complete
2025-12-21 00:35:22.849516 | 
2025-12-21 00:35:23.357305 | controller | changed: .d..t...... ./
2025-12-21 00:35:23.884551 | controller | changed: .d..t...... ./
2025-12-21 00:35:23.912916 | 
2025-12-21 00:35:23.913042 | TASK [include_role : fetch-output-openshift]
2025-12-21 00:35:23.939935 | controller | skipping: Conditional result was False
2025-12-21 00:35:23.984931 | 
2025-12-21 00:35:23.985415 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-21 00:35:24.028728 | controller | skipping: Conditional result was False
2025-12-21 00:35:24.047319 | controller | skipping: Conditional result was False
2025-12-21 00:35:24.093621 | 
2025-12-21 00:35:24.093808 | PLAY [localhost]
2025-12-21 00:35:24.110423 | 
2025-12-21 00:35:24.110525 | TASK [Run Zuul manifest role]
2025-12-21 00:35:24.129562 | localhost | ok
2025-12-21 00:35:24.143642 | 
2025-12-21 00:35:24.143731 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-21 00:35:24.609777 | localhost | changed
2025-12-21 00:35:24.614497 | 
2025-12-21 00:35:24.614560 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-21 00:35:24.664045 | localhost | ok
2025-12-21 00:35:24.671908 | 
2025-12-21 00:35:24.671965 | TASK [Set zuul-log-path fact]
2025-12-21 00:35:24.700508 | localhost | ok
2025-12-21 00:35:24.714712 | 
2025-12-21 00:35:24.714778 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-21 00:35:24.754777 | localhost | ok
2025-12-21 00:35:24.762599 | 
2025-12-21 00:35:24.762658 | LOOP [Run upload-logs-swift role]
2025-12-21 00:35:24.808896 | localhost | Output suppressed because no_log was given
2025-12-21 00:35:24.842206 | 
2025-12-21 00:35:24.842298 | TASK [Set zuul-log-path fact]
2025-12-21 00:35:24.867139 | localhost | skipping: Conditional result was False
2025-12-21 00:35:24.872168 | 
2025-12-21 00:35:24.872237 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-21 00:35:25.273771 | localhost -> localhost | ok: Runtime: 0:00:00.009587
2025-12-21 00:35:25.309927 | 
2025-12-21 00:35:25.310056 | TASK [upload-logs-swift : Upload logs to swift]