2026-01-04 00:14:35.964066 | Job console starting...
2026-01-04 00:14:35.975760 | Updating repositories
2026-01-04 00:14:36.114327 | Preparing job workspace
2026-01-04 00:14:39.960450 | Running Ansible setup...
2026-01-04 00:14:45.353467 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-04 00:14:45.995240 | 
2026-01-04 00:14:45.995411 | PLAY [localhost]
2026-01-04 00:14:46.005027 | 
2026-01-04 00:14:46.005109 | TASK [Gathering Facts]
2026-01-04 00:14:47.155768 | localhost | ok
2026-01-04 00:14:47.178672 | 
2026-01-04 00:14:47.178948 | TASK [Setup log path fact]
2026-01-04 00:14:47.213305 | localhost | ok
2026-01-04 00:14:47.232926 | 
2026-01-04 00:14:47.233058 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-04 00:14:47.277971 | localhost | ok
2026-01-04 00:14:47.290243 | 
2026-01-04 00:14:47.290378 | TASK [emit-job-header : Print job information]
2026-01-04 00:14:47.347051 | # Job Information
2026-01-04 00:14:47.347417 | Ansible Version: 2.15.12
2026-01-04 00:14:47.347491 | Job: ansible-test-sanity-docker-devel
2026-01-04 00:14:47.347537 | Pipeline: periodic
2026-01-04 00:14:47.347577 | Executor: ze04.softwarefactory-project.io
2026-01-04 00:14:47.347616 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-04 00:14:47.347662 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/da2/ansible/da25d11967df4ffba81bd06876de98ae/
2026-01-04 00:14:47.347754 | Event ID: 4040b8efc4c7403f988e7928565c0397
2026-01-04 00:14:47.357935 | 
2026-01-04 00:14:47.358130 | LOOP [emit-job-header : Print node information]
2026-01-04 00:14:47.499236 | localhost | ok:
2026-01-04 00:14:47.499605 | localhost | # Node Information
2026-01-04 00:14:47.499668 | localhost | Inventory Hostname: controller
2026-01-04 00:14:47.499763 | localhost | Hostname: np0005573917
2026-01-04 00:14:47.499809 | localhost | Username: zuul
2026-01-04 00:14:47.499854 | localhost | Distro: Fedora 37
2026-01-04 00:14:47.499893 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-04 00:14:47.499931 | localhost | Region: ca-ymq-1
2026-01-04 00:14:47.499967 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-04 00:14:47.500003 | localhost | Product Name: OpenStack Nova
2026-01-04 00:14:47.500040 | localhost | Interface IP: 162.253.55.74
2026-01-04 00:14:47.514110 | 
2026-01-04 00:14:47.514367 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-04 00:14:47.983174 | localhost -> localhost | changed
2026-01-04 00:14:47.996424 | 
2026-01-04 00:14:47.996640 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-04 00:14:49.041585 | localhost -> localhost | changed
2026-01-04 00:14:49.076783 | 
2026-01-04 00:14:49.076937 | PLAY [all:!appliance*]
2026-01-04 00:14:49.102132 | 
2026-01-04 00:14:49.102286 | TASK [include_role : start-zuul-console]
2026-01-04 00:14:49.124054 | controller | ok
2026-01-04 00:14:49.139598 | 
2026-01-04 00:14:49.139804 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-04 00:14:49.527996 | controller | ok
2026-01-04 00:14:49.548869 | 
2026-01-04 00:14:49.549071 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-04 00:14:50.447849 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-04 00:14:50.454858 | 
2026-01-04 00:14:50.454926 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-04 00:14:50.987348 | controller | skipping: Conditional result was False
2026-01-04 00:14:50.994803 | 
2026-01-04 00:14:50.994876 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-04 00:14:51.019497 | controller | skipping: Conditional result was False
2026-01-04 00:14:51.030392 | 
2026-01-04 00:14:51.030594 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-04 00:14:51.056749 | controller | skipping: Conditional result was False
2026-01-04 00:14:51.066402 | 
2026-01-04 00:14:51.066516 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-04 00:14:51.092882 | controller | skipping: Conditional result was False
2026-01-04 00:14:51.101897 | 
2026-01-04 00:14:51.101998 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-04 00:14:51.128471 | controller | skipping: Conditional result was False
2026-01-04 00:14:51.139642 | 
2026-01-04 00:14:51.139776 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-04 00:14:51.165604 | controller | skipping: Conditional result was False
2026-01-04 00:14:51.181927 | 
2026-01-04 00:14:51.182034 | TASK [Disable Fedora Modular]
2026-01-04 00:14:51.442168 | controller | changed
2026-01-04 00:14:51.451928 | 
2026-01-04 00:14:51.452047 | TASK [Enable EPEL]
2026-01-04 00:14:51.488536 | controller | skipping: Conditional result was False
2026-01-04 00:14:51.498500 | 
2026-01-04 00:14:51.498642 | TASK [Register the RHEL node]
2026-01-04 00:14:52.059260 | 
2026-01-04 00:14:52.060231 | TASK [Show the subscription-manager status]
2026-01-04 00:14:52.662088 | controller | skipping: Conditional result was False
2026-01-04 00:14:52.677200 | 
2026-01-04 00:14:52.677361 | TASK [Enable EPEL on RHEL]
2026-01-04 00:14:53.237233 | controller | skipping: Conditional result was False
2026-01-04 00:14:53.243859 | 
2026-01-04 00:14:53.243941 | TASK [Install git and tox]
2026-01-04 00:16:24.154781 | controller | changed
2026-01-04 00:16:24.168054 | 
2026-01-04 00:16:24.168187 | TASK [include_role : prepare-workspace]
2026-01-04 00:16:24.211450 | controller | ok
2026-01-04 00:16:24.258280 | 
2026-01-04 00:16:24.258494 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-04 00:16:24.532067 | controller | ok
2026-01-04 00:16:24.546766 | 
2026-01-04 00:16:24.546980 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-04 00:16:37.207778 | controller | Output suppressed because no_log was given
2026-01-04 00:16:37.272145 | 
2026-01-04 00:16:37.272589 | TASK [include_role : prepare-workspace-openshift]
2026-01-04 00:16:37.300003 | controller | skipping: Conditional result was False
2026-01-04 00:16:37.330152 | 
2026-01-04 00:16:37.330264 | PLAY [all:!appliance]
2026-01-04 00:16:37.348406 | 
2026-01-04 00:16:37.348510 | TASK [Run add-build-sshkey role (RSA)]
2026-01-04 00:16:37.371115 | controller | ok
2026-01-04 00:16:37.387785 | 
2026-01-04 00:16:37.387934 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-04 00:16:37.638439 | controller -> localhost | ok
2026-01-04 00:16:37.646892 | 
2026-01-04 00:16:37.646988 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-04 00:16:37.678391 | controller | ok
2026-01-04 00:16:37.693230 | controller | included: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-04 00:16:37.699449 | 
2026-01-04 00:16:37.699574 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-04 00:16:38.215811 | controller -> localhost | Generating public/private rsa key pair.
2026-01-04 00:16:38.216220 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/da25d11967df4ffba81bd06876de98ae_id_rsa.
2026-01-04 00:16:38.216264 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/da25d11967df4ffba81bd06876de98ae_id_rsa.pub.
2026-01-04 00:16:38.216298 | controller -> localhost | The key fingerprint is:
2026-01-04 00:16:38.216331 | controller -> localhost | SHA256:tLToQL/DyBBv6jFwCfHGLdySb2TrOiFAz2YHz1aB8d8 zuul-build-sshkey
2026-01-04 00:16:38.216362 | controller -> localhost | The key's randomart image is:
2026-01-04 00:16:38.216391 | controller -> localhost | +---[RSA 2048]----+
2026-01-04 00:16:38.216417 | controller -> localhost | |.    .o..        |
2026-01-04 00:16:38.216441 | controller -> localhost | | * = ...         |
2026-01-04 00:16:38.216463 | controller -> localhost | |o % X ..o        |
2026-01-04 00:16:38.216484 | controller -> localhost | |.o / B +.o.      |
2026-01-04 00:16:38.216506 | controller -> localhost | |o * X o S. E     |
2026-01-04 00:16:38.216549 | controller -> localhost | |.o.B = .         |
2026-01-04 00:16:38.216585 | controller -> localhost | | .+.+ =          |
2026-01-04 00:16:38.216614 | controller -> localhost | | ..+   .         |
2026-01-04 00:16:38.216640 | controller -> localhost | |  o.             |
2026-01-04 00:16:38.216666 | controller -> localhost | +----[SHA256]-----+
2026-01-04 00:16:38.216768 | controller -> localhost | ok: Runtime: 0:00:00.083876
2026-01-04 00:16:38.226343 | 
2026-01-04 00:16:38.226445 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-04 00:16:38.263961 | controller | ok
2026-01-04 00:16:38.282211 | controller | included: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-04 00:16:38.296449 | 
2026-01-04 00:16:38.296540 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-04 00:16:38.324335 | controller | skipping: Conditional result was False
2026-01-04 00:16:38.334017 | 
2026-01-04 00:16:38.334128 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-04 00:16:38.825806 | controller | changed
2026-01-04 00:16:38.843804 | 
2026-01-04 00:16:38.844025 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-04 00:16:39.086290 | controller | ok
2026-01-04 00:16:39.096888 | 
2026-01-04 00:16:39.097003 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-04 00:16:39.723480 | controller | changed
2026-01-04 00:16:39.736608 | 
2026-01-04 00:16:39.736847 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-04 00:16:40.360978 | controller | changed
2026-01-04 00:16:40.367317 | 
2026-01-04 00:16:40.367410 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-04 00:16:40.403416 | controller | skipping: Conditional result was False
2026-01-04 00:16:40.416805 | 
2026-01-04 00:16:40.417000 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-04 00:16:40.893445 | controller -> localhost | changed
2026-01-04 00:16:40.928420 | 
2026-01-04 00:16:40.928583 | TASK [add-build-sshkey : Add back temp key]
2026-01-04 00:16:41.242313 | controller -> localhost | Identity added: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/da25d11967df4ffba81bd06876de98ae_id_rsa (zuul-build-sshkey)
2026-01-04 00:16:41.242618 | controller -> localhost | ok: Runtime: 0:00:00.010658
2026-01-04 00:16:41.249930 | 
2026-01-04 00:16:41.250043 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-04 00:16:41.641110 | controller | ok
2026-01-04 00:16:41.653148 | 
2026-01-04 00:16:41.653242 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-04 00:16:41.681283 | controller | skipping: Conditional result was False
2026-01-04 00:16:41.701826 | 
2026-01-04 00:16:41.702039 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-04 00:16:41.742815 | controller | ok
2026-01-04 00:16:41.768419 | 
2026-01-04 00:16:41.768580 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-04 00:16:42.019531 | controller -> localhost | ok
2026-01-04 00:16:42.027066 | 
2026-01-04 00:16:42.027142 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-04 00:16:42.057328 | controller | ok
2026-01-04 00:16:42.081804 | controller | included: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-04 00:16:42.089009 | 
2026-01-04 00:16:42.089077 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-04 00:16:42.451058 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-04 00:16:42.451332 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/da25d11967df4ffba81bd06876de98ae_id_ecdsa.
2026-01-04 00:16:42.451361 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/da25d11967df4ffba81bd06876de98ae_id_ecdsa.pub.
2026-01-04 00:16:42.451394 | controller -> localhost | The key fingerprint is:
2026-01-04 00:16:42.451414 | controller -> localhost | SHA256:G8aqNfgjHvLy4jLxlMi4fYS6kcUpPFv557JuSohZ3f0 zuul-build-sshkey
2026-01-04 00:16:42.451433 | controller -> localhost | The key's randomart image is:
2026-01-04 00:16:42.451451 | controller -> localhost | +---[ECDSA 521]---+
2026-01-04 00:16:42.451469 | controller -> localhost | |                 |
2026-01-04 00:16:42.451486 | controller -> localhost | |                 |
2026-01-04 00:16:42.451503 | controller -> localhost | |                 |
2026-01-04 00:16:42.451519 | controller -> localhost | |.. o.. o         |
2026-01-04 00:16:42.451536 | controller -> localhost | |++==. . S        |
2026-01-04 00:16:42.451552 | controller -> localhost | |=BO o. o +       |
2026-01-04 00:16:42.451569 | controller -> localhost | |=X.oo.+.. E      |
2026-01-04 00:16:42.451586 | controller -> localhost | |=.*ooB+.         |
2026-01-04 00:16:42.451602 | controller -> localhost | |.=.BO++o         |
2026-01-04 00:16:42.451619 | controller -> localhost | +----[SHA256]-----+
2026-01-04 00:16:42.451698 | controller -> localhost | ok: Runtime: 0:00:00.016984
2026-01-04 00:16:42.458905 | 
2026-01-04 00:16:42.458972 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-04 00:16:42.500982 | controller | ok
2026-01-04 00:16:42.508768 | controller | included: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-04 00:16:42.518396 | 
2026-01-04 00:16:42.518465 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-04 00:16:42.546539 | controller | skipping: Conditional result was False
2026-01-04 00:16:42.554193 | 
2026-01-04 00:16:42.554276 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-04 00:16:42.828565 | controller | changed
2026-01-04 00:16:42.839305 | 
2026-01-04 00:16:42.839582 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-04 00:16:43.059648 | controller | ok
2026-01-04 00:16:43.071038 | 
2026-01-04 00:16:43.071243 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-04 00:16:43.734190 | controller | changed
2026-01-04 00:16:43.740248 | 
2026-01-04 00:16:43.740318 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-04 00:16:44.387193 | controller | changed
2026-01-04 00:16:44.404117 | 
2026-01-04 00:16:44.404309 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-04 00:16:44.424200 | controller | skipping: Conditional result was False
2026-01-04 00:16:44.497892 | 
2026-01-04 00:16:44.498075 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-04 00:16:44.750869 | controller -> localhost | changed
2026-01-04 00:16:44.763005 | 
2026-01-04 00:16:44.763102 | TASK [add-build-sshkey : Add back temp key]
2026-01-04 00:16:45.099932 | controller -> localhost | Identity added: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/da25d11967df4ffba81bd06876de98ae_id_ecdsa (zuul-build-sshkey)
2026-01-04 00:16:45.100193 | controller -> localhost | ok: Runtime: 0:00:00.014609
2026-01-04 00:16:45.109144 | 
2026-01-04 00:16:45.109234 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-04 00:16:45.332279 | controller | ok
2026-01-04 00:16:45.351534 | 
2026-01-04 00:16:45.351641 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-04 00:16:45.377950 | controller | skipping: Conditional result was False
2026-01-04 00:16:45.397817 | 
2026-01-04 00:16:45.397991 | TASK [include_role : remove-zuul-sshkey]
2026-01-04 00:16:45.414941 | controller | skipping: Conditional result was False
2026-01-04 00:16:45.425853 | 
2026-01-04 00:16:45.426000 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-04 00:16:45.663065 | controller | ok: "logs"
2026-01-04 00:16:45.667118 | controller | ok: All items complete
2026-01-04 00:16:45.667205 | 
2026-01-04 00:16:45.851778 | controller | ok: "artifacts"
2026-01-04 00:16:46.045921 | controller | ok: "docs"
2026-01-04 00:16:46.070526 | 
2026-01-04 00:16:46.070779 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-04 00:16:46.322145 | controller | changed: "logs"
2026-01-04 00:16:46.523392 | controller | changed: "artifacts"
2026-01-04 00:16:46.724156 | controller | changed: "docs"
2026-01-04 00:16:46.767050 | 
2026-01-04 00:16:46.767258 | PLAY RECAP
2026-01-04 00:16:46.767354 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-04 00:16:46.767412 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-04 00:16:46.767453 | 
2026-01-04 00:16:46.935329 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-04 00:16:46.936374 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-04 00:16:47.524540 | 
2026-01-04 00:16:47.524708 | PLAY [all]
2026-01-04 00:16:47.548636 | 
2026-01-04 00:16:47.548795 | TASK [Install binary dependencies]
2026-01-04 00:16:47.611744 | controller | ok
2026-01-04 00:16:47.632540 | 
2026-01-04 00:16:47.632672 | TASK [bindep : Include find tasks]
2026-01-04 00:16:47.674692 | controller | ok
2026-01-04 00:16:47.684596 | controller | included: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-04 00:16:47.691356 | 
2026-01-04 00:16:47.691421 | TASK [bindep : Look for bindep.txt]
2026-01-04 00:16:48.128344 | controller | ok
2026-01-04 00:16:48.140215 | 
2026-01-04 00:16:48.140345 | TASK [bindep : Define bindep_file fact]
2026-01-04 00:16:48.166315 | controller | skipping: Conditional result was False
2026-01-04 00:16:48.176408 | 
2026-01-04 00:16:48.176543 | TASK [bindep : Look for other-requirements.txt]
2026-01-04 00:16:48.391572 | controller | ok
2026-01-04 00:16:48.405750 | 
2026-01-04 00:16:48.405903 | TASK [bindep : Define bindep_file fact]
2026-01-04 00:16:48.444972 | controller | skipping: Conditional result was False
2026-01-04 00:16:48.460020 | 
2026-01-04 00:16:48.460258 | TASK [bindep : Look for bindep fallback file]
2026-01-04 00:16:48.508343 | controller | skipping: Conditional result was False
2026-01-04 00:16:48.524801 | 
2026-01-04 00:16:48.524967 | TASK [bindep : Define bindep_file fact]
2026-01-04 00:16:48.564574 | controller | skipping: Conditional result was False
2026-01-04 00:16:48.580221 | 
2026-01-04 00:16:48.580376 | TASK [bindep : Include bindep tasks]
2026-01-04 00:16:48.629499 | controller | skipping: Conditional result was False
2026-01-04 00:16:48.638702 | 
2026-01-04 00:16:48.638800 | TASK [bindep : Include install tasks]
2026-01-04 00:16:48.685072 | controller | skipping: Conditional result was False
2026-01-04 00:16:48.701456 | 
2026-01-04 00:16:48.701566 | LOOP [bindep : Include package tasks]
2026-01-04 00:16:48.763408 | 
2026-01-04 00:16:48.763643 | TASK [Run test-setup role]
2026-01-04 00:16:48.788779 | controller | ok
2026-01-04 00:16:48.811229 | 
2026-01-04 00:16:48.811420 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-04 00:16:49.036618 | controller | ok
2026-01-04 00:16:49.050588 | 
2026-01-04 00:16:49.050753 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-04 00:16:49.609827 | controller | skipping: Conditional result was False
2026-01-04 00:16:49.667877 | 
2026-01-04 00:16:49.668000 | PLAY RECAP
2026-01-04 00:16:49.668057 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-04 00:16:49.668084 | 
2026-01-04 00:16:49.804303 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-04 00:16:49.805308 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-04 00:16:50.458962 | 
2026-01-04 00:16:50.459204 | PLAY [controller]
2026-01-04 00:16:50.481640 | 
2026-01-04 00:16:50.481814 | TASK [Create the /root directory]
2026-01-04 00:16:50.947086 | controller | ok
2026-01-04 00:16:50.957644 | 
2026-01-04 00:16:50.957816 | TASK [Install glibc-langpack-en]
2026-01-04 00:16:55.076335 | controller | ok: Nothing to do
2026-01-04 00:16:55.085013 | 
2026-01-04 00:16:55.085140 | TASK [Ensure controller directory exists]
2026-01-04 00:16:55.297441 | controller | changed
2026-01-04 00:16:55.306360 | 
2026-01-04 00:16:55.306457 | TASK [Install container runtime]
2026-01-04 00:16:55.400212 | controller | ok
2026-01-04 00:16:55.450598 | 
2026-01-04 00:16:55.450751 | LOOP [ensure-podman : Find distribution installation]
2026-01-04 00:16:55.490118 | controller | ok: "/var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-04 00:16:55.506931 | controller | included: /var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-04 00:16:55.516321 | 
2026-01-04 00:16:55.516414 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-04 00:18:01.108517 | controller | changed
2026-01-04 00:18:01.120358 | 
2026-01-04 00:18:01.120538 | TASK [ensure-podman : Fetch podman version]
2026-01-04 00:18:01.675538 | controller | Client:       Podman Engine
2026-01-04 00:18:01.675645 | controller | Version:      4.6.2
2026-01-04 00:18:01.675690 | controller | API Version:  4.6.2
2026-01-04 00:18:01.675730 | controller | Go Version:   go1.19.12
2026-01-04 00:18:01.675779 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-04 00:18:01.675820 | controller | OS/Arch:      linux/amd64
2026-01-04 00:18:02.171228 | controller | ok: Runtime: 0:00:00.180354
2026-01-04 00:18:02.178465 | 
2026-01-04 00:18:02.178727 | TASK [ensure-podman : Print podman version installed]
2026-01-04 00:18:02.212042 | Podman version: Client:       Podman Engine
2026-01-04 00:18:02.212224 | Version:      4.6.2
2026-01-04 00:18:02.212252 | API Version:  4.6.2
2026-01-04 00:18:02.212272 | Go Version:   go1.19.12
2026-01-04 00:18:02.212291 | Built:        Mon Aug 28 19:38:31 2023
2026-01-04 00:18:02.212309 | OS/Arch:      linux/amd64
2026-01-04 00:18:02.218725 | 
2026-01-04 00:18:02.218805 | TASK [ensure-podman : Validate podman engine]
2026-01-04 00:18:02.755251 | controller | skipping: Conditional result was False
2026-01-04 00:18:02.763149 | 
2026-01-04 00:18:02.763291 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-04 00:18:02.790902 | controller | skipping: Conditional result was False
2026-01-04 00:18:02.813143 | 
2026-01-04 00:18:02.813264 | TASK [Ensure python3.8 is present]
2026-01-04 00:18:02.840331 | controller | skipping: Conditional result was False
2026-01-04 00:18:02.849858 | 
2026-01-04 00:18:02.849960 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-04 00:18:02.887715 | controller | ok
2026-01-04 00:18:02.931238 | 
2026-01-04 00:18:02.931420 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-04 00:18:04.408017 | controller | ok: Nothing to do
2026-01-04 00:18:04.421986 | 
2026-01-04 00:18:04.422139 | TASK [our-ensure-python : Also install python3-devel]
2026-01-04 00:18:14.513686 | controller | changed
2026-01-04 00:18:14.527439 | 
2026-01-04 00:18:14.527628 | TASK [Run ensure-virtualenv role]
2026-01-04 00:18:14.549669 | controller | ok
2026-01-04 00:18:14.571729 | 
2026-01-04 00:18:14.571850 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-04 00:18:14.862569 | controller | /usr/bin/virtualenv
2026-01-04 00:18:15.183954 | controller | ok: Runtime: 0:00:00.005373
2026-01-04 00:18:15.202475 | 
2026-01-04 00:18:15.202669 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-04 00:18:15.230979 | controller | skipping: Conditional result was False
2026-01-04 00:18:15.231527 | controller | ok: All items complete
2026-01-04 00:18:15.231617 | 
2026-01-04 00:18:15.259253 | 
2026-01-04 00:18:15.259379 | TASK [Find the full path of the Python interpreter]
2026-01-04 00:18:15.488547 | controller | /usr/bin/python3
2026-01-04 00:18:15.803104 | controller | ok
2026-01-04 00:18:15.812423 | 
2026-01-04 00:18:15.812577 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-04 00:18:16.749072 | controller | created virtual environment CPython3.11.0.final.0-64 in 548ms
2026-01-04 00:18:16.783943 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-04 00:18:16.784447 | 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-01-04 00:18:16.784683 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-04 00:18:16.785011 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-04 00:18:16.859388 | controller | changed
2026-01-04 00:18:16.873858 | 
2026-01-04 00:18:16.874016 | TASK [Set selinux package]
2026-01-04 00:18:16.914765 | controller | ok
2026-01-04 00:18:16.924726 | 
2026-01-04 00:18:16.924820 | TASK [Set selinux package (Fedora)]
2026-01-04 00:18:16.983845 | controller | ok
2026-01-04 00:18:16.993095 | 
2026-01-04 00:18:16.993188 | TASK [Install selinux into virtualenv]
2026-01-04 00:18:42.483990 | controller | Collecting selinux-please-lie-to-me
2026-01-04 00:18:54.702345 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-04 00:18:55.019928 | controller | Collecting setuptools<50.0.0
2026-01-04 00:18:55.025528 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-04 00:18:55.088265 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 13.9 MB/s eta 0:00:00
2026-01-04 00:18:55.168900 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-04 00:18:55.169053 | controller |   Attempting uninstall: setuptools
2026-01-04 00:18:55.171455 | controller |     Found existing installation: setuptools 62.6.0
2026-01-04 00:18:55.229857 | controller |     Uninstalling setuptools-62.6.0:
2026-01-04 00:18:55.238476 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-04 00:18:55.576770 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-04 00:19:07.067031 | controller |
2026-01-04 00:19:07.184241 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-04 00:19:07.184308 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-04 00:19:07.578126 | controller | ok: Runtime: 0:00:49.965437
2026-01-04 00:19:07.591529 | 
2026-01-04 00:19:07.591724 | TASK [Install pytest-forked into virtualenv]
2026-01-04 00:19:19.334947 | controller | Collecting pytest-forked
2026-01-04 00:19:31.564920 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-04 00:19:31.610921 | controller | Collecting py
2026-01-04 00:19:31.617186 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-04 00:19:31.639347 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.1 MB/s eta 0:00:00
2026-01-04 00:19:31.746881 | controller | Collecting pytest>=3.10
2026-01-04 00:19:31.752628 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-04 00:19:31.784777 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 12.4 MB/s eta 0:00:00
2026-01-04 00:19:31.816258 | controller | Collecting iniconfig>=1.0.1
2026-01-04 00:19:31.821309 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-04 00:19:31.862120 | controller | Collecting packaging>=22
2026-01-04 00:19:31.865803 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2026-01-04 00:19:31.870543 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 22.5 MB/s eta 0:00:00
2026-01-04 00:19:31.900876 | controller | Collecting pluggy<2,>=1.5
2026-01-04 00:19:31.904295 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-04 00:19:31.948519 | controller | Collecting pygments>=2.7.2
2026-01-04 00:19:31.951957 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-04 00:19:31.996763 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 29.7 MB/s eta 0:00:00
2026-01-04 00:19:32.066532 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-04 00:19:33.100942 | 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
2026-01-04 00:19:33.110080 | controller |
2026-01-04 00:19:33.198682 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-04 00:19:33.198734 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-04 00:19:33.664153 | controller | ok: Runtime: 0:00:25.359596
2026-01-04 00:19:33.681086 | 
2026-01-04 00:19:33.681329 | TASK [Update pip]
2026-01-04 00:19:34.236233 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-04 00:20:07.839426 | controller | Collecting pip
2026-01-04 00:20:20.205115 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-04 00:20:20.278730 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 26.1 MB/s eta 0:00:00
2026-01-04 00:20:20.343585 | controller | Installing collected packages: pip
2026-01-04 00:20:20.343883 | controller |   Attempting uninstall: pip
2026-01-04 00:20:20.347042 | controller |     Found existing installation: pip 22.2.2
2026-01-04 00:20:20.482018 | controller |     Uninstalling pip-22.2.2:
2026-01-04 00:20:20.496884 | controller |       Successfully uninstalled pip-22.2.2
2026-01-04 00:20:21.312612 | controller | Successfully installed pip-25.3
2026-01-04 00:20:21.764906 | controller | ok: Runtime: 0:00:47.456124
2026-01-04 00:20:21.778073 | 
2026-01-04 00:20:21.778352 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-04 00:20:22.008822 | controller | changed
2026-01-04 00:20:22.023578 | 
2026-01-04 00:20:22.023822 | TASK [Install ansible into virtualenv]
2026-01-04 00:20:22.538689 | controller | Processing ./src/github.com/ansible/ansible
2026-01-04 00:20:22.541850 | controller |   Installing build dependencies: started
2026-01-04 00:20:45.431080 | controller |   Installing build dependencies: finished with status 'done'
2026-01-04 00:20:45.432223 | controller |   Getting requirements to build wheel: started
2026-01-04 00:20:46.169125 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-04 00:20:46.170802 | controller |   Preparing metadata (pyproject.toml): started
2026-01-04 00:20:46.631732 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-04 00:20:46.637292 | 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-01-04 00:20:46.640879 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-04 00:20:47.089894 | controller | ERROR
2026-01-04 00:20:47.090252 | controller | {
2026-01-04 00:20:47.090316 | controller |   "delta": "0:00:24.443076",
2026-01-04 00:20:47.090361 | controller |   "end": "2026-01-04 00:20:46.707971",
2026-01-04 00:20:47.090398 | controller |   "msg": "non-zero return code",
2026-01-04 00:20:47.090462 | controller |   "rc": 1,
2026-01-04 00:20:47.090498 | controller |   "start": "2026-01-04 00:20:22.264895"
2026-01-04 00:20:47.090532 | controller | }
failure
2026-01-04 00:20:47.093400 | 
2026-01-04 00:20:47.093502 | PLAY RECAP
2026-01-04 00:20:47.093585 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-04 00:20:47.093628 | 
2026-01-04 00:20:47.273273 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-04 00:20:47.275336 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-04 00:20:47.889602 | 
2026-01-04 00:20:47.889785 | PLAY [all]
2026-01-04 00:20:47.915113 | 
2026-01-04 00:20:47.915251 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-04 00:20:48.199463 | controller | changed: non-zero return code
2026-01-04 00:20:48.212234 | 
2026-01-04 00:20:48.212396 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-04 00:20:48.240844 | controller | skipping: Conditional result was False
2026-01-04 00:20:48.254238 | 
2026-01-04 00:20:48.254390 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-04 00:20:48.297351 | 
2026-01-04 00:20:48.297721 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-04 00:20:48.346578 | 
2026-01-04 00:20:48.346843 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-04 00:20:48.373277 | controller | skipping: Conditional result was False
2026-01-04 00:20:48.384330 | 
2026-01-04 00:20:48.384455 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-04 00:20:48.417603 | 
2026-01-04 00:20:48.417821 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-04 00:20:48.443241 | controller | skipping: Conditional result was False
2026-01-04 00:20:48.452775 | 
2026-01-04 00:20:48.452878 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-04 00:20:48.478861 | controller | skipping: Conditional result was False
2026-01-04 00:20:48.488044 | 
2026-01-04 00:20:48.488148 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-04 00:20:48.514200 | controller | skipping: Conditional result was False
2026-01-04 00:20:48.559866 | 
2026-01-04 00:20:48.559974 | PLAY RECAP
2026-01-04 00:20:48.560031 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-04 00:20:48.560061 | 
2026-01-04 00:20:48.688321 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-04 00:20:48.690184 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-04 00:20:49.282393 | 
2026-01-04 00:20:49.282524 | PLAY [all:!appliance*]
2026-01-04 00:20:49.305123 | 
2026-01-04 00:20:49.305249 | TASK [unregister the node]
2026-01-04 00:20:49.836933 | controller | skipping: Conditional result was False
2026-01-04 00:20:49.850416 | 
2026-01-04 00:20:49.850596 | TASK [include_role : fetch-output]
2026-01-04 00:20:49.902297 | controller | ok
2026-01-04 00:20:49.943083 | 
2026-01-04 00:20:49.943231 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-04 00:20:50.019818 | controller | skipping: Conditional result was False
2026-01-04 00:20:50.029407 | 
2026-01-04 00:20:50.029559 | TASK [fetch-output : Set log path for single node]
2026-01-04 00:20:50.073153 | controller | ok
2026-01-04 00:20:50.081244 | 
2026-01-04 00:20:50.081337 | LOOP [fetch-output : Ensure local output dirs]
2026-01-04 00:20:50.531108 | controller -> localhost | ok: "/var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/logs"
2026-01-04 00:20:50.807255 | controller -> localhost | changed: "/var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/artifacts"
2026-01-04 00:20:51.086933 | controller -> localhost | changed: "/var/lib/zuul/builds/da25d11967df4ffba81bd06876de98ae/work/docs"
2026-01-04 00:20:51.113879 | 
2026-01-04 00:20:51.114142 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-04 00:20:51.887733 | controller | changed:
2026-01-04 00:20:51.888165 | controller | .d..t...... ./
2026-01-04 00:20:51.888253 | controller | cd+++++++++ controller/
2026-01-04 00:20:51.888346 | controller | changed: All items complete
2026-01-04 00:20:51.888403 | 
2026-01-04 00:20:52.510655 | controller | changed: .d..t...... ./
2026-01-04 00:20:53.027917 | controller | changed: .d..t...... ./
2026-01-04 00:20:53.070351 | 
2026-01-04 00:20:53.070572 | TASK [include_role : fetch-output-openshift]
2026-01-04 00:20:53.097821 | controller | skipping: Conditional result was False
2026-01-04 00:20:53.111087 | 
2026-01-04 00:20:53.111203 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-04 00:20:53.162868 | controller | skipping: Conditional result was False
2026-01-04 00:20:53.182455 | controller | skipping: Conditional result was False
2026-01-04 00:20:53.245936 | 
2026-01-04 00:20:53.246086 | PLAY [localhost]
2026-01-04 00:20:53.264703 | 
2026-01-04 00:20:53.264835 | TASK [Run Zuul manifest role]
2026-01-04 00:20:53.287976 | localhost | ok
2026-01-04 00:20:53.310376 | 
2026-01-04 00:20:53.310510 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-04 00:20:53.682144 | localhost | changed
2026-01-04 00:20:53.693216 | 
2026-01-04 00:20:53.693349 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-04 00:20:53.737390 | localhost | ok
2026-01-04 00:20:53.749377 | 
2026-01-04 00:20:53.749466 | TASK [Set zuul-log-path fact]
2026-01-04 00:20:53.771051 | localhost | ok
2026-01-04 00:20:53.791302 | 
2026-01-04 00:20:53.791406 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-04 00:20:53.830957 | localhost | ok
2026-01-04 00:20:53.839247 | 
2026-01-04 00:20:53.839314 | LOOP [Run upload-logs-swift role]
2026-01-04 00:20:53.874239 | localhost | Output suppressed because no_log was given
2026-01-04 00:20:53.899210 | 
2026-01-04 00:20:53.899314 | TASK [Set zuul-log-path fact]
2026-01-04 00:20:53.933791 | localhost | skipping: Conditional result was False
2026-01-04 00:20:53.938894 | 
2026-01-04 00:20:53.938966 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-04 00:20:54.373084 | localhost -> localhost | ok: Runtime: 0:00:00.006218
2026-01-04 00:20:54.410008 | 
2026-01-04 00:20:54.410152 | TASK [upload-logs-swift : Upload logs to swift]