2026-02-13 00:18:02.851329 | Job console starting...
2026-02-13 00:18:02.860940 | Updating repositories
2026-02-13 00:18:02.986513 | Preparing job workspace
2026-02-13 00:18:07.510216 | Running Ansible setup...
2026-02-13 00:18:12.610874 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-13 00:18:13.231717 | 
2026-02-13 00:18:13.231857 | PLAY [localhost]
2026-02-13 00:18:13.240925 | 
2026-02-13 00:18:13.241055 | TASK [Gathering Facts]
2026-02-13 00:18:14.236642 | localhost | ok
2026-02-13 00:18:14.263228 | 
2026-02-13 00:18:14.263387 | TASK [Setup log path fact]
2026-02-13 00:18:14.284382 | localhost | ok
2026-02-13 00:18:14.297146 | 
2026-02-13 00:18:14.297237 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-13 00:18:14.324831 | localhost | ok
2026-02-13 00:18:14.336235 | 
2026-02-13 00:18:14.336349 | TASK [emit-job-header : Print job information]
2026-02-13 00:18:14.367076 | # Job Information
2026-02-13 00:18:14.367276 | Ansible Version: 2.15.12
2026-02-13 00:18:14.367322 | Job: ansible-test-sanity-docker-milestone
2026-02-13 00:18:14.367352 | Pipeline: periodic
2026-02-13 00:18:14.367378 | Executor: ze01.softwarefactory-project.io
2026-02-13 00:18:14.367403 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-13 00:18:14.367437 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/e80/ansible/e80101339b5a4d689198f924d248732a/
2026-02-13 00:18:14.367473 | Event ID: 0fb89987ddbf4579b8946ad3b376b620
2026-02-13 00:18:14.373150 | 
2026-02-13 00:18:14.373257 | LOOP [emit-job-header : Print node information]
2026-02-13 00:18:14.477903 | localhost | ok:
2026-02-13 00:18:14.478118 | localhost | # Node Information
2026-02-13 00:18:14.478148 | localhost | Inventory Hostname: controller
2026-02-13 00:18:14.478169 | localhost | Hostname: np0005618405
2026-02-13 00:18:14.478188 | localhost | Username: zuul
2026-02-13 00:18:14.478209 | localhost | Distro: Fedora 37
2026-02-13 00:18:14.478227 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-13 00:18:14.478245 | localhost | Region: ca-ymq-1
2026-02-13 00:18:14.478262 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-13 00:18:14.478283 | localhost | Product Name: OpenStack Nova
2026-02-13 00:18:14.478302 | localhost | Interface IP: 199.204.45.72
2026-02-13 00:18:14.487731 | 
2026-02-13 00:18:14.487835 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-13 00:18:14.939674 | localhost -> localhost | changed
2026-02-13 00:18:14.952454 | 
2026-02-13 00:18:14.952625 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-13 00:18:15.869141 | localhost -> localhost | changed
2026-02-13 00:18:15.890582 | 
2026-02-13 00:18:15.890686 | PLAY [all:!appliance*]
2026-02-13 00:18:15.907266 | 
2026-02-13 00:18:15.907342 | TASK [include_role : start-zuul-console]
2026-02-13 00:18:15.927452 | controller | ok
2026-02-13 00:18:15.941893 | 
2026-02-13 00:18:15.941983 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-13 00:18:16.306175 | controller | ok
2026-02-13 00:18:16.325847 | 
2026-02-13 00:18:16.325983 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-13 00:18:17.409538 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-13 00:18:17.423963 | 
2026-02-13 00:18:17.424177 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-13 00:18:17.976820 | controller | skipping: Conditional result was False
2026-02-13 00:18:17.985518 | 
2026-02-13 00:18:17.985613 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-13 00:18:18.021309 | controller | skipping: Conditional result was False
2026-02-13 00:18:18.030123 | 
2026-02-13 00:18:18.030266 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-13 00:18:18.065897 | controller | skipping: Conditional result was False
2026-02-13 00:18:18.074646 | 
2026-02-13 00:18:18.074770 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-13 00:18:18.101911 | controller | skipping: Conditional result was False
2026-02-13 00:18:18.111311 | 
2026-02-13 00:18:18.111443 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-13 00:18:18.137488 | controller | skipping: Conditional result was False
2026-02-13 00:18:18.147309 | 
2026-02-13 00:18:18.147457 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-13 00:18:18.194370 | controller | skipping: Conditional result was False
2026-02-13 00:18:18.211557 | 
2026-02-13 00:18:18.211794 | TASK [Disable Fedora Modular]
2026-02-13 00:18:18.456303 | controller | changed
2026-02-13 00:18:18.470900 | 
2026-02-13 00:18:18.471099 | TASK [Enable EPEL]
2026-02-13 00:18:18.496757 | controller | skipping: Conditional result was False
2026-02-13 00:18:18.506699 | 
2026-02-13 00:18:18.506837 | TASK [Register the RHEL node]
2026-02-13 00:18:19.067445 | 
2026-02-13 00:18:19.067704 | TASK [Show the subscription-manager status]
2026-02-13 00:18:19.656822 | controller | skipping: Conditional result was False
2026-02-13 00:18:19.672715 | 
2026-02-13 00:18:19.672879 | TASK [Enable EPEL on RHEL]
2026-02-13 00:18:20.217993 | controller | skipping: Conditional result was False
2026-02-13 00:18:20.233496 | 
2026-02-13 00:18:20.233684 | TASK [Install git and tox]
2026-02-13 00:19:42.088938 | controller | changed
2026-02-13 00:19:42.095521 | 
2026-02-13 00:19:42.095631 | TASK [include_role : prepare-workspace]
2026-02-13 00:19:42.116264 | controller | ok
2026-02-13 00:19:42.138183 | 
2026-02-13 00:19:42.138321 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-13 00:19:42.371932 | controller | ok
2026-02-13 00:19:42.387626 | 
2026-02-13 00:19:42.387811 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-13 00:19:55.820213 | controller | Output suppressed because no_log was given
2026-02-13 00:19:55.862891 | 
2026-02-13 00:19:55.863009 | TASK [include_role : prepare-workspace-openshift]
2026-02-13 00:19:55.889231 | controller | skipping: Conditional result was False
2026-02-13 00:19:55.912821 | 
2026-02-13 00:19:55.912919 | PLAY [all:!appliance]
2026-02-13 00:19:55.933006 | 
2026-02-13 00:19:55.933157 | TASK [Run add-build-sshkey role (RSA)]
2026-02-13 00:19:55.967507 | controller | ok
2026-02-13 00:19:55.982088 | 
2026-02-13 00:19:55.982191 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-13 00:19:56.232355 | controller -> localhost | ok
2026-02-13 00:19:56.247282 | 
2026-02-13 00:19:56.247632 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-13 00:19:56.287990 | controller | ok
2026-02-13 00:19:56.313640 | controller | included: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-13 00:19:56.324101 | 
2026-02-13 00:19:56.324214 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-13 00:19:56.929754 | controller -> localhost | Generating public/private rsa key pair.
2026-02-13 00:19:56.930083 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/e80101339b5a4d689198f924d248732a_id_rsa.
2026-02-13 00:19:56.930155 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/e80101339b5a4d689198f924d248732a_id_rsa.pub.
2026-02-13 00:19:56.930203 | controller -> localhost | The key fingerprint is:
2026-02-13 00:19:56.930247 | controller -> localhost | SHA256:94hdfv+z7x+ChMkW8V94JWw4wzoJgVB4PsulRz9Yl+o zuul-build-sshkey
2026-02-13 00:19:56.930317 | controller -> localhost | The key's randomart image is:
2026-02-13 00:19:56.930376 | controller -> localhost | +---[RSA 2048]----+
2026-02-13 00:19:56.930434 | controller -> localhost | |    .+...o . o. .|
2026-02-13 00:19:56.930478 | controller -> localhost | |    . o . o = +..|
2026-02-13 00:19:56.930519 | controller -> localhost | |     o   o + * o |
2026-02-13 00:19:56.930560 | controller -> localhost | |      o + O + o  |
2026-02-13 00:19:56.930599 | controller -> localhost | |     . *SO.=..   |
2026-02-13 00:19:56.930661 | controller -> localhost | |      + ++==.    |
2026-02-13 00:19:56.930712 | controller -> localhost | |       ...ooo... |
2026-02-13 00:19:56.930754 | controller -> localhost | |          E  ..o.|
2026-02-13 00:19:56.930794 | controller -> localhost | |               o%|
2026-02-13 00:19:56.930840 | controller -> localhost | +----[SHA256]-----+
2026-02-13 00:19:56.930961 | controller -> localhost | ok: Runtime: 0:00:00.168231
2026-02-13 00:19:56.947195 | 
2026-02-13 00:19:56.947366 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-13 00:19:56.987125 | controller | ok
2026-02-13 00:19:57.007910 | controller | included: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-13 00:19:57.022151 | 
2026-02-13 00:19:57.022306 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-13 00:19:57.048401 | controller | skipping: Conditional result was False
2026-02-13 00:19:57.058946 | 
2026-02-13 00:19:57.059189 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-13 00:19:57.494774 | controller | changed
2026-02-13 00:19:57.505498 | 
2026-02-13 00:19:57.505623 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-13 00:19:57.725636 | controller | ok
2026-02-13 00:19:57.734875 | 
2026-02-13 00:19:57.734984 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-13 00:19:58.366863 | controller | changed
2026-02-13 00:19:58.382773 | 
2026-02-13 00:19:58.382951 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-13 00:19:59.061478 | controller | changed
2026-02-13 00:19:59.068142 | 
2026-02-13 00:19:59.068461 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-13 00:19:59.092743 | controller | skipping: Conditional result was False
2026-02-13 00:19:59.099920 | 
2026-02-13 00:19:59.100006 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-13 00:19:59.522758 | controller -> localhost | changed
2026-02-13 00:19:59.542767 | 
2026-02-13 00:19:59.542901 | TASK [add-build-sshkey : Add back temp key]
2026-02-13 00:19:59.848336 | controller -> localhost | Identity added: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/e80101339b5a4d689198f924d248732a_id_rsa (zuul-build-sshkey)
2026-02-13 00:19:59.848737 | controller -> localhost | ok: Runtime: 0:00:00.016320
2026-02-13 00:19:59.876146 | 
2026-02-13 00:19:59.876345 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-13 00:20:00.217086 | controller | ok
2026-02-13 00:20:00.224859 | 
2026-02-13 00:20:00.224939 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-13 00:20:00.261920 | controller | skipping: Conditional result was False
2026-02-13 00:20:00.283692 | 
2026-02-13 00:20:00.283848 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-13 00:20:00.317734 | controller | ok
2026-02-13 00:20:00.335506 | 
2026-02-13 00:20:00.335604 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-13 00:20:00.584566 | controller -> localhost | ok
2026-02-13 00:20:00.591626 | 
2026-02-13 00:20:00.591697 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-13 00:20:00.613844 | controller | ok
2026-02-13 00:20:00.625328 | controller | included: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-13 00:20:00.632482 | 
2026-02-13 00:20:00.632552 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-13 00:20:00.945522 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-13 00:20:00.945864 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/e80101339b5a4d689198f924d248732a_id_ecdsa.
2026-02-13 00:20:00.945927 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/e80101339b5a4d689198f924d248732a_id_ecdsa.pub.
2026-02-13 00:20:00.945993 | controller -> localhost | The key fingerprint is:
2026-02-13 00:20:00.946082 | controller -> localhost | SHA256:+qPDTcg/CCxfjtuKv8bV7lJHQYYODNqdmSPDmcZAEM8 zuul-build-sshkey
2026-02-13 00:20:00.946129 | controller -> localhost | The key's randomart image is:
2026-02-13 00:20:00.946172 | controller -> localhost | +---[ECDSA 521]---+
2026-02-13 00:20:00.946214 | controller -> localhost | |o+o .o   oo      |
2026-02-13 00:20:00.946255 | controller -> localhost | | o * +o+...      |
2026-02-13 00:20:00.946325 | controller -> localhost | |  E X *o   .     |
2026-02-13 00:20:00.946366 | controller -> localhost | |   . o .. .      |
2026-02-13 00:20:00.946406 | controller -> localhost | |   . . oS.       |
2026-02-13 00:20:00.946444 | controller -> localhost | |  . o =.+ .      |
2026-02-13 00:20:00.946483 | controller -> localhost | |   + B.B .       |
2026-02-13 00:20:00.946523 | controller -> localhost | |   .=.*.*        |
2026-02-13 00:20:00.946562 | controller -> localhost | |  .o=+o=oo       |
2026-02-13 00:20:00.946600 | controller -> localhost | +----[SHA256]-----+
2026-02-13 00:20:00.946690 | controller -> localhost | ok: Runtime: 0:00:00.008553
2026-02-13 00:20:00.964867 | 
2026-02-13 00:20:00.965126 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-13 00:20:00.991629 | controller | ok
2026-02-13 00:20:01.004451 | controller | included: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-13 00:20:01.020453 | 
2026-02-13 00:20:01.020555 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-13 00:20:01.045898 | controller | skipping: Conditional result was False
2026-02-13 00:20:01.053124 | 
2026-02-13 00:20:01.053201 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-13 00:20:01.326822 | controller | changed
2026-02-13 00:20:01.341349 | 
2026-02-13 00:20:01.341510 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-13 00:20:01.570285 | controller | ok
2026-02-13 00:20:01.579614 | 
2026-02-13 00:20:01.579718 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-13 00:20:02.206965 | controller | changed
2026-02-13 00:20:02.227464 | 
2026-02-13 00:20:02.227744 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-13 00:20:02.908672 | controller | changed
2026-02-13 00:20:02.926290 | 
2026-02-13 00:20:02.926498 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-13 00:20:02.955201 | controller | skipping: Conditional result was False
2026-02-13 00:20:03.014257 | 
2026-02-13 00:20:03.014411 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-13 00:20:03.305408 | controller -> localhost | changed
2026-02-13 00:20:03.333768 | 
2026-02-13 00:20:03.333975 | TASK [add-build-sshkey : Add back temp key]
2026-02-13 00:20:03.669708 | controller -> localhost | Identity added: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/e80101339b5a4d689198f924d248732a_id_ecdsa (zuul-build-sshkey)
2026-02-13 00:20:03.670239 | controller -> localhost | ok: Runtime: 0:00:00.013457
2026-02-13 00:20:03.685366 | 
2026-02-13 00:20:03.685557 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-13 00:20:03.922534 | controller | ok
2026-02-13 00:20:03.938454 | 
2026-02-13 00:20:03.938854 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-13 00:20:03.985971 | controller | skipping: Conditional result was False
2026-02-13 00:20:04.002048 | 
2026-02-13 00:20:04.002140 | TASK [include_role : remove-zuul-sshkey]
2026-02-13 00:20:04.027574 | controller | skipping: Conditional result was False
2026-02-13 00:20:04.037126 | 
2026-02-13 00:20:04.037221 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-13 00:20:04.287755 | controller | ok: "logs"
2026-02-13 00:20:04.288678 | controller | ok: All items complete
2026-02-13 00:20:04.288732 | 
2026-02-13 00:20:04.525081 | controller | ok: "artifacts"
2026-02-13 00:20:04.733954 | controller | ok: "docs"
2026-02-13 00:20:04.745913 | 
2026-02-13 00:20:04.746059 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-13 00:20:05.012723 | controller | changed: "logs"
2026-02-13 00:20:05.221530 | controller | changed: "artifacts"
2026-02-13 00:20:05.439416 | controller | changed: "docs"
2026-02-13 00:20:05.495703 | 
2026-02-13 00:20:05.495835 | PLAY RECAP
2026-02-13 00:20:05.495896 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-13 00:20:05.495930 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-13 00:20:05.495955 | 
2026-02-13 00:20:05.626254 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-13 00:20:05.628506 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-13 00:20:06.256517 | 
2026-02-13 00:20:06.256674 | PLAY [all]
2026-02-13 00:20:06.282305 | 
2026-02-13 00:20:06.282456 | TASK [Install binary dependencies]
2026-02-13 00:20:06.333398 | controller | ok
2026-02-13 00:20:06.357054 | 
2026-02-13 00:20:06.357188 | TASK [bindep : Include find tasks]
2026-02-13 00:20:06.397255 | controller | ok
2026-02-13 00:20:06.405800 | controller | included: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-13 00:20:06.412496 | 
2026-02-13 00:20:06.412571 | TASK [bindep : Look for bindep.txt]
2026-02-13 00:20:06.780502 | controller | ok
2026-02-13 00:20:06.788859 | 
2026-02-13 00:20:06.788976 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:20:06.815230 | controller | skipping: Conditional result was False
2026-02-13 00:20:06.832059 | 
2026-02-13 00:20:06.832302 | TASK [bindep : Look for other-requirements.txt]
2026-02-13 00:20:07.056041 | controller | ok
2026-02-13 00:20:07.069763 | 
2026-02-13 00:20:07.069932 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:20:07.108447 | controller | skipping: Conditional result was False
2026-02-13 00:20:07.124138 | 
2026-02-13 00:20:07.124325 | TASK [bindep : Look for bindep fallback file]
2026-02-13 00:20:07.163230 | controller | skipping: Conditional result was False
2026-02-13 00:20:07.175994 | 
2026-02-13 00:20:07.176195 | TASK [bindep : Define bindep_file fact]
2026-02-13 00:20:07.204650 | controller | skipping: Conditional result was False
2026-02-13 00:20:07.216596 | 
2026-02-13 00:20:07.216794 | TASK [bindep : Include bindep tasks]
2026-02-13 00:20:07.244416 | controller | skipping: Conditional result was False
2026-02-13 00:20:07.252266 | 
2026-02-13 00:20:07.252390 | TASK [bindep : Include install tasks]
2026-02-13 00:20:07.277439 | controller | skipping: Conditional result was False
2026-02-13 00:20:07.287370 | 
2026-02-13 00:20:07.287489 | LOOP [bindep : Include package tasks]
2026-02-13 00:20:07.358956 | 
2026-02-13 00:20:07.359347 | TASK [Run test-setup role]
2026-02-13 00:20:07.383902 | controller | ok
2026-02-13 00:20:07.408868 | 
2026-02-13 00:20:07.409004 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-13 00:20:07.632261 | controller | ok
2026-02-13 00:20:07.646946 | 
2026-02-13 00:20:07.647199 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-13 00:20:08.199221 | controller | skipping: Conditional result was False
2026-02-13 00:20:08.235156 | 
2026-02-13 00:20:08.235257 | PLAY RECAP
2026-02-13 00:20:08.235315 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-13 00:20:08.235344 | 
2026-02-13 00:20:08.351902 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-13 00:20:08.352849 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-13 00:20:08.977133 | 
2026-02-13 00:20:08.977285 | PLAY [controller]
2026-02-13 00:20:08.998576 | 
2026-02-13 00:20:08.998715 | TASK [Create the /root directory]
2026-02-13 00:20:09.587099 | controller | ok
2026-02-13 00:20:09.600782 | 
2026-02-13 00:20:09.600956 | TASK [Install glibc-langpack-en]
2026-02-13 00:20:13.452913 | controller | ok: Nothing to do
2026-02-13 00:20:13.467221 | 
2026-02-13 00:20:13.467381 | TASK [Ensure controller directory exists]
2026-02-13 00:20:13.697539 | controller | changed
2026-02-13 00:20:13.707170 | 
2026-02-13 00:20:13.707289 | TASK [Install container runtime]
2026-02-13 00:20:13.782331 | controller | ok
2026-02-13 00:20:13.833838 | 
2026-02-13 00:20:13.833959 | LOOP [ensure-podman : Find distribution installation]
2026-02-13 00:20:13.860595 | controller | ok: "/var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-13 00:20:13.879749 | controller | included: /var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-13 00:20:13.891081 | 
2026-02-13 00:20:13.891246 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-13 00:21:19.100305 | controller | changed
2026-02-13 00:21:19.109093 | 
2026-02-13 00:21:19.109201 | TASK [ensure-podman : Fetch podman version]
2026-02-13 00:21:19.635043 | controller | Client:       Podman Engine
2026-02-13 00:21:19.664454 | controller | Version:      4.6.2
2026-02-13 00:21:19.664496 | controller | API Version:  4.6.2
2026-02-13 00:21:19.664509 | controller | Go Version:   go1.19.12
2026-02-13 00:21:19.664532 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-13 00:21:19.664545 | controller | OS/Arch:      linux/amd64
2026-02-13 00:21:20.153515 | controller | ok: Runtime: 0:00:00.174934
2026-02-13 00:21:20.170257 | 
2026-02-13 00:21:20.170454 | TASK [ensure-podman : Print podman version installed]
2026-02-13 00:21:20.211690 | Podman version: Client:       Podman Engine
2026-02-13 00:21:20.211971 | Version:      4.6.2
2026-02-13 00:21:20.212071 | API Version:  4.6.2
2026-02-13 00:21:20.212120 | Go Version:   go1.19.12
2026-02-13 00:21:20.212161 | Built:        Mon Aug 28 19:38:31 2023
2026-02-13 00:21:20.212205 | OS/Arch:      linux/amd64
2026-02-13 00:21:20.225263 | 
2026-02-13 00:21:20.225395 | TASK [ensure-podman : Validate podman engine]
2026-02-13 00:21:20.770853 | controller | skipping: Conditional result was False
2026-02-13 00:21:20.784453 | 
2026-02-13 00:21:20.784615 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-13 00:21:20.801766 | controller | skipping: Conditional result was False
2026-02-13 00:21:20.829552 | 
2026-02-13 00:21:20.829671 | TASK [Ensure python3.8 is present]
2026-02-13 00:21:20.846009 | controller | skipping: Conditional result was False
2026-02-13 00:21:20.857410 | 
2026-02-13 00:21:20.857530 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-13 00:21:20.882714 | controller | ok
2026-02-13 00:21:20.915212 | 
2026-02-13 00:21:20.915319 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-13 00:21:22.426373 | controller | ok: Nothing to do
2026-02-13 00:21:22.434391 | 
2026-02-13 00:21:22.434468 | TASK [our-ensure-python : Also install python3-devel]
2026-02-13 00:21:35.115245 | controller | changed
2026-02-13 00:21:35.131619 | 
2026-02-13 00:21:35.131737 | TASK [Run ensure-virtualenv role]
2026-02-13 00:21:35.165791 | controller | ok
2026-02-13 00:21:35.196626 | 
2026-02-13 00:21:35.196790 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-13 00:21:35.462400 | controller | /usr/bin/virtualenv
2026-02-13 00:21:35.729848 | controller | ok: Runtime: 0:00:00.004780
2026-02-13 00:21:35.742715 | 
2026-02-13 00:21:35.742848 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-13 00:21:35.779913 | controller | skipping: Conditional result was False
2026-02-13 00:21:35.780637 | controller | ok: All items complete
2026-02-13 00:21:35.780713 | 
2026-02-13 00:21:35.803906 | 
2026-02-13 00:21:35.804072 | TASK [Find the full path of the Python interpreter]
2026-02-13 00:21:36.018531 | controller | /usr/bin/python3
2026-02-13 00:21:36.337799 | controller | ok
2026-02-13 00:21:36.344506 | 
2026-02-13 00:21:36.344584 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-13 00:21:37.300380 | controller | created virtual environment CPython3.11.0.final.0-64 in 528ms
2026-02-13 00:21:37.317275 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-13 00:21:37.317312 | 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-13 00:21:37.317321 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-13 00:21:37.317336 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-13 00:21:37.381075 | controller | changed
2026-02-13 00:21:37.395941 | 
2026-02-13 00:21:37.396146 | TASK [Set selinux package]
2026-02-13 00:21:37.441049 | controller | ok
2026-02-13 00:21:37.453798 | 
2026-02-13 00:21:37.454178 | TASK [Set selinux package (Fedora)]
2026-02-13 00:21:37.515282 | controller | ok
2026-02-13 00:21:37.527699 | 
2026-02-13 00:21:37.527850 | TASK [Install selinux into virtualenv]
2026-02-13 00:22:03.052926 | controller | Collecting selinux-please-lie-to-me
2026-02-13 00:22:39.179706 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-13 00:22:39.487048 | controller | Collecting setuptools<50.0.0
2026-02-13 00:22:39.491520 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-13 00:22:39.545640 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.0 MB/s eta 0:00:00
2026-02-13 00:22:39.623514 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-13 00:22:39.623729 | controller |   Attempting uninstall: setuptools
2026-02-13 00:22:39.626125 | controller |     Found existing installation: setuptools 62.6.0
2026-02-13 00:22:39.685287 | controller |     Uninstalling setuptools-62.6.0:
2026-02-13 00:22:39.693527 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-13 00:22:40.036611 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-13 00:22:52.434415 | controller |
2026-02-13 00:22:52.519557 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-13 00:22:52.519599 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-13 00:22:52.618533 | controller | ok: Runtime: 0:01:14.758025
2026-02-13 00:22:52.630928 | 
2026-02-13 00:22:52.631157 | TASK [Install pytest-forked into virtualenv]
2026-02-13 00:23:29.435346 | controller | Collecting pytest-forked
2026-02-13 00:23:41.757732 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-13 00:23:41.799017 | controller | Collecting py
2026-02-13 00:23:41.866084 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-13 00:23:41.882500 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.5 MB/s eta 0:00:00
2026-02-13 00:23:41.991802 | controller | Collecting pytest>=3.10
2026-02-13 00:23:41.997696 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-13 00:23:42.012801 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 31.4 MB/s eta 0:00:00
2026-02-13 00:23:42.054592 | controller | Collecting iniconfig>=1.0.1
2026-02-13 00:23:42.058745 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-13 00:23:42.104339 | controller | Collecting packaging>=22
2026-02-13 00:23:42.107517 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-13 00:23:42.113425 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 20.5 MB/s eta 0:00:00
2026-02-13 00:23:42.142540 | controller | Collecting pluggy<2,>=1.5
2026-02-13 00:23:42.155750 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-13 00:23:42.242841 | controller | Collecting pygments>=2.7.2
2026-02-13 00:23:42.312183 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-13 00:23:42.332325 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 69.9 MB/s eta 0:00:00
2026-02-13 00:23:42.395992 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-13 00:23:43.391708 | 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-13 00:23:43.400013 | controller |
2026-02-13 00:23:43.464411 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-13 00:23:43.464447 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-13 00:23:43.706398 | controller | ok: Runtime: 0:00:50.606043
2026-02-13 00:23:43.717408 | 
2026-02-13 00:23:43.717560 | TASK [Update pip]
2026-02-13 00:23:44.215202 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-13 00:23:54.140967 | controller | Collecting pip
2026-02-13 00:24:06.338053 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-13 00:24:06.434297 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 19.5 MB/s eta 0:00:00
2026-02-13 00:24:06.497955 | controller | Installing collected packages: pip
2026-02-13 00:24:06.498111 | controller |   Attempting uninstall: pip
2026-02-13 00:24:06.500343 | controller |     Found existing installation: pip 22.2.2
2026-02-13 00:24:06.637002 | controller |     Uninstalling pip-22.2.2:
2026-02-13 00:24:06.651785 | controller |       Successfully uninstalled pip-22.2.2
2026-02-13 00:24:07.448623 | controller | Successfully installed pip-26.0.1
2026-02-13 00:24:07.774511 | controller | ok: Runtime: 0:00:23.593251
2026-02-13 00:24:07.783778 | 
2026-02-13 00:24:07.783932 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-13 00:24:08.007652 | controller | changed
2026-02-13 00:24:08.021111 | 
2026-02-13 00:24:08.021269 | TASK [Install ansible into virtualenv]
2026-02-13 00:24:08.529233 | controller | Processing ./src/github.com/ansible/ansible
2026-02-13 00:24:08.531726 | controller |   Installing build dependencies: started
2026-02-13 00:24:55.405536 | controller |   Installing build dependencies: finished with status 'done'
2026-02-13 00:24:55.406202 | controller |   Getting requirements to build wheel: started
2026-02-13 00:24:56.138192 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-13 00:24:56.139126 | controller |   Preparing metadata (pyproject.toml): started
2026-02-13 00:24:56.601970 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-13 00:24:56.604234 | 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-13 00:24:56.606680 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-13 00:24:57.101972 | controller | ERROR
2026-02-13 00:24:57.102278 | controller | {
2026-02-13 00:24:57.102315 | controller |   "delta": "0:00:48.415442",
2026-02-13 00:24:57.102336 | controller |   "end": "2026-02-13 00:24:56.666838",
2026-02-13 00:24:57.102354 | controller |   "msg": "non-zero return code",
2026-02-13 00:24:57.102388 | controller |   "rc": 1,
2026-02-13 00:24:57.102429 | controller |   "start": "2026-02-13 00:24:08.251396"
2026-02-13 00:24:57.102460 | controller | }
failure
2026-02-13 00:24:57.104339 | 
2026-02-13 00:24:57.104399 | PLAY RECAP
2026-02-13 00:24:57.104467 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-13 00:24:57.104490 | 
2026-02-13 00:24:57.282004 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-13 00:24:57.283891 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-13 00:24:57.941437 | 
2026-02-13 00:24:57.941597 | PLAY [all]
2026-02-13 00:24:57.963384 | 
2026-02-13 00:24:57.963518 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-13 00:24:58.269794 | controller | changed: non-zero return code
2026-02-13 00:24:58.283814 | 
2026-02-13 00:24:58.283985 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-13 00:24:58.313106 | controller | skipping: Conditional result was False
2026-02-13 00:24:58.326925 | 
2026-02-13 00:24:58.327127 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-13 00:24:58.371462 | 
2026-02-13 00:24:58.371774 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-13 00:24:58.414888 | 
2026-02-13 00:24:58.415190 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-13 00:24:58.443997 | controller | skipping: Conditional result was False
2026-02-13 00:24:58.460232 | 
2026-02-13 00:24:58.460380 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-13 00:24:58.501619 | 
2026-02-13 00:24:58.501900 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-13 00:24:58.532412 | controller | skipping: Conditional result was False
2026-02-13 00:24:58.552562 | 
2026-02-13 00:24:58.552819 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-13 00:24:58.584716 | controller | skipping: Conditional result was False
2026-02-13 00:24:58.597703 | 
2026-02-13 00:24:58.597857 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-13 00:24:58.636809 | controller | skipping: Conditional result was False
2026-02-13 00:24:58.693298 | 
2026-02-13 00:24:58.693537 | PLAY RECAP
2026-02-13 00:24:58.693624 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-13 00:24:58.693663 | 
2026-02-13 00:24:58.910791 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-13 00:24:58.911807 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-13 00:24:59.548376 | 
2026-02-13 00:24:59.548587 | PLAY [all:!appliance*]
2026-02-13 00:24:59.571909 | 
2026-02-13 00:24:59.572107 | TASK [unregister the node]
2026-02-13 00:25:00.106632 | controller | skipping: Conditional result was False
2026-02-13 00:25:00.113854 | 
2026-02-13 00:25:00.113989 | TASK [include_role : fetch-output]
2026-02-13 00:25:00.162188 | controller | ok
2026-02-13 00:25:00.200046 | 
2026-02-13 00:25:00.200233 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-13 00:25:00.278823 | controller | skipping: Conditional result was False
2026-02-13 00:25:00.288473 | 
2026-02-13 00:25:00.288616 | TASK [fetch-output : Set log path for single node]
2026-02-13 00:25:00.334357 | controller | ok
2026-02-13 00:25:00.341511 | 
2026-02-13 00:25:00.341707 | LOOP [fetch-output : Ensure local output dirs]
2026-02-13 00:25:00.834724 | controller -> localhost | ok: "/var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/logs"
2026-02-13 00:25:01.081335 | controller -> localhost | changed: "/var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/artifacts"
2026-02-13 00:25:01.303769 | controller -> localhost | changed: "/var/lib/zuul/builds/e80101339b5a4d689198f924d248732a/work/docs"
2026-02-13 00:25:01.329816 | 
2026-02-13 00:25:01.330048 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-13 00:25:02.123986 | controller | changed:
2026-02-13 00:25:02.124696 | controller | .d..t...... ./
2026-02-13 00:25:02.124791 | controller | cd+++++++++ controller/
2026-02-13 00:25:02.124898 | controller | changed: All items complete
2026-02-13 00:25:02.124956 | 
2026-02-13 00:25:02.609263 | controller | changed: .d..t...... ./
2026-02-13 00:25:03.133538 | controller | changed: .d..t...... ./
2026-02-13 00:25:03.158755 | 
2026-02-13 00:25:03.158971 | TASK [include_role : fetch-output-openshift]
2026-02-13 00:25:03.188304 | controller | skipping: Conditional result was False
2026-02-13 00:25:03.203975 | 
2026-02-13 00:25:03.204242 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-13 00:25:03.238135 | controller | skipping: Conditional result was False
2026-02-13 00:25:03.249355 | controller | skipping: Conditional result was False
2026-02-13 00:25:03.310869 | 
2026-02-13 00:25:03.311156 | PLAY [localhost]
2026-02-13 00:25:03.329779 | 
2026-02-13 00:25:03.329963 | TASK [Run Zuul manifest role]
2026-02-13 00:25:03.353131 | localhost | ok
2026-02-13 00:25:03.370169 | 
2026-02-13 00:25:03.370321 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-13 00:25:03.767794 | localhost | changed
2026-02-13 00:25:03.778866 | 
2026-02-13 00:25:03.779008 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-13 00:25:03.825693 | localhost | ok
2026-02-13 00:25:03.844558 | 
2026-02-13 00:25:03.844689 | TASK [Set zuul-log-path fact]
2026-02-13 00:25:03.871521 | localhost | ok
2026-02-13 00:25:03.899347 | 
2026-02-13 00:25:03.899455 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-13 00:25:03.940911 | localhost | ok
2026-02-13 00:25:03.949279 | 
2026-02-13 00:25:03.949337 | LOOP [Run upload-logs-swift role]
2026-02-13 00:25:03.997393 | localhost | Output suppressed because no_log was given
2026-02-13 00:25:04.055709 | 
2026-02-13 00:25:04.055960 | TASK [Set zuul-log-path fact]
2026-02-13 00:25:04.104522 | localhost | skipping: Conditional result was False
2026-02-13 00:25:04.115513 | 
2026-02-13 00:25:04.115654 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-13 00:25:04.633654 | localhost -> localhost | ok: Runtime: 0:00:00.010763
2026-02-13 00:25:04.707229 | 
2026-02-13 00:25:04.707416 | TASK [upload-logs-swift : Upload logs to swift]