2026-02-03 00:27:39.186502 | Job console starting...
2026-02-03 00:27:39.204492 | Updating repositories
2026-02-03 00:27:39.341779 | Preparing job workspace
2026-02-03 00:27:43.495963 | Running Ansible setup...
2026-02-03 00:27:48.528863 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-03 00:27:49.210997 | 
2026-02-03 00:27:49.211170 | PLAY [localhost]
2026-02-03 00:27:49.220366 | 
2026-02-03 00:27:49.220477 | TASK [Gathering Facts]
2026-02-03 00:27:50.205249 | localhost | ok
2026-02-03 00:27:50.224994 | 
2026-02-03 00:27:50.225174 | TASK [Setup log path fact]
2026-02-03 00:27:50.256454 | localhost | ok
2026-02-03 00:27:50.274584 | 
2026-02-03 00:27:50.274723 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-03 00:27:50.315325 | localhost | ok
2026-02-03 00:27:50.327041 | 
2026-02-03 00:27:50.327171 | TASK [emit-job-header : Print job information]
2026-02-03 00:27:50.378583 | # Job Information
2026-02-03 00:27:50.378820 | Ansible Version: 2.15.12
2026-02-03 00:27:50.378891 | Job: ansible-test-sanity-docker-milestone
2026-02-03 00:27:50.378942 | Pipeline: periodic
2026-02-03 00:27:50.378984 | Executor: ze01.softwarefactory-project.io
2026-02-03 00:27:50.379054 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-03 00:27:50.379088 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/a48/ansible/a483f75ab5034d8bafe60faabcec6f24/
2026-02-03 00:27:50.379116 | Event ID: bc917e7b12a94a929f4345acdd6e8cbb
2026-02-03 00:27:50.384411 | 
2026-02-03 00:27:50.384527 | LOOP [emit-job-header : Print node information]
2026-02-03 00:27:50.517348 | localhost | ok:
2026-02-03 00:27:50.517518 | localhost | # Node Information
2026-02-03 00:27:50.517551 | localhost | Inventory Hostname: controller
2026-02-03 00:27:50.517577 | localhost | Hostname: np0005606110
2026-02-03 00:27:50.517602 | localhost | Username: zuul
2026-02-03 00:27:50.517630 | localhost | Distro: Fedora 37
2026-02-03 00:27:50.517655 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-03 00:27:50.517678 | localhost | Region: ca-ymq-1
2026-02-03 00:27:50.517700 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-03 00:27:50.517722 | localhost | Product Name: OpenStack Nova
2026-02-03 00:27:50.517745 | localhost | Interface IP: 162.253.55.218
2026-02-03 00:27:50.536811 | 
2026-02-03 00:27:50.536958 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-03 00:27:50.921676 | localhost -> localhost | changed
2026-02-03 00:27:50.927419 | 
2026-02-03 00:27:50.927496 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-03 00:27:51.729123 | localhost -> localhost | changed
2026-02-03 00:27:51.752587 | 
2026-02-03 00:27:51.752695 | PLAY [all:!appliance*]
2026-02-03 00:27:51.772410 | 
2026-02-03 00:27:51.772534 | TASK [include_role : start-zuul-console]
2026-02-03 00:27:51.792587 | controller | ok
2026-02-03 00:27:51.810878 | 
2026-02-03 00:27:51.811006 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-03 00:27:52.195527 | controller | ok
2026-02-03 00:27:52.215381 | 
2026-02-03 00:27:52.215543 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-03 00:27:53.201892 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-03 00:27:53.213183 | 
2026-02-03 00:27:53.213326 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-03 00:27:53.767331 | controller | skipping: Conditional result was False
2026-02-03 00:27:53.784559 | 
2026-02-03 00:27:53.784768 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-03 00:27:53.812290 | controller | skipping: Conditional result was False
2026-02-03 00:27:53.827151 | 
2026-02-03 00:27:53.827384 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-03 00:27:53.854513 | controller | skipping: Conditional result was False
2026-02-03 00:27:53.863374 | 
2026-02-03 00:27:53.863476 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-03 00:27:53.899274 | controller | skipping: Conditional result was False
2026-02-03 00:27:53.908457 | 
2026-02-03 00:27:53.908560 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-03 00:27:53.943904 | controller | skipping: Conditional result was False
2026-02-03 00:27:53.953253 | 
2026-02-03 00:27:53.953358 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-03 00:27:53.978639 | controller | skipping: Conditional result was False
2026-02-03 00:27:53.997480 | 
2026-02-03 00:27:53.997607 | TASK [Disable Fedora Modular]
2026-02-03 00:27:54.253666 | controller | changed
2026-02-03 00:27:54.269868 | 
2026-02-03 00:27:54.270179 | TASK [Enable EPEL]
2026-02-03 00:27:54.297269 | controller | skipping: Conditional result was False
2026-02-03 00:27:54.312058 | 
2026-02-03 00:27:54.312206 | TASK [Register the RHEL node]
2026-02-03 00:27:54.870999 | 
2026-02-03 00:27:54.871173 | TASK [Show the subscription-manager status]
2026-02-03 00:27:55.445647 | controller | skipping: Conditional result was False
2026-02-03 00:27:55.455840 | 
2026-02-03 00:27:55.455981 | TASK [Enable EPEL on RHEL]
2026-02-03 00:27:55.995995 | controller | skipping: Conditional result was False
2026-02-03 00:27:56.005995 | 
2026-02-03 00:27:56.006142 | TASK [Install git and tox]
2026-02-03 00:29:18.073077 | controller | changed
2026-02-03 00:29:18.079681 | 
2026-02-03 00:29:18.079741 | TASK [include_role : prepare-workspace]
2026-02-03 00:29:18.101107 | controller | ok
2026-02-03 00:29:18.124858 | 
2026-02-03 00:29:18.124973 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-03 00:29:18.371011 | controller | ok
2026-02-03 00:29:18.381212 | 
2026-02-03 00:29:18.381317 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-03 00:29:31.741480 | controller | Output suppressed because no_log was given
2026-02-03 00:29:31.803206 | 
2026-02-03 00:29:31.803348 | TASK [include_role : prepare-workspace-openshift]
2026-02-03 00:29:31.828191 | controller | skipping: Conditional result was False
2026-02-03 00:29:31.851032 | 
2026-02-03 00:29:31.851117 | PLAY [all:!appliance]
2026-02-03 00:29:31.869227 | 
2026-02-03 00:29:31.869432 | TASK [Run add-build-sshkey role (RSA)]
2026-02-03 00:29:31.899679 | controller | ok
2026-02-03 00:29:31.915557 | 
2026-02-03 00:29:31.915768 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-03 00:29:32.197748 | controller -> localhost | ok
2026-02-03 00:29:32.205201 | 
2026-02-03 00:29:32.205463 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-03 00:29:32.231659 | controller | ok
2026-02-03 00:29:32.255691 | controller | included: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-03 00:29:32.265277 | 
2026-02-03 00:29:32.265379 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-03 00:29:32.802391 | controller -> localhost | Generating public/private rsa key pair.
2026-02-03 00:29:32.802830 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/a483f75ab5034d8bafe60faabcec6f24_id_rsa.
2026-02-03 00:29:32.802915 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/a483f75ab5034d8bafe60faabcec6f24_id_rsa.pub.
2026-02-03 00:29:32.802982 | controller -> localhost | The key fingerprint is:
2026-02-03 00:29:32.803111 | controller -> localhost | SHA256:xXkWlIFeYXqisy3NRt0Ph4mNzHFfoEOxWlsKH4m0SWI zuul-build-sshkey
2026-02-03 00:29:32.803172 | controller -> localhost | The key's randomart image is:
2026-02-03 00:29:32.803223 | controller -> localhost | +---[RSA 2048]----+
2026-02-03 00:29:32.803271 | controller -> localhost | |        E ooO=.  |
2026-02-03 00:29:32.803320 | controller -> localhost | |       . =.Oo= . |
2026-02-03 00:29:32.803368 | controller -> localhost | |         .@.% o .|
2026-02-03 00:29:32.803416 | controller -> localhost | |         o.& & +.|
2026-02-03 00:29:32.803464 | controller -> localhost | |        S o X * o|
2026-02-03 00:29:32.803529 | controller -> localhost | |         B     + |
2026-02-03 00:29:32.803597 | controller -> localhost | |        o =     .|
2026-02-03 00:29:32.803649 | controller -> localhost | |         o       |
2026-02-03 00:29:32.803701 | controller -> localhost | |                 |
2026-02-03 00:29:32.803758 | controller -> localhost | +----[SHA256]-----+
2026-02-03 00:29:32.803884 | controller -> localhost | ok: Runtime: 0:00:00.127928
2026-02-03 00:29:32.824939 | 
2026-02-03 00:29:32.825202 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-03 00:29:32.863193 | controller | ok
2026-02-03 00:29:32.883851 | controller | included: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-03 00:29:32.898351 | 
2026-02-03 00:29:32.898464 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-03 00:29:32.912618 | controller | skipping: Conditional result was False
2026-02-03 00:29:32.921184 | 
2026-02-03 00:29:32.921306 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-03 00:29:33.334251 | controller | changed
2026-02-03 00:29:33.342365 | 
2026-02-03 00:29:33.342660 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-03 00:29:33.585475 | controller | ok
2026-02-03 00:29:33.601781 | 
2026-02-03 00:29:33.601961 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-03 00:29:34.265110 | controller | changed
2026-02-03 00:29:34.276091 | 
2026-02-03 00:29:34.276241 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-03 00:29:34.898687 | controller | changed
2026-02-03 00:29:34.910129 | 
2026-02-03 00:29:34.910268 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-03 00:29:34.947190 | controller | skipping: Conditional result was False
2026-02-03 00:29:34.961397 | 
2026-02-03 00:29:34.961602 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-03 00:29:35.410764 | controller -> localhost | changed
2026-02-03 00:29:35.445687 | 
2026-02-03 00:29:35.445828 | TASK [add-build-sshkey : Add back temp key]
2026-02-03 00:29:35.735737 | controller -> localhost | Identity added: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/a483f75ab5034d8bafe60faabcec6f24_id_rsa (zuul-build-sshkey)
2026-02-03 00:29:35.735998 | controller -> localhost | ok: Runtime: 0:00:00.008411
2026-02-03 00:29:35.743538 | 
2026-02-03 00:29:35.743629 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-03 00:29:36.082499 | controller | ok
2026-02-03 00:29:36.097351 | 
2026-02-03 00:29:36.097590 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-03 00:29:36.123976 | controller | skipping: Conditional result was False
2026-02-03 00:29:36.138049 | 
2026-02-03 00:29:36.138154 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-03 00:29:36.158284 | controller | ok
2026-02-03 00:29:36.175072 | 
2026-02-03 00:29:36.175188 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-03 00:29:36.413696 | controller -> localhost | ok
2026-02-03 00:29:36.420697 | 
2026-02-03 00:29:36.420794 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-03 00:29:36.473765 | controller | ok
2026-02-03 00:29:36.489901 | controller | included: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-03 00:29:36.499599 | 
2026-02-03 00:29:36.499728 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-03 00:29:36.810361 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-03 00:29:36.810774 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/a483f75ab5034d8bafe60faabcec6f24_id_ecdsa.
2026-02-03 00:29:36.810852 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/a483f75ab5034d8bafe60faabcec6f24_id_ecdsa.pub.
2026-02-03 00:29:36.810914 | controller -> localhost | The key fingerprint is:
2026-02-03 00:29:36.810979 | controller -> localhost | SHA256:ZJ96eWymDtVlMVq3VhFmRtzS22t+8VuHflRiCb2sEJ8 zuul-build-sshkey
2026-02-03 00:29:36.811137 | controller -> localhost | The key's randomart image is:
2026-02-03 00:29:36.811220 | controller -> localhost | +---[ECDSA 521]---+
2026-02-03 00:29:36.811287 | controller -> localhost | |             .*O*|
2026-02-03 00:29:36.811353 | controller -> localhost | |          . .o*==|
2026-02-03 00:29:36.811418 | controller -> localhost | |        o  o.+o*o|
2026-02-03 00:29:36.811472 | controller -> localhost | |       o ..oEoB.o|
2026-02-03 00:29:36.811521 | controller -> localhost | |        S +..o .o|
2026-02-03 00:29:36.811578 | controller -> localhost | |         o o.  =.|
2026-02-03 00:29:36.811628 | controller -> localhost | |        o o = +.=|
2026-02-03 00:29:36.811666 | controller -> localhost | |         o = . .*|
2026-02-03 00:29:36.811702 | controller -> localhost | |         .o   .oo|
2026-02-03 00:29:36.811738 | controller -> localhost | +----[SHA256]-----+
2026-02-03 00:29:36.811861 | controller -> localhost | ok: Runtime: 0:00:00.008455
2026-02-03 00:29:36.830960 | 
2026-02-03 00:29:36.831213 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-03 00:29:36.874143 | controller | ok
2026-02-03 00:29:36.887118 | controller | included: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-03 00:29:36.903830 | 
2026-02-03 00:29:36.903978 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-03 00:29:36.929915 | controller | skipping: Conditional result was False
2026-02-03 00:29:36.940236 | 
2026-02-03 00:29:36.940374 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-03 00:29:37.210590 | controller | changed
2026-02-03 00:29:37.220656 | 
2026-02-03 00:29:37.220787 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-03 00:29:37.446509 | controller | ok
2026-02-03 00:29:37.456223 | 
2026-02-03 00:29:37.456368 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-03 00:29:38.094650 | controller | changed
2026-02-03 00:29:38.103342 | 
2026-02-03 00:29:38.103478 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-03 00:29:38.742666 | controller | changed
2026-02-03 00:29:38.755336 | 
2026-02-03 00:29:38.755477 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-03 00:29:38.795993 | controller | skipping: Conditional result was False
2026-02-03 00:29:38.852970 | 
2026-02-03 00:29:38.853136 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-03 00:29:39.113147 | controller -> localhost | changed
2026-02-03 00:29:39.125545 | 
2026-02-03 00:29:39.125652 | TASK [add-build-sshkey : Add back temp key]
2026-02-03 00:29:39.413508 | controller -> localhost | Identity added: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/a483f75ab5034d8bafe60faabcec6f24_id_ecdsa (zuul-build-sshkey)
2026-02-03 00:29:39.413706 | controller -> localhost | ok: Runtime: 0:00:00.010159
2026-02-03 00:29:39.421212 | 
2026-02-03 00:29:39.421315 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-03 00:29:39.631129 | controller | ok
2026-02-03 00:29:39.646711 | 
2026-02-03 00:29:39.646889 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-03 00:29:39.694142 | controller | skipping: Conditional result was False
2026-02-03 00:29:39.711154 | 
2026-02-03 00:29:39.711295 | TASK [include_role : remove-zuul-sshkey]
2026-02-03 00:29:39.749773 | controller | skipping: Conditional result was False
2026-02-03 00:29:39.759215 | 
2026-02-03 00:29:39.759352 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-03 00:29:40.006495 | controller | ok: "logs"
2026-02-03 00:29:40.006799 | controller | ok: All items complete
2026-02-03 00:29:40.006839 | 
2026-02-03 00:29:40.222592 | controller | ok: "artifacts"
2026-02-03 00:29:40.432945 | controller | ok: "docs"
2026-02-03 00:29:40.447933 | 
2026-02-03 00:29:40.448053 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-03 00:29:40.696002 | controller | changed: "logs"
2026-02-03 00:29:40.888469 | controller | changed: "artifacts"
2026-02-03 00:29:41.082495 | controller | changed: "docs"
2026-02-03 00:29:41.122081 | 
2026-02-03 00:29:41.122182 | PLAY RECAP
2026-02-03 00:29:41.122234 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-03 00:29:41.122263 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-03 00:29:41.122286 | 
2026-02-03 00:29:41.274162 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-03 00:29:41.275000 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-03 00:29:41.920377 | 
2026-02-03 00:29:41.920584 | PLAY [all]
2026-02-03 00:29:41.944285 | 
2026-02-03 00:29:41.944399 | TASK [Install binary dependencies]
2026-02-03 00:29:42.004923 | controller | ok
2026-02-03 00:29:42.026598 | 
2026-02-03 00:29:42.026712 | TASK [bindep : Include find tasks]
2026-02-03 00:29:42.056283 | controller | ok
2026-02-03 00:29:42.064603 | controller | included: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-03 00:29:42.071756 | 
2026-02-03 00:29:42.071829 | TASK [bindep : Look for bindep.txt]
2026-02-03 00:29:42.445765 | controller | ok
2026-02-03 00:29:42.459195 | 
2026-02-03 00:29:42.459408 | TASK [bindep : Define bindep_file fact]
2026-02-03 00:29:42.488051 | controller | skipping: Conditional result was False
2026-02-03 00:29:42.502823 | 
2026-02-03 00:29:42.503047 | TASK [bindep : Look for other-requirements.txt]
2026-02-03 00:29:42.746201 | controller | ok
2026-02-03 00:29:42.759266 | 
2026-02-03 00:29:42.759471 | TASK [bindep : Define bindep_file fact]
2026-02-03 00:29:42.796459 | controller | skipping: Conditional result was False
2026-02-03 00:29:42.811559 | 
2026-02-03 00:29:42.811737 | TASK [bindep : Look for bindep fallback file]
2026-02-03 00:29:42.849634 | controller | skipping: Conditional result was False
2026-02-03 00:29:42.866856 | 
2026-02-03 00:29:42.867081 | TASK [bindep : Define bindep_file fact]
2026-02-03 00:29:42.895568 | controller | skipping: Conditional result was False
2026-02-03 00:29:42.909787 | 
2026-02-03 00:29:42.909959 | TASK [bindep : Include bindep tasks]
2026-02-03 00:29:42.938419 | controller | skipping: Conditional result was False
2026-02-03 00:29:42.952280 | 
2026-02-03 00:29:42.952462 | TASK [bindep : Include install tasks]
2026-02-03 00:29:42.980417 | controller | skipping: Conditional result was False
2026-02-03 00:29:42.996729 | 
2026-02-03 00:29:42.996946 | LOOP [bindep : Include package tasks]
2026-02-03 00:29:43.063521 | 
2026-02-03 00:29:43.063747 | TASK [Run test-setup role]
2026-02-03 00:29:43.089182 | controller | ok
2026-02-03 00:29:43.111416 | 
2026-02-03 00:29:43.111557 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-03 00:29:43.315090 | controller | ok
2026-02-03 00:29:43.320987 | 
2026-02-03 00:29:43.321081 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-03 00:29:43.852329 | controller | skipping: Conditional result was False
2026-02-03 00:29:43.879763 | 
2026-02-03 00:29:43.879869 | PLAY RECAP
2026-02-03 00:29:43.879932 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-03 00:29:43.879963 | 
2026-02-03 00:29:43.991192 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-03 00:29:43.992109 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-03 00:29:44.583700 | 
2026-02-03 00:29:44.583827 | PLAY [controller]
2026-02-03 00:29:44.604302 | 
2026-02-03 00:29:44.604413 | TASK [Create the /root directory]
2026-02-03 00:29:44.983260 | controller | ok
2026-02-03 00:29:44.992820 | 
2026-02-03 00:29:44.992962 | TASK [Install glibc-langpack-en]
2026-02-03 00:29:48.990880 | controller | ok: Nothing to do
2026-02-03 00:29:48.996748 | 
2026-02-03 00:29:48.996815 | TASK [Ensure controller directory exists]
2026-02-03 00:29:49.218223 | controller | changed
2026-02-03 00:29:49.228725 | 
2026-02-03 00:29:49.228823 | TASK [Install container runtime]
2026-02-03 00:29:49.295705 | controller | ok
2026-02-03 00:29:49.357173 | 
2026-02-03 00:29:49.357316 | LOOP [ensure-podman : Find distribution installation]
2026-02-03 00:29:49.389784 | controller | ok: "/var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-03 00:29:49.406750 | controller | included: /var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-03 00:29:49.418072 | 
2026-02-03 00:29:49.418170 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-03 00:30:54.294252 | controller | changed
2026-02-03 00:30:54.310088 | 
2026-02-03 00:30:54.310252 | TASK [ensure-podman : Fetch podman version]
2026-02-03 00:30:54.850218 | controller | Client:       Podman Engine
2026-02-03 00:30:54.879152 | controller | Version:      4.6.2
2026-02-03 00:30:54.879188 | controller | API Version:  4.6.2
2026-02-03 00:30:54.879200 | controller | Go Version:   go1.19.12
2026-02-03 00:30:54.879224 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-03 00:30:54.879275 | controller | OS/Arch:      linux/amd64
2026-02-03 00:30:55.358381 | controller | ok: Runtime: 0:00:00.197730
2026-02-03 00:30:55.372469 | 
2026-02-03 00:30:55.372749 | TASK [ensure-podman : Print podman version installed]
2026-02-03 00:30:55.414101 | Podman version: Client:       Podman Engine
2026-02-03 00:30:55.414363 | Version:      4.6.2
2026-02-03 00:30:55.414429 | API Version:  4.6.2
2026-02-03 00:30:55.414477 | Go Version:   go1.19.12
2026-02-03 00:30:55.414518 | Built:        Mon Aug 28 19:38:31 2023
2026-02-03 00:30:55.414594 | OS/Arch:      linux/amd64
2026-02-03 00:30:55.427372 | 
2026-02-03 00:30:55.427507 | TASK [ensure-podman : Validate podman engine]
2026-02-03 00:30:55.975188 | controller | skipping: Conditional result was False
2026-02-03 00:30:55.990567 | 
2026-02-03 00:30:55.990729 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-03 00:30:56.017773 | controller | skipping: Conditional result was False
2026-02-03 00:30:56.037730 | 
2026-02-03 00:30:56.037895 | TASK [Ensure python3.8 is present]
2026-02-03 00:30:56.064129 | controller | skipping: Conditional result was False
2026-02-03 00:30:56.075183 | 
2026-02-03 00:30:56.075334 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-03 00:30:56.100122 | controller | ok
2026-02-03 00:30:56.133190 | 
2026-02-03 00:30:56.133340 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-03 00:30:57.564706 | controller | ok: Nothing to do
2026-02-03 00:30:57.574029 | 
2026-02-03 00:30:57.574181 | TASK [our-ensure-python : Also install python3-devel]
2026-02-03 00:31:06.308867 | controller | changed
2026-02-03 00:31:06.324142 | 
2026-02-03 00:31:06.324284 | TASK [Run ensure-virtualenv role]
2026-02-03 00:31:06.348421 | controller | ok
2026-02-03 00:31:06.377232 | 
2026-02-03 00:31:06.377357 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-03 00:31:06.589738 | controller | /usr/bin/virtualenv
2026-02-03 00:31:06.908351 | controller | ok: Runtime: 0:00:00.005011
2026-02-03 00:31:06.919360 | 
2026-02-03 00:31:06.919493 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-03 00:31:06.951137 | controller | skipping: Conditional result was False
2026-02-03 00:31:06.951550 | controller | ok: All items complete
2026-02-03 00:31:06.951599 | 
2026-02-03 00:31:06.976647 | 
2026-02-03 00:31:06.976901 | TASK [Find the full path of the Python interpreter]
2026-02-03 00:31:07.268595 | controller | /usr/bin/python3
2026-02-03 00:31:07.567963 | controller | ok
2026-02-03 00:31:07.575651 | 
2026-02-03 00:31:07.575753 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-03 00:31:08.481248 | controller | created virtual environment CPython3.11.0.final.0-64 in 462ms
2026-02-03 00:31:08.508835 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-03 00:31:08.509187 | 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)
2026-02-03 00:31:08.509449 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-03 00:31:08.509483 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-03 00:31:08.619806 | controller | changed
2026-02-03 00:31:08.628582 | 
2026-02-03 00:31:08.628712 | TASK [Set selinux package]
2026-02-03 00:31:08.649853 | controller | ok
2026-02-03 00:31:08.654848 | 
2026-02-03 00:31:08.654913 | TASK [Set selinux package (Fedora)]
2026-02-03 00:31:08.687004 | controller | ok
2026-02-03 00:31:08.694474 | 
2026-02-03 00:31:08.694615 | TASK [Install selinux into virtualenv]
2026-02-03 00:31:34.207356 | controller | Collecting selinux-please-lie-to-me
2026-02-03 00:31:46.460777 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-03 00:31:46.775854 | controller | Collecting setuptools<50.0.0
2026-02-03 00:31:46.781993 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-03 00:31:46.823091 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.5 MB/s eta 0:00:00
2026-02-03 00:31:46.906411 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-03 00:31:46.906620 | controller |   Attempting uninstall: setuptools
2026-02-03 00:31:46.908985 | controller |     Found existing installation: setuptools 62.6.0
2026-02-03 00:31:46.969494 | controller |     Uninstalling setuptools-62.6.0:
2026-02-03 00:31:46.977468 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-03 00:31:47.386917 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-03 00:31:58.888819 | controller |
2026-02-03 00:31:58.970307 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-03 00:31:58.970347 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-03 00:31:59.258821 | controller | ok: Runtime: 0:00:50.049378
2026-02-03 00:31:59.264742 | 
2026-02-03 00:31:59.264804 | TASK [Install pytest-forked into virtualenv]
2026-02-03 00:32:10.118777 | controller | Collecting pytest-forked
2026-02-03 00:32:22.514888 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-03 00:32:22.584105 | controller | Collecting py
2026-02-03 00:32:22.591038 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-03 00:32:22.615400 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.9 MB/s eta 0:00:00
2026-02-03 00:32:22.719073 | controller | Collecting pytest>=3.10
2026-02-03 00:32:22.722887 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-03 00:32:22.748572 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 18.8 MB/s eta 0:00:00
2026-02-03 00:32:22.783061 | controller | Collecting iniconfig>=1.0.1
2026-02-03 00:32:22.788851 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-03 00:32:22.835598 | controller | Collecting packaging>=22
2026-02-03 00:32:22.840274 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-03 00:32:22.848676 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 11.2 MB/s eta 0:00:00
2026-02-03 00:32:22.882707 | controller | Collecting pluggy<2,>=1.5
2026-02-03 00:32:22.886431 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-03 00:32:22.934908 | controller | Collecting pygments>=2.7.2
2026-02-03 00:32:22.938289 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-03 00:32:22.959786 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 68.7 MB/s eta 0:00:00
2026-02-03 00:32:23.027044 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-03 00:32:24.089639 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2026-02-03 00:32:24.098378 | controller |
2026-02-03 00:32:24.167084 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0
2026-02-03 00:32:24.167131 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-03 00:32:24.309147 | controller | ok: Runtime: 0:00:24.680430
2026-02-03 00:32:24.323084 | 
2026-02-03 00:32:24.323234 | TASK [Update pip]
2026-02-03 00:32:24.848871 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-03 00:32:34.750569 | controller | Collecting pip
2026-02-03 00:32:46.984907 | controller |   Downloading pip-26.0-py3-none-any.whl (1.8 MB)
2026-02-03 00:32:47.040282 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 36.7 MB/s eta 0:00:00
2026-02-03 00:32:47.106968 | controller | Installing collected packages: pip
2026-02-03 00:32:47.107013 | controller |   Attempting uninstall: pip
2026-02-03 00:32:47.109319 | controller |     Found existing installation: pip 22.2.2
2026-02-03 00:32:47.249017 | controller |     Uninstalling pip-22.2.2:
2026-02-03 00:32:47.264185 | controller |       Successfully uninstalled pip-22.2.2
2026-02-03 00:32:48.098468 | controller | Successfully installed pip-26.0
2026-02-03 00:32:48.388537 | controller | ok: Runtime: 0:00:23.625549
2026-02-03 00:32:48.406416 | 
2026-02-03 00:32:48.406593 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-03 00:32:48.610220 | controller | changed
2026-02-03 00:32:48.623515 | 
2026-02-03 00:32:48.623657 | TASK [Install ansible into virtualenv]
2026-02-03 00:32:49.189734 | controller | Processing ./src/github.com/ansible/ansible
2026-02-03 00:32:49.192437 | controller |   Installing build dependencies: started
2026-02-03 00:33:09.989987 | controller |   Installing build dependencies: finished with status 'done'
2026-02-03 00:33:09.991022 | controller |   Getting requirements to build wheel: started
2026-02-03 00:33:10.717124 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-03 00:33:10.718444 | controller |   Preparing metadata (pyproject.toml): started
2026-02-03 00:33:11.180273 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-03 00:33:11.184718 | 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.
2026-02-03 00:33:11.188548 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-03 00:33:11.709401 | controller | ERROR
2026-02-03 00:33:11.709586 | controller | {
2026-02-03 00:33:11.709634 | controller |   "delta": "0:00:22.354796",
2026-02-03 00:33:11.709667 | controller |   "end": "2026-02-03 00:33:11.253814",
2026-02-03 00:33:11.709696 | controller |   "msg": "non-zero return code",
2026-02-03 00:33:11.709731 | controller |   "rc": 1,
2026-02-03 00:33:11.709751 | controller |   "start": "2026-02-03 00:32:48.899018"
2026-02-03 00:33:11.709769 | controller | }
failure
2026-02-03 00:33:11.711237 | 
2026-02-03 00:33:11.711294 | PLAY RECAP
2026-02-03 00:33:11.711353 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-03 00:33:11.711387 | 
2026-02-03 00:33:11.830616 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-03 00:33:11.832108 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-03 00:33:12.445163 | 
2026-02-03 00:33:12.445280 | PLAY [all]
2026-02-03 00:33:12.467148 | 
2026-02-03 00:33:12.467274 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-03 00:33:12.749745 | controller | changed: non-zero return code
2026-02-03 00:33:12.763587 | 
2026-02-03 00:33:12.763768 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-03 00:33:12.791758 | controller | skipping: Conditional result was False
2026-02-03 00:33:12.806281 | 
2026-02-03 00:33:12.806454 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-03 00:33:12.836761 | 
2026-02-03 00:33:12.836950 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-03 00:33:12.861342 | 
2026-02-03 00:33:12.861528 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-03 00:33:12.878160 | controller | skipping: Conditional result was False
2026-02-03 00:33:12.889410 | 
2026-02-03 00:33:12.889525 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-03 00:33:12.914821 | 
2026-02-03 00:33:12.915004 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-03 00:33:12.929744 | controller | skipping: Conditional result was False
2026-02-03 00:33:12.939328 | 
2026-02-03 00:33:12.939423 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-03 00:33:12.954638 | controller | skipping: Conditional result was False
2026-02-03 00:33:12.963990 | 
2026-02-03 00:33:12.964155 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-03 00:33:12.979006 | controller | skipping: Conditional result was False
2026-02-03 00:33:13.005633 | 
2026-02-03 00:33:13.005721 | PLAY RECAP
2026-02-03 00:33:13.005772 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-03 00:33:13.005801 | 
2026-02-03 00:33:13.104555 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-03 00:33:13.105679 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-03 00:33:13.683672 | 
2026-02-03 00:33:13.683809 | PLAY [all:!appliance*]
2026-02-03 00:33:13.709189 | 
2026-02-03 00:33:13.709320 | TASK [unregister the node]
2026-02-03 00:33:14.240102 | controller | skipping: Conditional result was False
2026-02-03 00:33:14.254150 | 
2026-02-03 00:33:14.254305 | TASK [include_role : fetch-output]
2026-02-03 00:33:14.294855 | controller | ok
2026-02-03 00:33:14.337375 | 
2026-02-03 00:33:14.337518 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-03 00:33:14.393904 | controller | skipping: Conditional result was False
2026-02-03 00:33:14.404940 | 
2026-02-03 00:33:14.405144 | TASK [fetch-output : Set log path for single node]
2026-02-03 00:33:14.454302 | controller | ok
2026-02-03 00:33:14.470644 | 
2026-02-03 00:33:14.470811 | LOOP [fetch-output : Ensure local output dirs]
2026-02-03 00:33:14.887968 | controller -> localhost | ok: "/var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/logs"
2026-02-03 00:33:15.146980 | controller -> localhost | changed: "/var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/artifacts"
2026-02-03 00:33:15.383473 | controller -> localhost | changed: "/var/lib/zuul/builds/a483f75ab5034d8bafe60faabcec6f24/work/docs"
2026-02-03 00:33:15.392183 | 
2026-02-03 00:33:15.392257 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-03 00:33:16.112924 | controller | changed:
2026-02-03 00:33:16.113444 | controller | .d..t...... ./
2026-02-03 00:33:16.113514 | controller | cd+++++++++ controller/
2026-02-03 00:33:16.113583 | controller | changed: All items complete
2026-02-03 00:33:16.113629 | 
2026-02-03 00:33:16.667252 | controller | changed: .d..t...... ./
2026-02-03 00:33:17.181708 | controller | changed: .d..t...... ./
2026-02-03 00:33:17.212706 | 
2026-02-03 00:33:17.212926 | TASK [include_role : fetch-output-openshift]
2026-02-03 00:33:17.241182 | controller | skipping: Conditional result was False
2026-02-03 00:33:17.257816 | 
2026-02-03 00:33:17.258062 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-03 00:33:17.315365 | controller | skipping: Conditional result was False
2026-02-03 00:33:17.327531 | controller | skipping: Conditional result was False
2026-02-03 00:33:17.392947 | 
2026-02-03 00:33:17.393101 | PLAY [localhost]
2026-02-03 00:33:17.411612 | 
2026-02-03 00:33:17.411744 | TASK [Run Zuul manifest role]
2026-02-03 00:33:17.439828 | localhost | ok
2026-02-03 00:33:17.470993 | 
2026-02-03 00:33:17.471143 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-03 00:33:17.903972 | localhost | changed
2026-02-03 00:33:17.914340 | 
2026-02-03 00:33:17.914486 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-03 00:33:17.961696 | localhost | ok
2026-02-03 00:33:17.981382 | 
2026-02-03 00:33:17.981531 | TASK [Set zuul-log-path fact]
2026-02-03 00:33:18.004680 | localhost | ok
2026-02-03 00:33:18.023900 | 
2026-02-03 00:33:18.024000 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-03 00:33:18.068784 | localhost | ok
2026-02-03 00:33:18.081903 | 
2026-02-03 00:33:18.081994 | LOOP [Run upload-logs-swift role]
2026-02-03 00:33:18.118557 | localhost | Output suppressed because no_log was given
2026-02-03 00:33:18.168628 | 
2026-02-03 00:33:18.168736 | TASK [Set zuul-log-path fact]
2026-02-03 00:33:18.204151 | localhost | skipping: Conditional result was False
2026-02-03 00:33:18.211599 | 
2026-02-03 00:33:18.211727 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-03 00:33:18.645776 | localhost -> localhost | ok: Runtime: 0:00:00.005938
2026-02-03 00:33:18.678235 | 
2026-02-03 00:33:18.678364 | TASK [upload-logs-swift : Upload logs to swift]