2025-11-01 00:06:54.369481 | Job console starting...
2025-11-01 00:06:54.379178 | Updating repositories
2025-11-01 00:06:54.558168 | Preparing job workspace
2025-11-01 00:06:59.313172 | Running Ansible setup...
2025-11-01 00:07:07.555496 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-01 00:07:08.163000 | 
2025-11-01 00:07:08.163119 | PLAY [localhost]
2025-11-01 00:07:08.171156 | 
2025-11-01 00:07:08.171227 | TASK [Gathering Facts]
2025-11-01 00:07:09.168439 | localhost | ok
2025-11-01 00:07:09.189105 | 
2025-11-01 00:07:09.189274 | TASK [Setup log path fact]
2025-11-01 00:07:09.208496 | localhost | ok
2025-11-01 00:07:09.221467 | 
2025-11-01 00:07:09.221635 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-01 00:07:09.261465 | localhost | ok
2025-11-01 00:07:09.269684 | 
2025-11-01 00:07:09.269778 | TASK [emit-job-header : Print job information]
2025-11-01 00:07:09.308774 | # Job Information
2025-11-01 00:07:09.308990 | Ansible Version: 2.15.12
2025-11-01 00:07:09.309025 | Job: ansible-test-sanity-docker-devel
2025-11-01 00:07:09.309048 | Pipeline: periodic
2025-11-01 00:07:09.309066 | Executor: ze02.softwarefactory-project.io
2025-11-01 00:07:09.309084 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-01 00:07:09.309105 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/7bf/ansible/7bfc2a04b2d64f5db6045f48522262fb/
2025-11-01 00:07:09.309125 | Event ID: a664f74adefa4145bbf2cab5da247121
2025-11-01 00:07:09.313521 | 
2025-11-01 00:07:09.313606 | LOOP [emit-job-header : Print node information]
2025-11-01 00:07:09.439880 | localhost | ok:
2025-11-01 00:07:09.440158 | localhost | # Node Information
2025-11-01 00:07:09.440218 | localhost | Inventory Hostname: controller
2025-11-01 00:07:09.440265 | localhost | Hostname: np0005508776
2025-11-01 00:07:09.440307 | localhost | Username: zuul
2025-11-01 00:07:09.440360 | localhost | Distro: Fedora 37
2025-11-01 00:07:09.440416 | localhost | Provider: ansible-vexxhost-ams1
2025-11-01 00:07:09.440458 | localhost | Region: ams1
2025-11-01 00:07:09.440496 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-01 00:07:09.440534 | localhost | Product Name: OpenStack Nova
2025-11-01 00:07:09.440571 | localhost | Interface IP: 38.129.16.133
2025-11-01 00:07:09.460241 | 
2025-11-01 00:07:09.460386 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-01 00:07:09.832939 | localhost -> localhost | changed
2025-11-01 00:07:09.838347 | 
2025-11-01 00:07:09.838418 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-01 00:07:10.605157 | localhost -> localhost | changed
2025-11-01 00:07:10.628455 | 
2025-11-01 00:07:10.628543 | PLAY [all:!appliance*]
2025-11-01 00:07:10.644871 | 
2025-11-01 00:07:10.644992 | TASK [include_role : start-zuul-console]
2025-11-01 00:07:10.666910 | controller | ok
2025-11-01 00:07:10.688185 | 
2025-11-01 00:07:10.688296 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-01 00:07:11.636994 | controller | ok
2025-11-01 00:07:11.649937 | 
2025-11-01 00:07:11.650494 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-01 00:07:13.812288 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-01 00:07:13.829504 | 
2025-11-01 00:07:13.829919 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-01 00:07:14.210846 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.226600 | 
2025-11-01 00:07:14.226824 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-01 00:07:14.264166 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.278600 | 
2025-11-01 00:07:14.278798 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-01 00:07:14.295117 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.304591 | 
2025-11-01 00:07:14.304787 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-01 00:07:14.329821 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.337857 | 
2025-11-01 00:07:14.337972 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-01 00:07:14.362688 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.369520 | 
2025-11-01 00:07:14.369626 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-01 00:07:14.393739 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.408771 | 
2025-11-01 00:07:14.408890 | TASK [Disable Fedora Modular]
2025-11-01 00:07:15.260724 | controller | changed
2025-11-01 00:07:15.269739 | 
2025-11-01 00:07:15.269836 | TASK [Enable EPEL]
2025-11-01 00:07:15.295397 | controller | skipping: Conditional result was False
2025-11-01 00:07:15.304684 | 
2025-11-01 00:07:15.304790 | TASK [Register the RHEL node]
2025-11-01 00:07:15.711420 | 
2025-11-01 00:07:15.711560 | TASK [Show the subscription-manager status]
2025-11-01 00:07:16.076653 | controller | skipping: Conditional result was False
2025-11-01 00:07:16.083550 | 
2025-11-01 00:07:16.083627 | TASK [Enable EPEL on RHEL]
2025-11-01 00:07:16.443728 | controller | skipping: Conditional result was False
2025-11-01 00:07:16.457558 | 
2025-11-01 00:07:16.457751 | TASK [Install git and tox]
2025-11-01 00:09:55.496609 | controller | changed
2025-11-01 00:09:55.504548 | 
2025-11-01 00:09:55.504685 | TASK [include_role : prepare-workspace]
2025-11-01 00:09:55.526198 | controller | ok
2025-11-01 00:09:55.551694 | 
2025-11-01 00:09:55.551807 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-01 00:09:56.363504 | controller | ok
2025-11-01 00:09:56.370481 | 
2025-11-01 00:09:56.370561 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-01 00:10:15.614899 | controller | Output suppressed because no_log was given
2025-11-01 00:10:15.629352 | 
2025-11-01 00:10:15.629474 | TASK [include_role : prepare-workspace-openshift]
2025-11-01 00:10:15.655985 | controller | skipping: Conditional result was False
2025-11-01 00:10:15.682779 | 
2025-11-01 00:10:15.682857 | PLAY [all:!appliance]
2025-11-01 00:10:15.703756 | 
2025-11-01 00:10:15.703888 | TASK [Run add-build-sshkey role (RSA)]
2025-11-01 00:10:15.734075 | controller | ok
2025-11-01 00:10:15.756459 | 
2025-11-01 00:10:15.756567 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-01 00:10:15.996636 | controller -> localhost | ok
2025-11-01 00:10:16.003815 | 
2025-11-01 00:10:16.003901 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-01 00:10:16.034914 | controller | ok
2025-11-01 00:10:16.052755 | controller | included: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-01 00:10:16.060343 | 
2025-11-01 00:10:16.060448 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-01 00:10:16.603750 | controller -> localhost | Generating public/private rsa key pair.
2025-11-01 00:10:16.603970 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/7bfc2a04b2d64f5db6045f48522262fb_id_rsa.
2025-11-01 00:10:16.604000 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/7bfc2a04b2d64f5db6045f48522262fb_id_rsa.pub.
2025-11-01 00:10:16.604022 | controller -> localhost | The key fingerprint is:
2025-11-01 00:10:16.604051 | controller -> localhost | SHA256:QYIs+HelUo2wWrezd9DSe1ZlHdPRzjiILN1xILX2tgY zuul-build-sshkey
2025-11-01 00:10:16.604073 | controller -> localhost | The key's randomart image is:
2025-11-01 00:10:16.604091 | controller -> localhost | +---[RSA 2048]----+
2025-11-01 00:10:16.604110 | controller -> localhost | | . ..o.o. ..o. ++|
2025-11-01 00:10:16.604128 | controller -> localhost | |. . o.ooo  .... *|
2025-11-01 00:10:16.604158 | controller -> localhost | | . .o..o.o oo+ ++|
2025-11-01 00:10:16.604178 | controller -> localhost | |  .oo.o..++.o.ooo|
2025-11-01 00:10:16.604196 | controller -> localhost | |  .. oo S.o E +. |
2025-11-01 00:10:16.604223 | controller -> localhost | |       o o . + . |
2025-11-01 00:10:16.604246 | controller -> localhost | |      . . o o o  |
2025-11-01 00:10:16.604267 | controller -> localhost | |       . . o .   |
2025-11-01 00:10:16.604286 | controller -> localhost | |                 |
2025-11-01 00:10:16.604306 | controller -> localhost | +----[SHA256]-----+
2025-11-01 00:10:16.604350 | controller -> localhost | ok: Runtime: 0:00:00.088230
2025-11-01 00:10:16.612239 | 
2025-11-01 00:10:16.612332 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-01 00:10:16.632397 | controller | ok
2025-11-01 00:10:16.643449 | controller | included: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-01 00:10:16.655658 | 
2025-11-01 00:10:16.655794 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-01 00:10:16.670504 | controller | skipping: Conditional result was False
2025-11-01 00:10:16.677241 | 
2025-11-01 00:10:16.677332 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-01 00:10:17.750830 | controller | changed
2025-11-01 00:10:17.757084 | 
2025-11-01 00:10:17.757163 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-01 00:10:18.409458 | controller | ok
2025-11-01 00:10:18.420143 | 
2025-11-01 00:10:18.420268 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-01 00:10:21.403714 | controller | changed
2025-11-01 00:10:21.416639 | 
2025-11-01 00:10:21.416827 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-01 00:10:24.442123 | controller | changed
2025-11-01 00:10:24.452181 | 
2025-11-01 00:10:24.452298 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-01 00:10:24.527874 | controller | skipping: Conditional result was False
2025-11-01 00:10:24.535336 | 
2025-11-01 00:10:24.535451 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-01 00:10:25.032867 | controller -> localhost | changed
2025-11-01 00:10:25.062254 | 
2025-11-01 00:10:25.062401 | TASK [add-build-sshkey : Add back temp key]
2025-11-01 00:10:25.567951 | controller -> localhost | Identity added: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/7bfc2a04b2d64f5db6045f48522262fb_id_rsa (zuul-build-sshkey)
2025-11-01 00:10:25.568130 | controller -> localhost | ok: Runtime: 0:00:00.008794
2025-11-01 00:10:25.575917 | 
2025-11-01 00:10:25.575983 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-01 00:10:26.530688 | controller | ok
2025-11-01 00:10:26.536599 | 
2025-11-01 00:10:26.536704 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-01 00:10:26.612818 | controller | skipping: Conditional result was False
2025-11-01 00:10:26.626745 | 
2025-11-01 00:10:26.626836 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-01 00:10:26.659216 | controller | ok
2025-11-01 00:10:26.678299 | 
2025-11-01 00:10:26.678432 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-01 00:10:26.941999 | controller -> localhost | ok
2025-11-01 00:10:26.950593 | 
2025-11-01 00:10:26.950914 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-01 00:10:26.986958 | controller | ok
2025-11-01 00:10:27.002283 | controller | included: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-01 00:10:27.009909 | 
2025-11-01 00:10:27.010001 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-01 00:10:27.288817 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-01 00:10:27.289020 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/7bfc2a04b2d64f5db6045f48522262fb_id_ecdsa.
2025-11-01 00:10:27.289051 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/7bfc2a04b2d64f5db6045f48522262fb_id_ecdsa.pub.
2025-11-01 00:10:27.289082 | controller -> localhost | The key fingerprint is:
2025-11-01 00:10:27.289109 | controller -> localhost | SHA256:LY9oDYt0XT7TMlMPW4G4/iVfELOJ3SZzuLvkIDu+e/Y zuul-build-sshkey
2025-11-01 00:10:27.289130 | controller -> localhost | The key's randomart image is:
2025-11-01 00:10:27.289149 | controller -> localhost | +---[ECDSA 521]---+
2025-11-01 00:10:27.289168 | controller -> localhost | |           . ..  |
2025-11-01 00:10:27.289187 | controller -> localhost | |          . . o. |
2025-11-01 00:10:27.289205 | controller -> localhost | |          ..oo.B |
2025-11-01 00:10:27.289228 | controller -> localhost | |       . +.o.=O +|
2025-11-01 00:10:27.289251 | controller -> localhost | |    . o S.O o .B |
2025-11-01 00:10:27.289270 | controller -> localhost | |   . o = +.*. o .|
2025-11-01 00:10:27.289293 | controller -> localhost | |    . + o o..+.o |
2025-11-01 00:10:27.289312 | controller -> localhost | |     .    .o++o  |
2025-11-01 00:10:27.289329 | controller -> localhost | |         .=* .E. |
2025-11-01 00:10:27.289365 | controller -> localhost | +----[SHA256]-----+
2025-11-01 00:10:27.289412 | controller -> localhost | ok: Runtime: 0:00:00.008105
2025-11-01 00:10:27.297449 | 
2025-11-01 00:10:27.297547 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-01 00:10:27.328603 | controller | ok
2025-11-01 00:10:27.337077 | controller | included: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-01 00:10:27.347727 | 
2025-11-01 00:10:27.347822 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-01 00:10:27.372263 | controller | skipping: Conditional result was False
2025-11-01 00:10:27.413076 | 
2025-11-01 00:10:27.413227 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-01 00:10:28.269430 | controller | changed
2025-11-01 00:10:28.282727 | 
2025-11-01 00:10:28.282859 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-01 00:10:28.912806 | controller | ok
2025-11-01 00:10:28.923640 | 
2025-11-01 00:10:28.923789 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-01 00:10:31.846895 | controller | changed
2025-11-01 00:10:31.855821 | 
2025-11-01 00:10:31.856024 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-01 00:10:34.811770 | controller | changed
2025-11-01 00:10:34.825878 | 
2025-11-01 00:10:34.826018 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-01 00:10:34.843772 | controller | skipping: Conditional result was False
2025-11-01 00:10:34.885180 | 
2025-11-01 00:10:34.885301 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-01 00:10:35.147591 | controller -> localhost | changed
2025-11-01 00:10:35.166141 | 
2025-11-01 00:10:35.166290 | TASK [add-build-sshkey : Add back temp key]
2025-11-01 00:10:35.510187 | controller -> localhost | Identity added: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/7bfc2a04b2d64f5db6045f48522262fb_id_ecdsa (zuul-build-sshkey)
2025-11-01 00:10:35.510431 | controller -> localhost | ok: Runtime: 0:00:00.010406
2025-11-01 00:10:35.519287 | 
2025-11-01 00:10:35.519406 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-01 00:10:36.198377 | controller | ok
2025-11-01 00:10:36.207050 | 
2025-11-01 00:10:36.207172 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-01 00:10:36.233632 | controller | skipping: Conditional result was False
2025-11-01 00:10:36.253137 | 
2025-11-01 00:10:36.253348 | TASK [include_role : remove-zuul-sshkey]
2025-11-01 00:10:36.291901 | controller | skipping: Conditional result was False
2025-11-01 00:10:36.300653 | 
2025-11-01 00:10:36.300778 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-01 00:10:36.924261 | controller | ok: "logs"
2025-11-01 00:10:36.924533 | controller | ok: All items complete
2025-11-01 00:10:36.924577 | 
2025-11-01 00:10:37.503400 | controller | ok: "artifacts"
2025-11-01 00:10:38.083658 | controller | ok: "docs"
2025-11-01 00:10:38.106553 | 
2025-11-01 00:10:38.106818 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-01 00:10:38.726953 | controller | changed: "logs"
2025-11-01 00:10:39.312363 | controller | changed: "artifacts"
2025-11-01 00:10:39.902749 | controller | changed: "docs"
2025-11-01 00:10:39.944742 | 
2025-11-01 00:10:39.944856 | PLAY RECAP
2025-11-01 00:10:39.944908 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-01 00:10:39.944944 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-01 00:10:39.944969 | 
2025-11-01 00:10:40.083615 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-01 00:10:40.084468 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-01 00:10:40.619152 | 
2025-11-01 00:10:40.619260 | PLAY [all]
2025-11-01 00:10:40.646530 | 
2025-11-01 00:10:40.646646 | TASK [Install binary dependencies]
2025-11-01 00:10:40.717072 | controller | ok
2025-11-01 00:10:40.747378 | 
2025-11-01 00:10:40.747521 | TASK [bindep : Include find tasks]
2025-11-01 00:10:40.807790 | controller | ok
2025-11-01 00:10:40.818287 | controller | included: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-01 00:10:40.825141 | 
2025-11-01 00:10:40.825212 | TASK [bindep : Look for bindep.txt]
2025-11-01 00:10:41.725533 | controller | ok
2025-11-01 00:10:41.731734 | 
2025-11-01 00:10:41.731820 | TASK [bindep : Define bindep_file fact]
2025-11-01 00:10:41.748980 | controller | skipping: Conditional result was False
2025-11-01 00:10:41.765355 | 
2025-11-01 00:10:41.765543 | TASK [bindep : Look for other-requirements.txt]
2025-11-01 00:10:42.369195 | controller | ok
2025-11-01 00:10:42.380070 | 
2025-11-01 00:10:42.380221 | TASK [bindep : Define bindep_file fact]
2025-11-01 00:10:42.405784 | controller | skipping: Conditional result was False
2025-11-01 00:10:42.420540 | 
2025-11-01 00:10:42.420743 | TASK [bindep : Look for bindep fallback file]
2025-11-01 00:10:42.446821 | controller | skipping: Conditional result was False
2025-11-01 00:10:42.455328 | 
2025-11-01 00:10:42.455447 | TASK [bindep : Define bindep_file fact]
2025-11-01 00:10:42.479219 | controller | skipping: Conditional result was False
2025-11-01 00:10:42.486473 | 
2025-11-01 00:10:42.486569 | TASK [bindep : Include bindep tasks]
2025-11-01 00:10:42.510312 | controller | skipping: Conditional result was False
2025-11-01 00:10:42.518934 | 
2025-11-01 00:10:42.519048 | TASK [bindep : Include install tasks]
2025-11-01 00:10:42.543644 | controller | skipping: Conditional result was False
2025-11-01 00:10:42.550445 | 
2025-11-01 00:10:42.550531 | LOOP [bindep : Include package tasks]
2025-11-01 00:10:42.615688 | 
2025-11-01 00:10:42.615884 | TASK [Run test-setup role]
2025-11-01 00:10:42.637628 | controller | ok
2025-11-01 00:10:42.659575 | 
2025-11-01 00:10:42.659726 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-01 00:10:43.345169 | controller | ok
2025-11-01 00:10:43.362078 | 
2025-11-01 00:10:43.362248 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-01 00:10:43.738399 | controller | skipping: Conditional result was False
2025-11-01 00:10:43.795210 | 
2025-11-01 00:10:43.795312 | PLAY RECAP
2025-11-01 00:10:43.795368 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-01 00:10:43.795398 | 
2025-11-01 00:10:43.901288 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-01 00:10:43.902351 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-01 00:10:44.543335 | 
2025-11-01 00:10:44.543492 | PLAY [controller]
2025-11-01 00:10:44.566140 | 
2025-11-01 00:10:44.566275 | TASK [Create the /root directory]
2025-11-01 00:10:45.573362 | controller | ok
2025-11-01 00:10:45.588313 | 
2025-11-01 00:10:45.588478 | TASK [Install glibc-langpack-en]
2025-11-01 00:10:52.948396 | controller | ok: Nothing to do
2025-11-01 00:10:52.957781 | 
2025-11-01 00:10:52.957875 | TASK [Ensure controller directory exists]
2025-11-01 00:10:53.768261 | controller | changed
2025-11-01 00:10:53.784214 | 
2025-11-01 00:10:53.784527 | TASK [Install container runtime]
2025-11-01 00:10:53.841233 | controller | ok
2025-11-01 00:10:53.895061 | 
2025-11-01 00:10:53.895259 | LOOP [ensure-podman : Find distribution installation]
2025-11-01 00:10:53.937429 | controller | ok: "/var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-01 00:10:53.952220 | controller | included: /var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-01 00:10:53.961735 | 
2025-11-01 00:10:53.961861 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-01 00:12:42.424041 | controller | changed
2025-11-01 00:12:42.439149 | 
2025-11-01 00:12:42.439298 | TASK [ensure-podman : Fetch podman version]
2025-11-01 00:12:43.569032 | controller | Client:       Podman Engine
2025-11-01 00:12:43.600786 | controller | Version:      4.6.2
2025-11-01 00:12:43.600839 | controller | API Version:  4.6.2
2025-11-01 00:12:43.600847 | controller | Go Version:   go1.19.12
2025-11-01 00:12:43.600865 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-01 00:12:43.600874 | controller | OS/Arch:      linux/amd64
2025-11-01 00:12:43.809006 | controller | ok: Runtime: 0:00:00.267018
2025-11-01 00:12:43.817760 | 
2025-11-01 00:12:43.817863 | TASK [ensure-podman : Print podman version installed]
2025-11-01 00:12:43.850465 | Podman version: Client:       Podman Engine
2025-11-01 00:12:43.850620 | Version:      4.6.2
2025-11-01 00:12:43.850658 | API Version:  4.6.2
2025-11-01 00:12:43.850718 | Go Version:   go1.19.12
2025-11-01 00:12:43.850739 | Built:        Mon Aug 28 19:38:31 2023
2025-11-01 00:12:43.850761 | OS/Arch:      linux/amd64
2025-11-01 00:12:43.858480 | 
2025-11-01 00:12:43.858553 | TASK [ensure-podman : Validate podman engine]
2025-11-01 00:12:44.219652 | controller | skipping: Conditional result was False
2025-11-01 00:12:44.228450 | 
2025-11-01 00:12:44.228918 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-01 00:12:44.254036 | controller | skipping: Conditional result was False
2025-11-01 00:12:44.270298 | 
2025-11-01 00:12:44.270423 | TASK [Ensure python3.8 is present]
2025-11-01 00:12:44.295918 | controller | skipping: Conditional result was False
2025-11-01 00:12:44.305140 | 
2025-11-01 00:12:44.305246 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-01 00:12:44.328808 | controller | ok
2025-11-01 00:12:44.356295 | 
2025-11-01 00:12:44.356436 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-01 00:12:47.581621 | controller | ok: Nothing to do
2025-11-01 00:12:47.587723 | 
2025-11-01 00:12:47.587789 | TASK [our-ensure-python : Also install python3-devel]
2025-11-01 00:13:00.836126 | controller | changed
2025-11-01 00:13:00.847478 | 
2025-11-01 00:13:00.847539 | TASK [Run ensure-virtualenv role]
2025-11-01 00:13:00.867533 | controller | ok
2025-11-01 00:13:00.888848 | 
2025-11-01 00:13:00.888927 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-01 00:13:01.634890 | controller | /usr/bin/virtualenv
2025-11-01 00:13:01.770528 | controller | ok: Runtime: 0:00:00.006222
2025-11-01 00:13:01.779350 | 
2025-11-01 00:13:01.779465 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-01 00:13:01.801439 | controller | skipping: Conditional result was False
2025-11-01 00:13:01.801735 | controller | ok: All items complete
2025-11-01 00:13:01.801776 | 
2025-11-01 00:13:01.817837 | 
2025-11-01 00:13:01.817954 | TASK [Find the full path of the Python interpreter]
2025-11-01 00:13:02.415295 | controller | /usr/bin/python3
2025-11-01 00:13:02.672472 | controller | ok
2025-11-01 00:13:02.686481 | 
2025-11-01 00:13:02.686713 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-01 00:13:04.340425 | controller | created virtual environment CPython3.11.0.final.0-64 in 700ms
2025-11-01 00:13:04.405861 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-01 00:13:04.405910 | 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-11-01 00:13:04.405928 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-01 00:13:04.405946 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-01 00:13:04.566142 | controller | changed
2025-11-01 00:13:04.584783 | 
2025-11-01 00:13:04.585001 | TASK [Set selinux package]
2025-11-01 00:13:04.629583 | controller | ok
2025-11-01 00:13:04.647894 | 
2025-11-01 00:13:04.648041 | TASK [Set selinux package (Fedora)]
2025-11-01 00:13:04.707865 | controller | ok
2025-11-01 00:13:04.722761 | 
2025-11-01 00:13:04.722953 | TASK [Install selinux into virtualenv]
2025-11-01 00:13:07.287463 | controller | Collecting selinux-please-lie-to-me
2025-11-01 00:13:07.372031 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-01 00:13:07.854118 | controller | Collecting setuptools<50.0.0
2025-11-01 00:13:07.860328 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-01 00:13:07.930111 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 12.3 MB/s eta 0:00:00
2025-11-01 00:13:08.045387 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-01 00:13:08.045709 | controller |   Attempting uninstall: setuptools
2025-11-01 00:13:08.049485 | controller |     Found existing installation: setuptools 62.6.0
2025-11-01 00:13:08.139675 | controller |     Uninstalling setuptools-62.6.0:
2025-11-01 00:13:08.151519 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-01 00:13:08.912328 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-01 00:13:09.086594 | controller |
2025-11-01 00:13:09.312032 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-01 00:13:09.312087 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-01 00:13:09.612875 | controller | ok: Runtime: 0:00:03.855090
2025-11-01 00:13:09.626724 | 
2025-11-01 00:13:09.626899 | TASK [Install pytest-forked into virtualenv]
2025-11-01 00:13:11.149759 | controller | Collecting pytest-forked
2025-11-01 00:13:11.212115 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-01 00:13:11.275319 | controller | Collecting py
2025-11-01 00:13:11.281055 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-01 00:13:11.311399 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.5 MB/s eta 0:00:00
2025-11-01 00:13:11.465080 | controller | Collecting pytest>=3.10
2025-11-01 00:13:11.472794 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-11-01 00:13:11.500418 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 19.1 MB/s eta 0:00:00
2025-11-01 00:13:11.561085 | controller | Collecting iniconfig>=1
2025-11-01 00:13:11.566821 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-01 00:13:11.624345 | controller | Collecting packaging>=20
2025-11-01 00:13:11.631548 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-01 00:13:11.647189 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 5.1 MB/s eta 0:00:00
2025-11-01 00:13:11.694760 | controller | Collecting pluggy<2,>=1.5
2025-11-01 00:13:11.700313 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-01 00:13:11.767571 | controller | Collecting pygments>=2.7.2
2025-11-01 00:13:11.774068 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-01 00:13:11.815585 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 36.2 MB/s eta 0:00:00
2025-11-01 00:13:11.924309 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-01 00:13:14.296066 | 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-11-01 00:13:14.310038 | controller |
2025-11-01 00:13:14.640425 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-01 00:13:14.640518 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-01 00:13:15.022022 | controller | ok: Runtime: 0:00:04.238632
2025-11-01 00:13:15.036999 | 
2025-11-01 00:13:15.037246 | TASK [Update pip]
2025-11-01 00:13:16.673357 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-01 00:13:16.953477 | controller | Collecting pip
2025-11-01 00:13:17.034870 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-01 00:13:17.129547 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 20.5 MB/s eta 0:00:00
2025-11-01 00:13:17.261200 | controller | Installing collected packages: pip
2025-11-01 00:13:17.261596 | controller |   Attempting uninstall: pip
2025-11-01 00:13:17.265402 | controller |     Found existing installation: pip 22.2.2
2025-11-01 00:13:17.476059 | controller |     Uninstalling pip-22.2.2:
2025-11-01 00:13:17.505270 | controller |       Successfully uninstalled pip-22.2.2
2025-11-01 00:13:19.566475 | controller | Successfully installed pip-25.3
2025-11-01 00:13:19.929350 | controller | ok: Runtime: 0:00:03.759923
2025-11-01 00:13:19.938394 | 
2025-11-01 00:13:19.938488 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-01 00:13:20.762564 | controller | changed
2025-11-01 00:13:20.775630 | 
2025-11-01 00:13:20.775835 | TASK [Install ansible into virtualenv]
2025-11-01 00:13:22.008176 | controller | Processing ./src/github.com/ansible/ansible
2025-11-01 00:13:22.012936 | controller |   Installing build dependencies: started
2025-11-01 00:13:23.583317 | controller |   Installing build dependencies: finished with status 'done'
2025-11-01 00:13:23.584360 | controller |   Getting requirements to build wheel: started
2025-11-01 00:13:24.928341 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-01 00:13:25.681300 | controller |   Preparing metadata (pyproject.toml): started
2025-11-01 00:13:25.681371 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-01 00:13:25.684342 | 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-11-01 00:13:25.688773 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-01 00:13:26.182865 | controller | ERROR
2025-11-01 00:13:26.183074 | controller | {
2025-11-01 00:13:26.183107 | controller |   "delta": "0:00:04.366193",
2025-11-01 00:13:26.183127 | controller |   "end": "2025-11-01 00:13:25.825976",
2025-11-01 00:13:26.183145 | controller |   "msg": "non-zero return code",
2025-11-01 00:13:26.183171 | controller |   "rc": 1,
2025-11-01 00:13:26.183188 | controller |   "start": "2025-11-01 00:13:21.459783"
2025-11-01 00:13:26.183204 | controller | }
failure
2025-11-01 00:13:26.184835 | 
2025-11-01 00:13:26.184884 | PLAY RECAP
2025-11-01 00:13:26.184935 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-01 00:13:26.184967 | 
2025-11-01 00:13:26.292462 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-01 00:13:26.293450 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-01 00:13:26.923236 | 
2025-11-01 00:13:26.923380 | PLAY [all]
2025-11-01 00:13:26.946475 | 
2025-11-01 00:13:26.946615 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-01 00:13:28.787873 | controller | changed: non-zero return code
2025-11-01 00:13:28.802612 | 
2025-11-01 00:13:28.802867 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-01 00:13:28.831210 | controller | skipping: Conditional result was False
2025-11-01 00:13:28.846033 | 
2025-11-01 00:13:28.846238 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-01 00:13:28.882951 | 
2025-11-01 00:13:28.883249 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-01 00:13:28.918754 | 
2025-11-01 00:13:28.919048 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-01 00:13:28.943937 | controller | skipping: Conditional result was False
2025-11-01 00:13:28.952516 | 
2025-11-01 00:13:28.952611 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-01 00:13:28.988096 | 
2025-11-01 00:13:28.988314 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-01 00:13:29.013644 | controller | skipping: Conditional result was False
2025-11-01 00:13:29.022902 | 
2025-11-01 00:13:29.023024 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-01 00:13:29.048387 | controller | skipping: Conditional result was False
2025-11-01 00:13:29.057552 | 
2025-11-01 00:13:29.057653 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-01 00:13:29.082635 | controller | skipping: Conditional result was False
2025-11-01 00:13:29.121450 | 
2025-11-01 00:13:29.121561 | PLAY RECAP
2025-11-01 00:13:29.121622 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-01 00:13:29.121651 | 
2025-11-01 00:13:29.232045 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-01 00:13:29.232929 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-01 00:13:29.874740 | 
2025-11-01 00:13:29.874871 | PLAY [all:!appliance*]
2025-11-01 00:13:29.898186 | 
2025-11-01 00:13:29.898302 | TASK [unregister the node]
2025-11-01 00:13:30.253781 | controller | skipping: Conditional result was False
2025-11-01 00:13:30.267064 | 
2025-11-01 00:13:30.267297 | TASK [include_role : fetch-output]
2025-11-01 00:13:30.326574 | controller | ok
2025-11-01 00:13:30.372109 | 
2025-11-01 00:13:30.372282 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-01 00:13:30.428327 | controller | skipping: Conditional result was False
2025-11-01 00:13:30.437203 | 
2025-11-01 00:13:30.437303 | TASK [fetch-output : Set log path for single node]
2025-11-01 00:13:30.480022 | controller | ok
2025-11-01 00:13:30.487540 | 
2025-11-01 00:13:30.487630 | LOOP [fetch-output : Ensure local output dirs]
2025-11-01 00:13:30.922192 | controller -> localhost | ok: "/var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/logs"
2025-11-01 00:13:31.157264 | controller -> localhost | changed: "/var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/artifacts"
2025-11-01 00:13:31.396485 | controller -> localhost | changed: "/var/lib/zuul/builds/7bfc2a04b2d64f5db6045f48522262fb/work/docs"
2025-11-01 00:13:31.420951 | 
2025-11-01 00:13:31.421205 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-01 00:13:33.615979 | controller | changed:
2025-11-01 00:13:33.616158 | controller | .d..t...... ./
2025-11-01 00:13:33.616188 | controller | cd+++++++++ controller/
2025-11-01 00:13:33.616224 | controller | changed: All items complete
2025-11-01 00:13:33.616246 | 
2025-11-01 00:13:35.642960 | controller | changed: .d..t...... ./
2025-11-01 00:13:37.688834 | controller | changed: .d..t...... ./
2025-11-01 00:13:37.710853 | 
2025-11-01 00:13:37.711011 | TASK [include_role : fetch-output-openshift]
2025-11-01 00:13:37.728236 | controller | skipping: Conditional result was False
2025-11-01 00:13:37.740041 | 
2025-11-01 00:13:37.740189 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-01 00:13:37.792944 | controller | skipping: Conditional result was False
2025-11-01 00:13:37.805328 | controller | skipping: Conditional result was False
2025-11-01 00:13:37.862919 | 
2025-11-01 00:13:37.863050 | PLAY [localhost]
2025-11-01 00:13:37.883200 | 
2025-11-01 00:13:37.883295 | TASK [Run Zuul manifest role]
2025-11-01 00:13:37.913776 | localhost | ok
2025-11-01 00:13:37.934213 | 
2025-11-01 00:13:37.934384 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-01 00:13:38.314904 | localhost | changed
2025-11-01 00:13:38.319950 | 
2025-11-01 00:13:38.320161 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-01 00:13:38.348741 | localhost | ok
2025-11-01 00:13:38.357465 | 
2025-11-01 00:13:38.357528 | TASK [Set zuul-log-path fact]
2025-11-01 00:13:38.376402 | localhost | ok
2025-11-01 00:13:38.415019 | 
2025-11-01 00:13:38.415130 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-01 00:13:38.443800 | localhost | ok
2025-11-01 00:13:38.452543 | 
2025-11-01 00:13:38.452611 | LOOP [Run upload-logs-swift role]
2025-11-01 00:13:38.487798 | localhost | Output suppressed because no_log was given
2025-11-01 00:13:38.513305 | 
2025-11-01 00:13:38.513397 | TASK [Set zuul-log-path fact]
2025-11-01 00:13:38.547494 | localhost | skipping: Conditional result was False
2025-11-01 00:13:38.555463 | 
2025-11-01 00:13:38.555601 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-01 00:13:38.955394 | localhost -> localhost | ok: Runtime: 0:00:00.008478
2025-11-01 00:13:38.969099 | 
2025-11-01 00:13:38.969274 | TASK [upload-logs-swift : Upload logs to swift]