2025-12-28 00:22:29.223355 | Job console starting...
2025-12-28 00:22:29.232505 | Updating repositories
2025-12-28 00:22:29.359931 | Preparing job workspace
2025-12-28 00:22:33.385420 | Running Ansible setup...
2025-12-28 00:22:41.488496 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-28 00:22:42.083888 | 
2025-12-28 00:22:42.084064 | PLAY [localhost]
2025-12-28 00:22:42.092944 | 
2025-12-28 00:22:42.093024 | TASK [Gathering Facts]
2025-12-28 00:22:43.142146 | localhost | ok
2025-12-28 00:22:43.161350 | 
2025-12-28 00:22:43.161457 | TASK [Setup log path fact]
2025-12-28 00:22:43.182323 | localhost | ok
2025-12-28 00:22:43.194800 | 
2025-12-28 00:22:43.194869 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-28 00:22:43.227335 | localhost | ok
2025-12-28 00:22:43.235976 | 
2025-12-28 00:22:43.236062 | TASK [emit-job-header : Print job information]
2025-12-28 00:22:43.290539 | # Job Information
2025-12-28 00:22:43.290810 | Ansible Version: 2.15.12
2025-12-28 00:22:43.290857 | Job: ansible-test-sanity-docker-devel
2025-12-28 00:22:43.290889 | Pipeline: periodic
2025-12-28 00:22:43.290915 | Executor: ze04.softwarefactory-project.io
2025-12-28 00:22:43.290943 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-28 00:22:43.290977 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/33b/ansible/33bd1e3fa07f40abbcdeca663ab9c3ff/
2025-12-28 00:22:43.291006 | Event ID: 3f53bd7375e24114bd964e912e0e7186
2025-12-28 00:22:43.303050 | 
2025-12-28 00:22:43.303151 | LOOP [emit-job-header : Print node information]
2025-12-28 00:22:43.447288 | localhost | ok:
2025-12-28 00:22:43.447554 | localhost | # Node Information
2025-12-28 00:22:43.447592 | localhost | Inventory Hostname: controller
2025-12-28 00:22:43.447621 | localhost | Hostname: np0005571765
2025-12-28 00:22:43.447648 | localhost | Username: zuul
2025-12-28 00:22:43.447787 | localhost | Distro: Fedora 37
2025-12-28 00:22:43.447835 | localhost | Provider: ansible-vexxhost-ams1
2025-12-28 00:22:43.447863 | localhost | Region: ams1
2025-12-28 00:22:43.447888 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-28 00:22:43.447913 | localhost | Product Name: OpenStack Nova
2025-12-28 00:22:43.447937 | localhost | Interface IP: 38.129.16.79
2025-12-28 00:22:43.468457 | 
2025-12-28 00:22:43.468586 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-28 00:22:43.860840 | localhost -> localhost | changed
2025-12-28 00:22:43.867566 | 
2025-12-28 00:22:43.867644 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-28 00:22:44.705488 | localhost -> localhost | changed
2025-12-28 00:22:44.737454 | 
2025-12-28 00:22:44.737573 | PLAY [all:!appliance*]
2025-12-28 00:22:44.764850 | 
2025-12-28 00:22:44.765029 | TASK [include_role : start-zuul-console]
2025-12-28 00:22:44.787080 | controller | ok
2025-12-28 00:22:44.800634 | 
2025-12-28 00:22:44.800732 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-28 00:22:45.963347 | controller | ok
2025-12-28 00:22:45.989394 | 
2025-12-28 00:22:45.989566 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-28 00:22:48.332802 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-28 00:22:48.348229 | 
2025-12-28 00:22:48.348422 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-28 00:22:48.719514 | controller | skipping: Conditional result was False
2025-12-28 00:22:48.735368 | 
2025-12-28 00:22:48.735557 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-28 00:22:48.774671 | controller | skipping: Conditional result was False
2025-12-28 00:22:48.790300 | 
2025-12-28 00:22:48.790447 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-28 00:22:48.829134 | controller | skipping: Conditional result was False
2025-12-28 00:22:48.837313 | 
2025-12-28 00:22:48.837398 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-28 00:22:48.873527 | controller | skipping: Conditional result was False
2025-12-28 00:22:48.880733 | 
2025-12-28 00:22:48.880819 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-28 00:22:48.916321 | controller | skipping: Conditional result was False
2025-12-28 00:22:48.923955 | 
2025-12-28 00:22:48.924112 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-28 00:22:48.955174 | controller | skipping: Conditional result was False
2025-12-28 00:22:48.971986 | 
2025-12-28 00:22:48.972114 | TASK [Disable Fedora Modular]
2025-12-28 00:22:50.063275 | controller | changed
2025-12-28 00:22:50.073131 | 
2025-12-28 00:22:50.073236 | TASK [Enable EPEL]
2025-12-28 00:22:50.102035 | controller | skipping: Conditional result was False
2025-12-28 00:22:50.113928 | 
2025-12-28 00:22:50.114051 | TASK [Register the RHEL node]
2025-12-28 00:22:50.533845 | 
2025-12-28 00:22:50.534312 | TASK [Show the subscription-manager status]
2025-12-28 00:22:50.924445 | controller | skipping: Conditional result was False
2025-12-28 00:22:50.940982 | 
2025-12-28 00:22:50.941140 | TASK [Enable EPEL on RHEL]
2025-12-28 00:22:51.343784 | controller | skipping: Conditional result was False
2025-12-28 00:22:51.360306 | 
2025-12-28 00:22:51.360570 | TASK [Install git and tox]
2025-12-28 00:24:59.216125 | controller | changed
2025-12-28 00:24:59.231241 | 
2025-12-28 00:24:59.231386 | TASK [include_role : prepare-workspace]
2025-12-28 00:24:59.275062 | controller | ok
2025-12-28 00:24:59.313405 | 
2025-12-28 00:24:59.313533 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-28 00:25:00.215587 | controller | ok
2025-12-28 00:25:00.231889 | 
2025-12-28 00:25:00.232028 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-28 00:25:15.701533 | controller | Output suppressed because no_log was given
2025-12-28 00:25:15.715665 | 
2025-12-28 00:25:15.715777 | TASK [include_role : prepare-workspace-openshift]
2025-12-28 00:25:15.742398 | controller | skipping: Conditional result was False
2025-12-28 00:25:15.773093 | 
2025-12-28 00:25:15.773178 | PLAY [all:!appliance]
2025-12-28 00:25:15.794199 | 
2025-12-28 00:25:15.794304 | TASK [Run add-build-sshkey role (RSA)]
2025-12-28 00:25:15.827744 | controller | ok
2025-12-28 00:25:15.849373 | 
2025-12-28 00:25:15.849624 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-28 00:25:16.129623 | controller -> localhost | ok
2025-12-28 00:25:16.145333 | 
2025-12-28 00:25:16.145505 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-28 00:25:16.169738 | controller | ok
2025-12-28 00:25:16.191610 | controller | included: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-28 00:25:16.202081 | 
2025-12-28 00:25:16.202185 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-28 00:25:16.840808 | controller -> localhost | Generating public/private rsa key pair.
2025-12-28 00:25:16.841059 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/33bd1e3fa07f40abbcdeca663ab9c3ff_id_rsa.
2025-12-28 00:25:16.841090 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/33bd1e3fa07f40abbcdeca663ab9c3ff_id_rsa.pub.
2025-12-28 00:25:16.841113 | controller -> localhost | The key fingerprint is:
2025-12-28 00:25:16.841133 | controller -> localhost | SHA256:vt9stlZPwvGup5LFbfYip+5XU6BAh/FTxrgPNkpq6/k zuul-build-sshkey
2025-12-28 00:25:16.841153 | controller -> localhost | The key's randomart image is:
2025-12-28 00:25:16.841171 | controller -> localhost | +---[RSA 2048]----+
2025-12-28 00:25:16.841190 | controller -> localhost | |         .oo.oo  |
2025-12-28 00:25:16.841209 | controller -> localhost | |          oo.oo  |
2025-12-28 00:25:16.841227 | controller -> localhost | |           .oo . |
2025-12-28 00:25:16.841245 | controller -> localhost | |          . *.. .|
2025-12-28 00:25:16.841262 | controller -> localhost | |        So o * +.|
2025-12-28 00:25:16.841288 | controller -> localhost | |       .o .   B.B|
2025-12-28 00:25:16.841311 | controller -> localhost | |       ...   + Oo|
2025-12-28 00:25:16.841332 | controller -> localhost | |        .o oB + =|
2025-12-28 00:25:16.841349 | controller -> localhost | |       .+oE*BBo= |
2025-12-28 00:25:16.841370 | controller -> localhost | +----[SHA256]-----+
2025-12-28 00:25:16.841423 | controller -> localhost | ok: Runtime: 0:00:00.139789
2025-12-28 00:25:16.848501 | 
2025-12-28 00:25:16.848583 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-28 00:25:16.879674 | controller | ok
2025-12-28 00:25:16.891315 | controller | included: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-28 00:25:16.902414 | 
2025-12-28 00:25:16.902562 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-28 00:25:16.918286 | controller | skipping: Conditional result was False
2025-12-28 00:25:16.927555 | 
2025-12-28 00:25:16.927719 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-28 00:25:18.071177 | controller | changed
2025-12-28 00:25:18.079805 | 
2025-12-28 00:25:18.079908 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-28 00:25:18.714879 | controller | ok
2025-12-28 00:25:18.721885 | 
2025-12-28 00:25:18.721955 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-28 00:25:21.796224 | controller | changed
2025-12-28 00:25:21.810386 | 
2025-12-28 00:25:21.810535 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-28 00:25:24.871048 | controller | changed
2025-12-28 00:25:24.885121 | 
2025-12-28 00:25:24.885285 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-28 00:25:24.914096 | controller | skipping: Conditional result was False
2025-12-28 00:25:24.930698 | 
2025-12-28 00:25:24.930884 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-28 00:25:25.397952 | controller -> localhost | changed
2025-12-28 00:25:25.410353 | 
2025-12-28 00:25:25.410421 | TASK [add-build-sshkey : Add back temp key]
2025-12-28 00:25:25.744963 | controller -> localhost | Identity added: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/33bd1e3fa07f40abbcdeca663ab9c3ff_id_rsa (zuul-build-sshkey)
2025-12-28 00:25:25.745424 | controller -> localhost | ok: Runtime: 0:00:00.012598
2025-12-28 00:25:25.758957 | 
2025-12-28 00:25:25.759113 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-28 00:25:26.748783 | controller | ok
2025-12-28 00:25:26.762503 | 
2025-12-28 00:25:26.762762 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-28 00:25:26.792296 | controller | skipping: Conditional result was False
2025-12-28 00:25:26.819927 | 
2025-12-28 00:25:26.820111 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-28 00:25:26.857588 | controller | ok
2025-12-28 00:25:26.882334 | 
2025-12-28 00:25:26.882570 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-28 00:25:27.178658 | controller -> localhost | ok
2025-12-28 00:25:27.185588 | 
2025-12-28 00:25:27.185653 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-28 00:25:27.226554 | controller | ok
2025-12-28 00:25:27.240001 | controller | included: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-28 00:25:27.246310 | 
2025-12-28 00:25:27.246373 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-28 00:25:27.619049 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-28 00:25:27.620189 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/33bd1e3fa07f40abbcdeca663ab9c3ff_id_ecdsa.
2025-12-28 00:25:27.620281 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/33bd1e3fa07f40abbcdeca663ab9c3ff_id_ecdsa.pub.
2025-12-28 00:25:27.620351 | controller -> localhost | The key fingerprint is:
2025-12-28 00:25:27.620399 | controller -> localhost | SHA256:+udLXuSeRwbK9mJ1PmZ4FhVGbHTOTwLkXuVXd36/XM8 zuul-build-sshkey
2025-12-28 00:25:27.620441 | controller -> localhost | The key's randomart image is:
2025-12-28 00:25:27.620483 | controller -> localhost | +---[ECDSA 521]---+
2025-12-28 00:25:27.620524 | controller -> localhost | |           .o +o*|
2025-12-28 00:25:27.620563 | controller -> localhost | |           . . @=|
2025-12-28 00:25:27.620611 | controller -> localhost | |            . = X|
2025-12-28 00:25:27.620666 | controller -> localhost | |           ... o*|
2025-12-28 00:25:27.620750 | controller -> localhost | |        S. .o. .+|
2025-12-28 00:25:27.620792 | controller -> localhost | |       .  +o. *.+|
2025-12-28 00:25:27.620831 | controller -> localhost | |      .  ..oo* +E|
2025-12-28 00:25:27.620868 | controller -> localhost | |       . o+oo.O  |
2025-12-28 00:25:27.620905 | controller -> localhost | |        .++oo* . |
2025-12-28 00:25:27.620943 | controller -> localhost | +----[SHA256]-----+
2025-12-28 00:25:27.621054 | controller -> localhost | ok: Runtime: 0:00:00.017672
2025-12-28 00:25:27.641313 | 
2025-12-28 00:25:27.641471 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-28 00:25:27.684647 | controller | ok
2025-12-28 00:25:27.702084 | controller | included: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-28 00:25:27.763740 | 
2025-12-28 00:25:27.763898 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-28 00:25:27.781017 | controller | skipping: Conditional result was False
2025-12-28 00:25:27.789168 | 
2025-12-28 00:25:27.789264 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-28 00:25:28.708040 | controller | changed
2025-12-28 00:25:28.716547 | 
2025-12-28 00:25:28.716656 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-28 00:25:29.407948 | controller | ok
2025-12-28 00:25:29.421375 | 
2025-12-28 00:25:29.421750 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-28 00:25:32.469236 | controller | changed
2025-12-28 00:25:32.482606 | 
2025-12-28 00:25:32.482781 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-28 00:25:35.534927 | controller | changed
2025-12-28 00:25:35.548884 | 
2025-12-28 00:25:35.549033 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-28 00:25:35.577555 | controller | skipping: Conditional result was False
2025-12-28 00:25:35.592233 | 
2025-12-28 00:25:35.592382 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-28 00:25:35.834503 | controller -> localhost | changed
2025-12-28 00:25:35.861115 | 
2025-12-28 00:25:35.861239 | TASK [add-build-sshkey : Add back temp key]
2025-12-28 00:25:36.143581 | controller -> localhost | Identity added: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/33bd1e3fa07f40abbcdeca663ab9c3ff_id_ecdsa (zuul-build-sshkey)
2025-12-28 00:25:36.144041 | controller -> localhost | ok: Runtime: 0:00:00.017373
2025-12-28 00:25:36.159831 | 
2025-12-28 00:25:36.159952 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-28 00:25:36.871110 | controller | ok
2025-12-28 00:25:36.883862 | 
2025-12-28 00:25:36.884004 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-28 00:25:36.913312 | controller | skipping: Conditional result was False
2025-12-28 00:25:36.944276 | 
2025-12-28 00:25:36.944450 | TASK [include_role : remove-zuul-sshkey]
2025-12-28 00:25:36.961253 | controller | skipping: Conditional result was False
2025-12-28 00:25:36.971115 | 
2025-12-28 00:25:36.971211 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-28 00:25:37.674182 | controller | ok: "logs"
2025-12-28 00:25:37.674896 | controller | ok: All items complete
2025-12-28 00:25:37.674996 | 
2025-12-28 00:25:38.296339 | controller | ok: "artifacts"
2025-12-28 00:25:38.917798 | controller | ok: "docs"
2025-12-28 00:25:38.927825 | 
2025-12-28 00:25:38.927915 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-28 00:25:39.604383 | controller | changed: "logs"
2025-12-28 00:25:40.244312 | controller | changed: "artifacts"
2025-12-28 00:25:40.869429 | controller | changed: "docs"
2025-12-28 00:25:40.916851 | 
2025-12-28 00:25:40.916981 | PLAY RECAP
2025-12-28 00:25:40.917030 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-28 00:25:40.917056 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-28 00:25:40.917074 | 
2025-12-28 00:25:41.102165 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-28 00:25:41.104208 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-28 00:25:41.678412 | 
2025-12-28 00:25:41.678564 | PLAY [all]
2025-12-28 00:25:41.701620 | 
2025-12-28 00:25:41.701792 | TASK [Install binary dependencies]
2025-12-28 00:25:41.790800 | controller | ok
2025-12-28 00:25:41.826385 | 
2025-12-28 00:25:41.826588 | TASK [bindep : Include find tasks]
2025-12-28 00:25:41.871887 | controller | ok
2025-12-28 00:25:41.883605 | controller | included: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-28 00:25:41.893086 | 
2025-12-28 00:25:41.893212 | TASK [bindep : Look for bindep.txt]
2025-12-28 00:25:42.851871 | controller | ok
2025-12-28 00:25:42.864830 | 
2025-12-28 00:25:42.864979 | TASK [bindep : Define bindep_file fact]
2025-12-28 00:25:42.893228 | controller | skipping: Conditional result was False
2025-12-28 00:25:42.906447 | 
2025-12-28 00:25:42.906588 | TASK [bindep : Look for other-requirements.txt]
2025-12-28 00:25:43.557559 | controller | ok
2025-12-28 00:25:43.571330 | 
2025-12-28 00:25:43.571476 | TASK [bindep : Define bindep_file fact]
2025-12-28 00:25:43.610107 | controller | skipping: Conditional result was False
2025-12-28 00:25:43.627122 | 
2025-12-28 00:25:43.627274 | TASK [bindep : Look for bindep fallback file]
2025-12-28 00:25:43.665390 | controller | skipping: Conditional result was False
2025-12-28 00:25:43.680384 | 
2025-12-28 00:25:43.680535 | TASK [bindep : Define bindep_file fact]
2025-12-28 00:25:43.719252 | controller | skipping: Conditional result was False
2025-12-28 00:25:43.732916 | 
2025-12-28 00:25:43.733056 | TASK [bindep : Include bindep tasks]
2025-12-28 00:25:43.771021 | controller | skipping: Conditional result was False
2025-12-28 00:25:43.784541 | 
2025-12-28 00:25:43.784784 | TASK [bindep : Include install tasks]
2025-12-28 00:25:43.823752 | controller | skipping: Conditional result was False
2025-12-28 00:25:43.837459 | 
2025-12-28 00:25:43.837598 | LOOP [bindep : Include package tasks]
2025-12-28 00:25:43.925287 | 
2025-12-28 00:25:43.925555 | TASK [Run test-setup role]
2025-12-28 00:25:43.955354 | controller | ok
2025-12-28 00:25:43.985248 | 
2025-12-28 00:25:43.985336 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-28 00:25:44.717109 | controller | ok
2025-12-28 00:25:44.730919 | 
2025-12-28 00:25:44.731053 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-28 00:25:45.104010 | controller | skipping: Conditional result was False
2025-12-28 00:25:45.160824 | 
2025-12-28 00:25:45.161079 | PLAY RECAP
2025-12-28 00:25:45.161212 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-28 00:25:45.161265 | 
2025-12-28 00:25:45.318503 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-28 00:25:45.319506 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-28 00:25:45.996182 | 
2025-12-28 00:25:45.996356 | PLAY [controller]
2025-12-28 00:25:46.016776 | 
2025-12-28 00:25:46.016863 | TASK [Create the /root directory]
2025-12-28 00:25:47.099076 | controller | ok
2025-12-28 00:25:47.113778 | 
2025-12-28 00:25:47.113938 | TASK [Install glibc-langpack-en]
2025-12-28 00:25:55.090756 | controller | ok: Nothing to do
2025-12-28 00:25:55.104363 | 
2025-12-28 00:25:55.104550 | TASK [Ensure controller directory exists]
2025-12-28 00:25:55.967257 | controller | changed
2025-12-28 00:25:55.985607 | 
2025-12-28 00:25:55.985907 | TASK [Install container runtime]
2025-12-28 00:25:56.039145 | controller | ok
2025-12-28 00:25:56.089280 | 
2025-12-28 00:25:56.089433 | LOOP [ensure-podman : Find distribution installation]
2025-12-28 00:25:56.119151 | controller | ok: "/var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-28 00:25:56.137181 | controller | included: /var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-28 00:25:56.147796 | 
2025-12-28 00:25:56.147900 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-28 00:27:58.523546 | controller | changed
2025-12-28 00:27:58.538093 | 
2025-12-28 00:27:58.538254 | TASK [ensure-podman : Fetch podman version]
2025-12-28 00:27:59.763557 | controller | Client:       Podman Engine
2025-12-28 00:27:59.763678 | controller | Version:      4.6.2
2025-12-28 00:27:59.763723 | controller | API Version:  4.6.2
2025-12-28 00:27:59.763765 | controller | Go Version:   go1.19.12
2025-12-28 00:27:59.763818 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-28 00:27:59.763861 | controller | OS/Arch:      linux/amd64
2025-12-28 00:28:00.418309 | controller | ok: Runtime: 0:00:00.298979
2025-12-28 00:28:00.427880 | 
2025-12-28 00:28:00.427969 | TASK [ensure-podman : Print podman version installed]
2025-12-28 00:28:00.463282 | Podman version: Client:       Podman Engine
2025-12-28 00:28:00.463483 | Version:      4.6.2
2025-12-28 00:28:00.463521 | API Version:  4.6.2
2025-12-28 00:28:00.463548 | Go Version:   go1.19.12
2025-12-28 00:28:00.463573 | Built:        Mon Aug 28 19:38:31 2023
2025-12-28 00:28:00.463603 | OS/Arch:      linux/amd64
2025-12-28 00:28:00.471516 | 
2025-12-28 00:28:00.471608 | TASK [ensure-podman : Validate podman engine]
2025-12-28 00:28:00.832400 | controller | skipping: Conditional result was False
2025-12-28 00:28:00.841790 | 
2025-12-28 00:28:00.841895 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-28 00:28:00.857726 | controller | skipping: Conditional result was False
2025-12-28 00:28:00.880344 | 
2025-12-28 00:28:00.880474 | TASK [Ensure python3.8 is present]
2025-12-28 00:28:00.896425 | controller | skipping: Conditional result was False
2025-12-28 00:28:00.907257 | 
2025-12-28 00:28:00.907362 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-28 00:28:00.931575 | controller | ok
2025-12-28 00:28:00.960006 | 
2025-12-28 00:28:00.960146 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-28 00:28:04.734238 | controller | ok: Nothing to do
2025-12-28 00:28:04.749184 | 
2025-12-28 00:28:04.749371 | TASK [our-ensure-python : Also install python3-devel]
2025-12-28 00:28:21.644557 | controller | changed
2025-12-28 00:28:21.661651 | 
2025-12-28 00:28:21.661794 | TASK [Run ensure-virtualenv role]
2025-12-28 00:28:21.686290 | controller | ok
2025-12-28 00:28:21.714040 | 
2025-12-28 00:28:21.714116 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-28 00:28:22.529222 | controller | /usr/bin/virtualenv
2025-12-28 00:28:23.112002 | controller | ok: Runtime: 0:00:00.006821
2025-12-28 00:28:23.125418 | 
2025-12-28 00:28:23.125553 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-28 00:28:23.164638 | controller | skipping: Conditional result was False
2025-12-28 00:28:23.165039 | controller | ok: All items complete
2025-12-28 00:28:23.165067 | 
2025-12-28 00:28:23.197534 | 
2025-12-28 00:28:23.197745 | TASK [Find the full path of the Python interpreter]
2025-12-28 00:28:23.990270 | controller | /usr/bin/python3
2025-12-28 00:28:24.572351 | controller | ok
2025-12-28 00:28:24.579039 | 
2025-12-28 00:28:24.579109 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-28 00:28:26.483388 | controller | created virtual environment CPython3.11.0.final.0-64 in 976ms
2025-12-28 00:28:26.594550 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-28 00:28:26.594626 | 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-28 00:28:26.594647 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-28 00:28:26.594668 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-28 00:28:26.948457 | controller | changed
2025-12-28 00:28:26.956633 | 
2025-12-28 00:28:26.956738 | TASK [Set selinux package]
2025-12-28 00:28:26.989576 | controller | ok
2025-12-28 00:28:26.995046 | 
2025-12-28 00:28:26.995120 | TASK [Set selinux package (Fedora)]
2025-12-28 00:28:27.047416 | controller | ok
2025-12-28 00:28:27.052757 | 
2025-12-28 00:28:27.052822 | TASK [Install selinux into virtualenv]
2025-12-28 00:28:30.317775 | controller | Collecting selinux-please-lie-to-me
2025-12-28 00:28:30.384960 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-28 00:28:30.933239 | controller | Collecting setuptools<50.0.0
2025-12-28 00:28:30.940122 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-28 00:28:30.991799 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 17.0 MB/s eta 0:00:00
2025-12-28 00:28:31.132493 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-28 00:28:31.132688 | controller |   Attempting uninstall: setuptools
2025-12-28 00:28:31.139565 | controller |     Found existing installation: setuptools 62.6.0
2025-12-28 00:28:31.242336 | controller |     Uninstalling setuptools-62.6.0:
2025-12-28 00:28:31.257831 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-28 00:28:32.101208 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-28 00:28:32.309599 | controller |
2025-12-28 00:28:32.735472 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-28 00:28:32.735525 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-28 00:28:32.952031 | controller | ok: Runtime: 0:00:04.882322
2025-12-28 00:28:32.969203 | 
2025-12-28 00:28:32.969447 | TASK [Install pytest-forked into virtualenv]
2025-12-28 00:28:34.567786 | controller | Collecting pytest-forked
2025-12-28 00:28:34.634096 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-28 00:28:34.691917 | controller | Collecting py
2025-12-28 00:28:34.703465 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-28 00:28:34.741412 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.1 MB/s eta 0:00:00
2025-12-28 00:28:34.943124 | controller | Collecting pytest>=3.10
2025-12-28 00:28:34.950025 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-28 00:28:34.977762 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 15.8 MB/s eta 0:00:00
2025-12-28 00:28:35.055781 | controller | Collecting iniconfig>=1.0.1
2025-12-28 00:28:35.061491 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-28 00:28:35.125927 | controller | Collecting packaging>=22
2025-12-28 00:28:35.132870 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-28 00:28:35.147268 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 5.3 MB/s eta 0:00:00
2025-12-28 00:28:35.207491 | controller | Collecting pluggy<2,>=1.5
2025-12-28 00:28:35.215788 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-28 00:28:35.286943 | controller | Collecting pygments>=2.7.2
2025-12-28 00:28:35.291893 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-28 00:28:35.316384 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 58.4 MB/s eta 0:00:00
2025-12-28 00:28:35.417723 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-28 00:28:37.729929 | 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-28 00:28:37.746988 | controller |
2025-12-28 00:28:38.040680 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-28 00:28:38.040860 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-28 00:28:38.364077 | controller | ok: Runtime: 0:00:04.257583
2025-12-28 00:28:38.379942 | 
2025-12-28 00:28:38.380102 | TASK [Update pip]
2025-12-28 00:28:39.774578 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-28 00:28:40.121088 | controller | Collecting pip
2025-12-28 00:28:40.211035 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-28 00:28:40.307650 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 19.5 MB/s eta 0:00:00
2025-12-28 00:28:40.418674 | controller | Installing collected packages: pip
2025-12-28 00:28:40.418917 | controller |   Attempting uninstall: pip
2025-12-28 00:28:40.424414 | controller |     Found existing installation: pip 22.2.2
2025-12-28 00:28:40.662792 | controller |     Uninstalling pip-22.2.2:
2025-12-28 00:28:40.708349 | controller |       Successfully uninstalled pip-22.2.2
2025-12-28 00:28:42.521301 | controller | Successfully installed pip-25.3
2025-12-28 00:28:43.284441 | controller | ok: Runtime: 0:00:03.544748
2025-12-28 00:28:43.291278 | 
2025-12-28 00:28:43.291347 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-28 00:28:44.290553 | controller | changed
2025-12-28 00:28:44.296419 | 
2025-12-28 00:28:44.296483 | TASK [Install ansible into virtualenv]
2025-12-28 00:28:45.567924 | controller | Processing ./src/github.com/ansible/ansible
2025-12-28 00:28:45.572844 | controller |   Installing build dependencies: started
2025-12-28 00:28:47.455346 | controller |   Installing build dependencies: finished with status 'done'
2025-12-28 00:28:47.456342 | controller |   Getting requirements to build wheel: started
2025-12-28 00:28:48.894673 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-28 00:28:48.895531 | controller |   Preparing metadata (pyproject.toml): started
2025-12-28 00:28:49.775596 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-28 00:28:49.780796 | 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-28 00:28:49.786773 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-28 00:28:50.170374 | controller | ERROR
2025-12-28 00:28:50.170832 | controller | {
2025-12-28 00:28:50.170907 | controller |   "delta": "0:00:05.062845",
2025-12-28 00:28:50.170951 | controller |   "end": "2025-12-28 00:28:49.961446",
2025-12-28 00:28:50.170988 | controller |   "msg": "non-zero return code",
2025-12-28 00:28:50.171043 | controller |   "rc": 1,
2025-12-28 00:28:50.171080 | controller |   "start": "2025-12-28 00:28:44.898601"
2025-12-28 00:28:50.171116 | controller | }
failure
2025-12-28 00:28:50.174381 | 
2025-12-28 00:28:50.174479 | PLAY RECAP
2025-12-28 00:28:50.174588 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-28 00:28:50.174638 | 
2025-12-28 00:28:50.384053 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-28 00:28:50.386065 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-28 00:28:51.026145 | 
2025-12-28 00:28:51.026284 | PLAY [all]
2025-12-28 00:28:51.048052 | 
2025-12-28 00:28:51.048139 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-28 00:28:52.974823 | controller | changed: non-zero return code
2025-12-28 00:28:52.989746 | 
2025-12-28 00:28:52.989923 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-28 00:28:53.020411 | controller | skipping: Conditional result was False
2025-12-28 00:28:53.036852 | 
2025-12-28 00:28:53.037015 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-28 00:28:53.082434 | 
2025-12-28 00:28:53.082744 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-28 00:28:53.118167 | 
2025-12-28 00:28:53.118382 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-28 00:28:53.135037 | controller | skipping: Conditional result was False
2025-12-28 00:28:53.145340 | 
2025-12-28 00:28:53.145441 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-28 00:28:53.172093 | 
2025-12-28 00:28:53.172293 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-28 00:28:53.187917 | controller | skipping: Conditional result was False
2025-12-28 00:28:53.197001 | 
2025-12-28 00:28:53.197095 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-28 00:28:53.212894 | controller | skipping: Conditional result was False
2025-12-28 00:28:53.222706 | 
2025-12-28 00:28:53.222805 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-28 00:28:53.248985 | controller | skipping: Conditional result was False
2025-12-28 00:28:53.281930 | 
2025-12-28 00:28:53.282104 | PLAY RECAP
2025-12-28 00:28:53.282153 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-28 00:28:53.282173 | 
2025-12-28 00:28:53.445050 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-28 00:28:53.447535 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-28 00:28:54.102211 | 
2025-12-28 00:28:54.102389 | PLAY [all:!appliance*]
2025-12-28 00:28:54.125403 | 
2025-12-28 00:28:54.125498 | TASK [unregister the node]
2025-12-28 00:28:54.476478 | controller | skipping: Conditional result was False
2025-12-28 00:28:54.491244 | 
2025-12-28 00:28:54.491473 | TASK [include_role : fetch-output]
2025-12-28 00:28:54.555453 | controller | ok
2025-12-28 00:28:54.600874 | 
2025-12-28 00:28:54.601055 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-28 00:28:54.688547 | controller | skipping: Conditional result was False
2025-12-28 00:28:54.710175 | 
2025-12-28 00:28:54.710450 | TASK [fetch-output : Set log path for single node]
2025-12-28 00:28:54.778753 | controller | ok
2025-12-28 00:28:54.787211 | 
2025-12-28 00:28:54.787311 | LOOP [fetch-output : Ensure local output dirs]
2025-12-28 00:28:55.257925 | controller -> localhost | ok: "/var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/logs"
2025-12-28 00:28:55.519842 | controller -> localhost | changed: "/var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/artifacts"
2025-12-28 00:28:55.805082 | controller -> localhost | changed: "/var/lib/zuul/builds/33bd1e3fa07f40abbcdeca663ab9c3ff/work/docs"
2025-12-28 00:28:55.829026 | 
2025-12-28 00:28:55.829340 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-28 00:28:58.126672 | controller | changed:
2025-12-28 00:28:58.127803 | controller | .d..t...... ./
2025-12-28 00:28:58.127960 | controller | cd+++++++++ controller/
2025-12-28 00:28:58.128031 | controller | changed: All items complete
2025-12-28 00:28:58.128061 | 
2025-12-28 00:29:00.249574 | controller | changed: .d..t...... ./
2025-12-28 00:29:02.362484 | controller | changed: .d..t...... ./
2025-12-28 00:29:02.395876 | 
2025-12-28 00:29:02.396087 | TASK [include_role : fetch-output-openshift]
2025-12-28 00:29:02.414321 | controller | skipping: Conditional result was False
2025-12-28 00:29:02.430462 | 
2025-12-28 00:29:02.430601 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-28 00:29:02.462972 | controller | skipping: Conditional result was False
2025-12-28 00:29:02.470769 | controller | skipping: Conditional result was False
2025-12-28 00:29:02.529749 | 
2025-12-28 00:29:02.529884 | PLAY [localhost]
2025-12-28 00:29:02.547645 | 
2025-12-28 00:29:02.547751 | TASK [Run Zuul manifest role]
2025-12-28 00:29:02.568797 | localhost | ok
2025-12-28 00:29:02.586594 | 
2025-12-28 00:29:02.586704 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-28 00:29:03.022279 | localhost | changed
2025-12-28 00:29:03.032857 | 
2025-12-28 00:29:03.032998 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-28 00:29:03.070545 | localhost | ok
2025-12-28 00:29:03.090233 | 
2025-12-28 00:29:03.090489 | TASK [Set zuul-log-path fact]
2025-12-28 00:29:03.146701 | localhost | ok
2025-12-28 00:29:03.162181 | 
2025-12-28 00:29:03.162254 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-28 00:29:03.190764 | localhost | ok
2025-12-28 00:29:03.198613 | 
2025-12-28 00:29:03.198670 | LOOP [Run upload-logs-swift role]
2025-12-28 00:29:03.223802 | localhost | Output suppressed because no_log was given
2025-12-28 00:29:03.258293 | 
2025-12-28 00:29:03.258402 | TASK [Set zuul-log-path fact]
2025-12-28 00:29:03.293511 | localhost | skipping: Conditional result was False
2025-12-28 00:29:03.300606 | 
2025-12-28 00:29:03.300714 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-28 00:29:03.735196 | localhost -> localhost | ok: Runtime: 0:00:00.009879
2025-12-28 00:29:03.741207 | 
2025-12-28 00:29:03.741274 | TASK [upload-logs-swift : Upload logs to swift]