2025-12-19 00:21:35.366068 | Job console starting...
2025-12-19 00:21:35.375168 | Updating repositories
2025-12-19 00:21:35.505809 | Preparing job workspace
2025-12-19 00:21:39.111068 | Running Ansible setup...
2025-12-19 00:21:46.707482 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-19 00:21:47.348322 | 
2025-12-19 00:21:47.348530 | PLAY [localhost]
2025-12-19 00:21:47.356870 | 
2025-12-19 00:21:47.356941 | TASK [Gathering Facts]
2025-12-19 00:21:48.502890 | localhost | ok
2025-12-19 00:21:48.543926 | 
2025-12-19 00:21:48.544221 | TASK [Setup log path fact]
2025-12-19 00:21:48.573396 | localhost | ok
2025-12-19 00:21:48.589298 | 
2025-12-19 00:21:48.589455 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-19 00:21:48.622023 | localhost | ok
2025-12-19 00:21:48.634607 | 
2025-12-19 00:21:48.634810 | TASK [emit-job-header : Print job information]
2025-12-19 00:21:48.663777 | # Job Information
2025-12-19 00:21:48.663966 | Ansible Version: 2.15.12
2025-12-19 00:21:48.663997 | Job: ansible-test-sanity-docker-devel
2025-12-19 00:21:48.664018 | Pipeline: periodic
2025-12-19 00:21:48.664036 | Executor: ze04.softwarefactory-project.io
2025-12-19 00:21:48.664054 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-19 00:21:48.664074 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/ddb/ansible/ddbbde1301fc441d977ea2c2d271bd07/
2025-12-19 00:21:48.664096 | Event ID: 5e57919544954c60be3d868aae791c40
2025-12-19 00:21:48.668466 | 
2025-12-19 00:21:48.668534 | LOOP [emit-job-header : Print node information]
2025-12-19 00:21:48.777464 | localhost | ok:
2025-12-19 00:21:48.777707 | localhost | # Node Information
2025-12-19 00:21:48.777750 | localhost | Inventory Hostname: controller
2025-12-19 00:21:48.777780 | localhost | Hostname: np0005566452
2025-12-19 00:21:48.777807 | localhost | Username: zuul
2025-12-19 00:21:48.777839 | localhost | Distro: Fedora 37
2025-12-19 00:21:48.777866 | localhost | Provider: ansible-vexxhost-ams1
2025-12-19 00:21:48.777891 | localhost | Region: ams1
2025-12-19 00:21:48.777916 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-19 00:21:48.777940 | localhost | Product Name: OpenStack Nova
2025-12-19 00:21:48.777964 | localhost | Interface IP: 38.129.16.138
2025-12-19 00:21:48.797067 | 
2025-12-19 00:21:48.797184 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-19 00:21:49.223060 | localhost -> localhost | changed
2025-12-19 00:21:49.235272 | 
2025-12-19 00:21:49.235419 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-19 00:21:50.276283 | localhost -> localhost | changed
2025-12-19 00:21:50.297587 | 
2025-12-19 00:21:50.297650 | PLAY [all:!appliance*]
2025-12-19 00:21:50.314853 | 
2025-12-19 00:21:50.314921 | TASK [include_role : start-zuul-console]
2025-12-19 00:21:50.346878 | controller | ok
2025-12-19 00:21:50.360672 | 
2025-12-19 00:21:50.360764 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-19 00:21:51.422430 | controller | ok
2025-12-19 00:21:51.453708 | 
2025-12-19 00:21:51.453965 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-19 00:21:54.074926 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-19 00:21:54.087381 | 
2025-12-19 00:21:54.087566 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-19 00:21:54.451861 | controller | skipping: Conditional result was False
2025-12-19 00:21:54.463651 | 
2025-12-19 00:21:54.463876 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-19 00:21:54.501769 | controller | skipping: Conditional result was False
2025-12-19 00:21:54.515149 | 
2025-12-19 00:21:54.515383 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-19 00:21:54.554118 | controller | skipping: Conditional result was False
2025-12-19 00:21:54.565457 | 
2025-12-19 00:21:54.565578 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-19 00:21:54.603248 | controller | skipping: Conditional result was False
2025-12-19 00:21:54.613963 | 
2025-12-19 00:21:54.614082 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-19 00:21:54.651894 | controller | skipping: Conditional result was False
2025-12-19 00:21:54.662056 | 
2025-12-19 00:21:54.662160 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-19 00:21:54.699416 | controller | skipping: Conditional result was False
2025-12-19 00:21:54.717148 | 
2025-12-19 00:21:54.717244 | TASK [Disable Fedora Modular]
2025-12-19 00:21:55.902541 | controller | changed
2025-12-19 00:21:55.916508 | 
2025-12-19 00:21:55.916635 | TASK [Enable EPEL]
2025-12-19 00:21:55.945419 | controller | skipping: Conditional result was False
2025-12-19 00:21:55.962020 | 
2025-12-19 00:21:55.962187 | TASK [Register the RHEL node]
2025-12-19 00:21:56.406698 | 
2025-12-19 00:21:56.407198 | TASK [Show the subscription-manager status]
2025-12-19 00:21:56.787339 | controller | skipping: Conditional result was False
2025-12-19 00:21:56.801684 | 
2025-12-19 00:21:56.801850 | TASK [Enable EPEL on RHEL]
2025-12-19 00:21:57.187800 | controller | skipping: Conditional result was False
2025-12-19 00:21:57.201276 | 
2025-12-19 00:21:57.201411 | TASK [Install git and tox]
2025-12-19 00:24:00.280492 | controller | changed
2025-12-19 00:24:00.294190 | 
2025-12-19 00:24:00.294317 | TASK [include_role : prepare-workspace]
2025-12-19 00:24:00.328617 | controller | ok
2025-12-19 00:24:00.353114 | 
2025-12-19 00:24:00.353358 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-19 00:24:01.161395 | controller | ok
2025-12-19 00:24:01.168155 | 
2025-12-19 00:24:01.168221 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-19 00:24:17.076916 | controller | Output suppressed because no_log was given
2025-12-19 00:24:17.092479 | 
2025-12-19 00:24:17.092637 | TASK [include_role : prepare-workspace-openshift]
2025-12-19 00:24:17.124919 | controller | skipping: Conditional result was False
2025-12-19 00:24:17.160469 | 
2025-12-19 00:24:17.160541 | PLAY [all:!appliance]
2025-12-19 00:24:17.176893 | 
2025-12-19 00:24:17.176958 | TASK [Run add-build-sshkey role (RSA)]
2025-12-19 00:24:17.218078 | controller | ok
2025-12-19 00:24:17.234166 | 
2025-12-19 00:24:17.234235 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-19 00:24:17.473101 | controller -> localhost | ok
2025-12-19 00:24:17.480334 | 
2025-12-19 00:24:17.480402 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-19 00:24:17.512825 | controller | ok
2025-12-19 00:24:17.527278 | controller | included: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-19 00:24:17.534388 | 
2025-12-19 00:24:17.534451 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-19 00:24:18.038225 | controller -> localhost | Generating public/private rsa key pair.
2025-12-19 00:24:18.038489 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/ddbbde1301fc441d977ea2c2d271bd07_id_rsa.
2025-12-19 00:24:18.038520 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/ddbbde1301fc441d977ea2c2d271bd07_id_rsa.pub.
2025-12-19 00:24:18.038544 | controller -> localhost | The key fingerprint is:
2025-12-19 00:24:18.038573 | controller -> localhost | SHA256:No1sPEGKWd95N8oUOJClzV9JY2+FhDfx+daXMP1D28M zuul-build-sshkey
2025-12-19 00:24:18.038600 | controller -> localhost | The key's randomart image is:
2025-12-19 00:24:18.038645 | controller -> localhost | +---[RSA 2048]----+
2025-12-19 00:24:18.038672 | controller -> localhost | |      . o+...o*o.|
2025-12-19 00:24:18.038733 | controller -> localhost | |     + +.=o..+==o|
2025-12-19 00:24:18.038760 | controller -> localhost | |    o . + =.o+==+|
2025-12-19 00:24:18.038789 | controller -> localhost | |       o + = +=oB|
2025-12-19 00:24:18.038815 | controller -> localhost | |        S . +  EB|
2025-12-19 00:24:18.038845 | controller -> localhost | |       o o     .+|
2025-12-19 00:24:18.038871 | controller -> localhost | |                 |
2025-12-19 00:24:18.038892 | controller -> localhost | |                 |
2025-12-19 00:24:18.038913 | controller -> localhost | |                 |
2025-12-19 00:24:18.038945 | controller -> localhost | +----[SHA256]-----+
2025-12-19 00:24:18.039010 | controller -> localhost | ok: Runtime: 0:00:00.150341
2025-12-19 00:24:18.046795 | 
2025-12-19 00:24:18.046868 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-19 00:24:18.080843 | controller | ok
2025-12-19 00:24:18.096168 | controller | included: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-19 00:24:18.109580 | 
2025-12-19 00:24:18.109711 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-19 00:24:18.135806 | controller | skipping: Conditional result was False
2025-12-19 00:24:18.143104 | 
2025-12-19 00:24:18.143189 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-19 00:24:19.196047 | controller | changed
2025-12-19 00:24:19.208937 | 
2025-12-19 00:24:19.209073 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-19 00:24:19.878458 | controller | ok
2025-12-19 00:24:19.896941 | 
2025-12-19 00:24:19.897208 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-19 00:24:22.882646 | controller | changed
2025-12-19 00:24:22.891136 | 
2025-12-19 00:24:22.891282 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-19 00:24:25.915199 | controller | changed
2025-12-19 00:24:25.928425 | 
2025-12-19 00:24:25.928561 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-19 00:24:25.945195 | controller | skipping: Conditional result was False
2025-12-19 00:24:25.959725 | 
2025-12-19 00:24:25.959877 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-19 00:24:26.479469 | controller -> localhost | changed
2025-12-19 00:24:26.492984 | 
2025-12-19 00:24:26.493083 | TASK [add-build-sshkey : Add back temp key]
2025-12-19 00:24:26.754881 | controller -> localhost | Identity added: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/ddbbde1301fc441d977ea2c2d271bd07_id_rsa (zuul-build-sshkey)
2025-12-19 00:24:26.755289 | controller -> localhost | ok: Runtime: 0:00:00.016572
2025-12-19 00:24:26.766639 | 
2025-12-19 00:24:26.766757 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-19 00:24:27.712607 | controller | ok
2025-12-19 00:24:27.728807 | 
2025-12-19 00:24:27.728950 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-19 00:24:27.764909 | controller | skipping: Conditional result was False
2025-12-19 00:24:27.777311 | 
2025-12-19 00:24:27.777402 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-19 00:24:27.804962 | controller | ok
2025-12-19 00:24:27.833496 | 
2025-12-19 00:24:27.833648 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-19 00:24:28.084966 | controller -> localhost | ok
2025-12-19 00:24:28.093189 | 
2025-12-19 00:24:28.093276 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-19 00:24:28.124957 | controller | ok
2025-12-19 00:24:28.136604 | controller | included: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-19 00:24:28.144739 | 
2025-12-19 00:24:28.144814 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-19 00:24:28.403456 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-19 00:24:28.403707 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/ddbbde1301fc441d977ea2c2d271bd07_id_ecdsa.
2025-12-19 00:24:28.403754 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/ddbbde1301fc441d977ea2c2d271bd07_id_ecdsa.pub.
2025-12-19 00:24:28.403796 | controller -> localhost | The key fingerprint is:
2025-12-19 00:24:28.403826 | controller -> localhost | SHA256:/2om7gmMzmNRoBuEAtx4mVVjHtOM6sfCGubP+3IrqcA zuul-build-sshkey
2025-12-19 00:24:28.403856 | controller -> localhost | The key's randomart image is:
2025-12-19 00:24:28.403883 | controller -> localhost | +---[ECDSA 521]---+
2025-12-19 00:24:28.403908 | controller -> localhost | |+.o +..*+        |
2025-12-19 00:24:28.403934 | controller -> localhost | |oo.=. o.+o       |
2025-12-19 00:24:28.403959 | controller -> localhost | |.... ...         |
2025-12-19 00:24:28.403984 | controller -> localhost | |  o  ..          |
2025-12-19 00:24:28.404008 | controller -> localhost | |   oo.. S        |
2025-12-19 00:24:28.404033 | controller -> localhost | |. .o.* o .       |
2025-12-19 00:24:28.404058 | controller -> localhost | | Eo +.*   .      |
2025-12-19 00:24:28.404083 | controller -> localhost | |  .=++ o..o.     |
2025-12-19 00:24:28.404107 | controller -> localhost | |   o==*==+...    |
2025-12-19 00:24:28.404132 | controller -> localhost | +----[SHA256]-----+
2025-12-19 00:24:28.404194 | controller -> localhost | ok: Runtime: 0:00:00.010565
2025-12-19 00:24:28.413998 | 
2025-12-19 00:24:28.414087 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-19 00:24:28.446195 | controller | ok
2025-12-19 00:24:28.456897 | controller | included: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-19 00:24:28.469239 | 
2025-12-19 00:24:28.469331 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-19 00:24:28.495099 | controller | skipping: Conditional result was False
2025-12-19 00:24:28.507989 | 
2025-12-19 00:24:28.508162 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-19 00:24:29.394556 | controller | changed
2025-12-19 00:24:29.400352 | 
2025-12-19 00:24:29.400415 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-19 00:24:30.051120 | controller | ok
2025-12-19 00:24:30.057326 | 
2025-12-19 00:24:30.057406 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-19 00:24:33.055983 | controller | changed
2025-12-19 00:24:33.073204 | 
2025-12-19 00:24:33.073388 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-19 00:24:36.042577 | controller | changed
2025-12-19 00:24:36.057205 | 
2025-12-19 00:24:36.057343 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-19 00:24:36.086514 | controller | skipping: Conditional result was False
2025-12-19 00:24:36.104748 | 
2025-12-19 00:24:36.104918 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-19 00:24:36.452816 | controller -> localhost | changed
2025-12-19 00:24:36.466286 | 
2025-12-19 00:24:36.466375 | TASK [add-build-sshkey : Add back temp key]
2025-12-19 00:24:36.777994 | controller -> localhost | Identity added: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/ddbbde1301fc441d977ea2c2d271bd07_id_ecdsa (zuul-build-sshkey)
2025-12-19 00:24:36.778552 | controller -> localhost | ok: Runtime: 0:00:00.015226
2025-12-19 00:24:36.808210 | 
2025-12-19 00:24:36.808381 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-19 00:24:37.537915 | controller | ok
2025-12-19 00:24:37.546298 | 
2025-12-19 00:24:37.546401 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-19 00:24:37.583926 | controller | skipping: Conditional result was False
2025-12-19 00:24:37.602081 | 
2025-12-19 00:24:37.602198 | TASK [include_role : remove-zuul-sshkey]
2025-12-19 00:24:37.628766 | controller | skipping: Conditional result was False
2025-12-19 00:24:37.639289 | 
2025-12-19 00:24:37.639397 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-19 00:24:38.291945 | controller | ok: "logs"
2025-12-19 00:24:38.292551 | controller | ok: All items complete
2025-12-19 00:24:38.292649 | 
2025-12-19 00:24:38.910969 | controller | ok: "artifacts"
2025-12-19 00:24:39.539271 | controller | ok: "docs"
2025-12-19 00:24:39.560863 | 
2025-12-19 00:24:39.561230 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-19 00:24:40.236979 | controller | changed: "logs"
2025-12-19 00:24:40.871159 | controller | changed: "artifacts"
2025-12-19 00:24:41.469507 | controller | changed: "docs"
2025-12-19 00:24:41.501603 | 
2025-12-19 00:24:41.501770 | PLAY RECAP
2025-12-19 00:24:41.501825 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-19 00:24:41.501852 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-19 00:24:41.501870 | 
2025-12-19 00:24:41.700502 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-19 00:24:41.702604 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-19 00:24:42.342966 | 
2025-12-19 00:24:42.343123 | PLAY [all]
2025-12-19 00:24:42.372385 | 
2025-12-19 00:24:42.372571 | TASK [Install binary dependencies]
2025-12-19 00:24:42.426200 | controller | ok
2025-12-19 00:24:42.449227 | 
2025-12-19 00:24:42.449355 | TASK [bindep : Include find tasks]
2025-12-19 00:24:42.492533 | controller | ok
2025-12-19 00:24:42.500838 | controller | included: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-19 00:24:42.508063 | 
2025-12-19 00:24:42.508127 | TASK [bindep : Look for bindep.txt]
2025-12-19 00:24:43.443666 | controller | ok
2025-12-19 00:24:43.458473 | 
2025-12-19 00:24:43.458742 | TASK [bindep : Define bindep_file fact]
2025-12-19 00:24:43.477494 | controller | skipping: Conditional result was False
2025-12-19 00:24:43.493123 | 
2025-12-19 00:24:43.493333 | TASK [bindep : Look for other-requirements.txt]
2025-12-19 00:24:44.103921 | controller | ok
2025-12-19 00:24:44.118825 | 
2025-12-19 00:24:44.118995 | TASK [bindep : Define bindep_file fact]
2025-12-19 00:24:44.156382 | controller | skipping: Conditional result was False
2025-12-19 00:24:44.170442 | 
2025-12-19 00:24:44.170633 | TASK [bindep : Look for bindep fallback file]
2025-12-19 00:24:44.208429 | controller | skipping: Conditional result was False
2025-12-19 00:24:44.223033 | 
2025-12-19 00:24:44.223218 | TASK [bindep : Define bindep_file fact]
2025-12-19 00:24:44.260232 | controller | skipping: Conditional result was False
2025-12-19 00:24:44.275235 | 
2025-12-19 00:24:44.275434 | TASK [bindep : Include bindep tasks]
2025-12-19 00:24:44.303478 | controller | skipping: Conditional result was False
2025-12-19 00:24:44.318500 | 
2025-12-19 00:24:44.318670 | TASK [bindep : Include install tasks]
2025-12-19 00:24:44.345862 | controller | skipping: Conditional result was False
2025-12-19 00:24:44.364648 | 
2025-12-19 00:24:44.364908 | LOOP [bindep : Include package tasks]
2025-12-19 00:24:44.441451 | 
2025-12-19 00:24:44.441804 | TASK [Run test-setup role]
2025-12-19 00:24:44.467187 | controller | ok
2025-12-19 00:24:44.491457 | 
2025-12-19 00:24:44.491551 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-19 00:24:45.113444 | controller | ok
2025-12-19 00:24:45.127566 | 
2025-12-19 00:24:45.127738 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-19 00:24:45.506398 | controller | skipping: Conditional result was False
2025-12-19 00:24:45.571481 | 
2025-12-19 00:24:45.571745 | PLAY RECAP
2025-12-19 00:24:45.571823 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-19 00:24:45.571857 | 
2025-12-19 00:24:45.744159 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-19 00:24:45.745231 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-19 00:24:46.418623 | 
2025-12-19 00:24:46.418835 | PLAY [controller]
2025-12-19 00:24:46.439340 | 
2025-12-19 00:24:46.439433 | TASK [Create the /root directory]
2025-12-19 00:24:47.438784 | controller | ok
2025-12-19 00:24:47.447182 | 
2025-12-19 00:24:47.447292 | TASK [Install glibc-langpack-en]
2025-12-19 00:24:55.378874 | controller | ok: Nothing to do
2025-12-19 00:24:55.393164 | 
2025-12-19 00:24:55.393393 | TASK [Ensure controller directory exists]
2025-12-19 00:24:56.205406 | controller | changed
2025-12-19 00:24:56.211322 | 
2025-12-19 00:24:56.211392 | TASK [Install container runtime]
2025-12-19 00:24:56.282965 | controller | ok
2025-12-19 00:24:56.323729 | 
2025-12-19 00:24:56.323901 | LOOP [ensure-podman : Find distribution installation]
2025-12-19 00:24:56.355911 | controller | ok: "/var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-19 00:24:56.367950 | controller | included: /var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-19 00:24:56.375156 | 
2025-12-19 00:24:56.375237 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-19 00:26:53.532083 | controller | changed
2025-12-19 00:26:53.538531 | 
2025-12-19 00:26:53.538610 | TASK [ensure-podman : Fetch podman version]
2025-12-19 00:26:54.778969 | controller | Client:       Podman Engine
2025-12-19 00:26:54.809730 | controller | Version:      4.6.2
2025-12-19 00:26:54.809778 | controller | API Version:  4.6.2
2025-12-19 00:26:54.809789 | controller | Go Version:   go1.19.12
2025-12-19 00:26:54.809821 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-19 00:26:54.809829 | controller | OS/Arch:      linux/amd64
2025-12-19 00:26:55.428433 | controller | ok: Runtime: 0:00:00.291957
2025-12-19 00:26:55.437653 | 
2025-12-19 00:26:55.437774 | TASK [ensure-podman : Print podman version installed]
2025-12-19 00:26:55.493565 | Podman version: Client:       Podman Engine
2025-12-19 00:26:55.496331 | Version:      4.6.2
2025-12-19 00:26:55.496382 | API Version:  4.6.2
2025-12-19 00:26:55.496411 | Go Version:   go1.19.12
2025-12-19 00:26:55.496436 | Built:        Mon Aug 28 19:38:31 2023
2025-12-19 00:26:55.496462 | OS/Arch:      linux/amd64
2025-12-19 00:26:55.512073 | 
2025-12-19 00:26:55.512161 | TASK [ensure-podman : Validate podman engine]
2025-12-19 00:26:55.875073 | controller | skipping: Conditional result was False
2025-12-19 00:26:55.891377 | 
2025-12-19 00:26:55.891538 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-19 00:26:55.909637 | controller | skipping: Conditional result was False
2025-12-19 00:26:55.943162 | 
2025-12-19 00:26:55.943418 | TASK [Ensure python3.8 is present]
2025-12-19 00:26:55.961891 | controller | skipping: Conditional result was False
2025-12-19 00:26:55.971887 | 
2025-12-19 00:26:55.972012 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-19 00:26:55.995992 | controller | ok
2025-12-19 00:26:56.023936 | 
2025-12-19 00:26:56.024069 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-19 00:26:59.464093 | controller | ok: Nothing to do
2025-12-19 00:26:59.475222 | 
2025-12-19 00:26:59.475721 | TASK [our-ensure-python : Also install python3-devel]
2025-12-19 00:27:13.834696 | controller | changed
2025-12-19 00:27:13.846758 | 
2025-12-19 00:27:13.846839 | TASK [Run ensure-virtualenv role]
2025-12-19 00:27:13.868877 | controller | ok
2025-12-19 00:27:13.892643 | 
2025-12-19 00:27:13.892792 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-19 00:27:14.667955 | controller | /usr/bin/virtualenv
2025-12-19 00:27:15.288451 | controller | ok: Runtime: 0:00:00.005287
2025-12-19 00:27:15.294911 | 
2025-12-19 00:27:15.294984 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-19 00:27:15.330629 | controller | skipping: Conditional result was False
2025-12-19 00:27:15.331092 | controller | ok: All items complete
2025-12-19 00:27:15.331133 | 
2025-12-19 00:27:15.352506 | 
2025-12-19 00:27:15.352710 | TASK [Find the full path of the Python interpreter]
2025-12-19 00:27:16.110906 | controller | /usr/bin/python3
2025-12-19 00:27:16.711939 | controller | ok
2025-12-19 00:27:16.725620 | 
2025-12-19 00:27:16.725830 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-19 00:27:18.521980 | controller | created virtual environment CPython3.11.0.final.0-64 in 834ms
2025-12-19 00:27:18.594081 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-19 00:27:18.594139 | 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-19 00:27:18.594154 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-19 00:27:18.594174 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-19 00:27:19.105406 | controller | changed
2025-12-19 00:27:19.117156 | 
2025-12-19 00:27:19.117272 | TASK [Set selinux package]
2025-12-19 00:27:19.149506 | controller | ok
2025-12-19 00:27:19.162059 | 
2025-12-19 00:27:19.162185 | TASK [Set selinux package (Fedora)]
2025-12-19 00:27:19.226097 | controller | ok
2025-12-19 00:27:19.234900 | 
2025-12-19 00:27:19.234995 | TASK [Install selinux into virtualenv]
2025-12-19 00:27:22.299704 | controller | Collecting selinux-please-lie-to-me
2025-12-19 00:27:22.376354 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-19 00:27:22.916113 | controller | Collecting setuptools<50.0.0
2025-12-19 00:27:22.946654 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-19 00:27:23.004933 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.2 MB/s eta 0:00:00
2025-12-19 00:27:23.188972 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-19 00:27:23.189287 | controller |   Attempting uninstall: setuptools
2025-12-19 00:27:23.194892 | controller |     Found existing installation: setuptools 62.6.0
2025-12-19 00:27:23.292238 | controller |     Uninstalling setuptools-62.6.0:
2025-12-19 00:27:23.306387 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-19 00:27:23.989042 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-19 00:27:24.192293 | controller |
2025-12-19 00:27:24.438385 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-19 00:27:24.438436 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-19 00:27:24.626019 | controller | ok: Runtime: 0:00:04.356699
2025-12-19 00:27:24.647150 | 
2025-12-19 00:27:24.647376 | TASK [Install pytest-forked into virtualenv]
2025-12-19 00:27:26.105701 | controller | Collecting pytest-forked
2025-12-19 00:27:26.165709 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-19 00:27:26.239676 | controller | Collecting py
2025-12-19 00:27:26.245440 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-19 00:27:26.272976 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.8 MB/s eta 0:00:00
2025-12-19 00:27:26.466077 | controller | Collecting pytest>=3.10
2025-12-19 00:27:26.472021 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-19 00:27:26.490982 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 24.1 MB/s eta 0:00:00
2025-12-19 00:27:26.561954 | controller | Collecting iniconfig>=1.0.1
2025-12-19 00:27:26.567528 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-19 00:27:26.640947 | controller | Collecting packaging>=22
2025-12-19 00:27:26.648108 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-19 00:27:26.657705 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.0 MB/s eta 0:00:00
2025-12-19 00:27:26.711458 | controller | Collecting pluggy<2,>=1.5
2025-12-19 00:27:26.717259 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-19 00:27:26.811538 | controller | Collecting pygments>=2.7.2
2025-12-19 00:27:26.819922 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-19 00:27:26.861566 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 33.7 MB/s eta 0:00:00
2025-12-19 00:27:26.973835 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-19 00:27:29.498454 | 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-19 00:27:29.514552 | controller |
2025-12-19 00:27:29.753964 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-19 00:27:29.754016 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-19 00:27:30.061930 | controller | ok: Runtime: 0:00:04.336704
2025-12-19 00:27:30.076025 | 
2025-12-19 00:27:30.076216 | TASK [Update pip]
2025-12-19 00:27:31.452207 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-19 00:27:31.722990 | controller | Collecting pip
2025-12-19 00:27:31.802519 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-19 00:27:31.895114 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 20.8 MB/s eta 0:00:00
2025-12-19 00:27:32.018036 | controller | Installing collected packages: pip
2025-12-19 00:27:32.022354 | controller |   Attempting uninstall: pip
2025-12-19 00:27:32.022408 | controller |     Found existing installation: pip 22.2.2
2025-12-19 00:27:32.302758 | controller |     Uninstalling pip-22.2.2:
2025-12-19 00:27:32.333136 | controller |       Successfully uninstalled pip-22.2.2
2025-12-19 00:27:34.161470 | controller | Successfully installed pip-25.3
2025-12-19 00:27:34.952507 | controller | ok: Runtime: 0:00:03.499702
2025-12-19 00:27:34.960429 | 
2025-12-19 00:27:34.960499 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-19 00:27:35.805696 | controller | changed
2025-12-19 00:27:35.815026 | 
2025-12-19 00:27:35.815178 | TASK [Install ansible into virtualenv]
2025-12-19 00:27:37.085940 | controller | Processing ./src/github.com/ansible/ansible
2025-12-19 00:27:37.090729 | controller |   Installing build dependencies: started
2025-12-19 00:27:38.764910 | controller |   Installing build dependencies: finished with status 'done'
2025-12-19 00:27:38.766001 | controller |   Getting requirements to build wheel: started
2025-12-19 00:27:40.302981 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-19 00:27:40.303731 | controller |   Preparing metadata (pyproject.toml): started
2025-12-19 00:27:41.187909 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-19 00:27:41.190061 | 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-19 00:27:41.193648 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-19 00:27:41.744475 | controller | ERROR
2025-12-19 00:27:41.744815 | controller | {
2025-12-19 00:27:41.744884 | controller |   "delta": "0:00:04.859077",
2025-12-19 00:27:41.744926 | controller |   "end": "2025-12-19 00:27:41.345158",
2025-12-19 00:27:41.744964 | controller |   "msg": "non-zero return code",
2025-12-19 00:27:41.745017 | controller |   "rc": 1,
2025-12-19 00:27:41.745052 | controller |   "start": "2025-12-19 00:27:36.486081"
2025-12-19 00:27:41.745085 | controller | }
failure
2025-12-19 00:27:41.748149 | 
2025-12-19 00:27:41.748247 | PLAY RECAP
2025-12-19 00:27:41.748326 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-19 00:27:41.748369 | 
2025-12-19 00:27:41.864591 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-19 00:27:41.865584 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-19 00:27:42.486542 | 
2025-12-19 00:27:42.486697 | PLAY [all]
2025-12-19 00:27:42.512431 | 
2025-12-19 00:27:42.512553 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-19 00:27:44.348827 | controller | changed: non-zero return code
2025-12-19 00:27:44.354790 | 
2025-12-19 00:27:44.354865 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-19 00:27:44.379583 | controller | skipping: Conditional result was False
2025-12-19 00:27:44.385663 | 
2025-12-19 00:27:44.385755 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-19 00:27:44.417396 | 
2025-12-19 00:27:44.417531 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-19 00:27:44.450865 | 
2025-12-19 00:27:44.451066 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-19 00:27:44.476295 | controller | skipping: Conditional result was False
2025-12-19 00:27:44.486220 | 
2025-12-19 00:27:44.486344 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-19 00:27:44.520045 | 
2025-12-19 00:27:44.520318 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-19 00:27:44.545345 | controller | skipping: Conditional result was False
2025-12-19 00:27:44.553730 | 
2025-12-19 00:27:44.553834 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-19 00:27:44.578890 | controller | skipping: Conditional result was False
2025-12-19 00:27:44.588114 | 
2025-12-19 00:27:44.588237 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-19 00:27:44.613663 | controller | skipping: Conditional result was False
2025-12-19 00:27:44.650381 | 
2025-12-19 00:27:44.650493 | PLAY RECAP
2025-12-19 00:27:44.650546 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-19 00:27:44.650574 | 
2025-12-19 00:27:44.784543 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-19 00:27:44.785460 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-19 00:27:45.419257 | 
2025-12-19 00:27:45.419395 | PLAY [all:!appliance*]
2025-12-19 00:27:45.444185 | 
2025-12-19 00:27:45.444317 | TASK [unregister the node]
2025-12-19 00:27:45.798790 | controller | skipping: Conditional result was False
2025-12-19 00:27:45.813194 | 
2025-12-19 00:27:45.813481 | TASK [include_role : fetch-output]
2025-12-19 00:27:45.844999 | controller | ok
2025-12-19 00:27:45.869795 | 
2025-12-19 00:27:45.870129 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-19 00:27:45.927047 | controller | skipping: Conditional result was False
2025-12-19 00:27:45.936168 | 
2025-12-19 00:27:45.936331 | TASK [fetch-output : Set log path for single node]
2025-12-19 00:27:45.976935 | controller | ok
2025-12-19 00:27:45.985088 | 
2025-12-19 00:27:45.985232 | LOOP [fetch-output : Ensure local output dirs]
2025-12-19 00:27:46.388371 | controller -> localhost | ok: "/var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/logs"
2025-12-19 00:27:46.601868 | controller -> localhost | changed: "/var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/artifacts"
2025-12-19 00:27:46.818564 | controller -> localhost | changed: "/var/lib/zuul/builds/ddbbde1301fc441d977ea2c2d271bd07/work/docs"
2025-12-19 00:27:46.832942 | 
2025-12-19 00:27:46.833051 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-19 00:27:49.073752 | controller | changed:
2025-12-19 00:27:49.074090 | controller | .d..t...... ./
2025-12-19 00:27:49.074151 | controller | cd+++++++++ controller/
2025-12-19 00:27:49.074220 | controller | changed: All items complete
2025-12-19 00:27:49.074264 | 
2025-12-19 00:27:51.146509 | controller | changed: .d..t...... ./
2025-12-19 00:27:53.219590 | controller | changed: .d..t...... ./
2025-12-19 00:27:53.244893 | 
2025-12-19 00:27:53.245088 | TASK [include_role : fetch-output-openshift]
2025-12-19 00:27:53.262197 | controller | skipping: Conditional result was False
2025-12-19 00:27:53.269599 | 
2025-12-19 00:27:53.269753 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-19 00:27:53.301174 | controller | skipping: Conditional result was False
2025-12-19 00:27:53.309361 | controller | skipping: Conditional result was False
2025-12-19 00:27:53.359343 | 
2025-12-19 00:27:53.359486 | PLAY [localhost]
2025-12-19 00:27:53.377187 | 
2025-12-19 00:27:53.377290 | TASK [Run Zuul manifest role]
2025-12-19 00:27:53.399800 | localhost | ok
2025-12-19 00:27:53.418911 | 
2025-12-19 00:27:53.419041 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-19 00:27:53.764599 | localhost | changed
2025-12-19 00:27:53.769650 | 
2025-12-19 00:27:53.769737 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-19 00:27:53.798591 | localhost | ok
2025-12-19 00:27:53.806608 | 
2025-12-19 00:27:53.806667 | TASK [Set zuul-log-path fact]
2025-12-19 00:27:53.825558 | localhost | ok
2025-12-19 00:27:53.865906 | 
2025-12-19 00:27:53.866029 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-19 00:27:53.895289 | localhost | ok
2025-12-19 00:27:53.903509 | 
2025-12-19 00:27:53.903567 | LOOP [Run upload-logs-swift role]
2025-12-19 00:27:53.928432 | localhost | Output suppressed because no_log was given
2025-12-19 00:27:53.953400 | 
2025-12-19 00:27:53.953471 | TASK [Set zuul-log-path fact]
2025-12-19 00:27:53.988745 | localhost | skipping: Conditional result was False
2025-12-19 00:27:53.994625 | 
2025-12-19 00:27:53.994721 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-19 00:27:54.422549 | localhost -> localhost | ok: Runtime: 0:00:00.005940
2025-12-19 00:27:54.428295 | 
2025-12-19 00:27:54.428387 | TASK [upload-logs-swift : Upload logs to swift]