2025-09-23 00:06:33.144398 | Job console starting...
2025-09-23 00:06:33.153972 | Updating repositories
2025-09-23 00:06:35.688547 | Preparing job workspace
2025-09-23 00:06:39.462016 | Running Ansible setup...
2025-09-23 00:06:45.724504 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-09-23 00:06:46.358160 | 
2025-09-23 00:06:46.358281 | PLAY [localhost]
2025-09-23 00:06:46.366642 | 
2025-09-23 00:06:46.366744 | TASK [Gathering Facts]
2025-09-23 00:06:47.391425 | localhost | ok
2025-09-23 00:06:47.426274 | 
2025-09-23 00:06:47.426495 | TASK [Setup log path fact]
2025-09-23 00:06:47.450231 | localhost | ok
2025-09-23 00:06:47.469107 | 
2025-09-23 00:06:47.469298 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-23 00:06:47.509968 | localhost | ok
2025-09-23 00:06:47.521957 | 
2025-09-23 00:06:47.522115 | TASK [emit-job-header : Print job information]
2025-09-23 00:06:47.573954 | # Job Information
2025-09-23 00:06:47.574136 | Ansible Version: 2.15.12
2025-09-23 00:06:47.574181 | Job: ansible-test-sanity-docker-stable-2.10
2025-09-23 00:06:47.574212 | Pipeline: periodic
2025-09-23 00:06:47.574237 | Executor: ze03.softwarefactory-project.io
2025-09-23 00:06:47.574265 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-09-23 00:06:47.574304 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/f11/ansible/f113ce09efd64dcabc054f91d65acbab/
2025-09-23 00:06:47.574337 | Event ID: ce90a15208884c3e9ebd24fbd880974e
2025-09-23 00:06:47.581813 | 
2025-09-23 00:06:47.581918 | LOOP [emit-job-header : Print node information]
2025-09-23 00:06:47.730696 | localhost | ok:
2025-09-23 00:06:47.730984 | localhost | # Node Information
2025-09-23 00:06:47.731025 | localhost | Inventory Hostname: controller
2025-09-23 00:06:47.731054 | localhost | Hostname: np0005446002
2025-09-23 00:06:47.731081 | localhost | Username: zuul
2025-09-23 00:06:47.731113 | localhost | Distro: Fedora 37
2025-09-23 00:06:47.731140 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-09-23 00:06:47.731173 | localhost | Region: ca-ymq-1
2025-09-23 00:06:47.731211 | localhost | Label: ansible-fedora-37-1vcpu
2025-09-23 00:06:47.731244 | localhost | Product Name: OpenStack Nova
2025-09-23 00:06:47.731269 | localhost | Interface IP: 162.253.55.221
2025-09-23 00:06:47.744449 | 
2025-09-23 00:06:47.744578 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-09-23 00:06:48.145036 | localhost -> localhost | changed
2025-09-23 00:06:48.159698 | 
2025-09-23 00:06:48.159939 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-09-23 00:06:49.072788 | localhost -> localhost | changed
2025-09-23 00:06:49.097540 | 
2025-09-23 00:06:49.097663 | PLAY [all:!appliance*]
2025-09-23 00:06:49.119001 | 
2025-09-23 00:06:49.119140 | TASK [include_role : start-zuul-console]
2025-09-23 00:06:49.152968 | controller | ok
2025-09-23 00:06:49.174379 | 
2025-09-23 00:06:49.174513 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-09-23 00:06:49.573391 | controller | ok
2025-09-23 00:06:49.590141 | 
2025-09-23 00:06:49.590268 | TASK [use-our-mirror : Retrieve the IP address]
2025-09-23 00:06:51.053807 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-09-23 00:06:51.068617 | 
2025-09-23 00:06:51.068752 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-09-23 00:06:51.598909 | controller | skipping: Conditional result was False
2025-09-23 00:06:51.612881 | 
2025-09-23 00:06:51.613028 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-09-23 00:06:51.639892 | controller | skipping: Conditional result was False
2025-09-23 00:06:51.654373 | 
2025-09-23 00:06:51.654535 | TASK [use-our-mirror : Create the podman configuration directory]
2025-09-23 00:06:51.671447 | controller | skipping: Conditional result was False
2025-09-23 00:06:51.683836 | 
2025-09-23 00:06:51.683975 | TASK [use-our-mirror : Copy the podman configuration]
2025-09-23 00:06:51.718664 | controller | skipping: Conditional result was False
2025-09-23 00:06:51.725091 | 
2025-09-23 00:06:51.725180 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-09-23 00:06:51.749788 | controller | skipping: Conditional result was False
2025-09-23 00:06:51.757814 | 
2025-09-23 00:06:51.758068 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-09-23 00:06:51.782121 | controller | skipping: Conditional result was False
2025-09-23 00:06:51.794890 | 
2025-09-23 00:06:51.795015 | TASK [Disable Fedora Modular]
2025-09-23 00:06:52.046780 | controller | changed
2025-09-23 00:06:52.062022 | 
2025-09-23 00:06:52.062203 | TASK [Enable EPEL]
2025-09-23 00:06:52.090045 | controller | skipping: Conditional result was False
2025-09-23 00:06:52.108260 | 
2025-09-23 00:06:52.108442 | TASK [Register the RHEL node]
2025-09-23 00:06:52.668501 | 
2025-09-23 00:06:52.668627 | TASK [Show the subscription-manager status]
2025-09-23 00:06:53.243602 | controller | skipping: Conditional result was False
2025-09-23 00:06:53.250406 | 
2025-09-23 00:06:53.250475 | TASK [Enable EPEL on RHEL]
2025-09-23 00:06:53.789864 | controller | skipping: Conditional result was False
2025-09-23 00:06:53.799646 | 
2025-09-23 00:06:53.799882 | TASK [Install git and tox]
2025-09-23 00:08:31.758169 | controller | changed
2025-09-23 00:08:31.769286 | 
2025-09-23 00:08:31.769418 | TASK [include_role : prepare-workspace]
2025-09-23 00:08:31.807247 | controller | ok
2025-09-23 00:08:31.840842 | 
2025-09-23 00:08:31.840970 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-09-23 00:08:32.087786 | controller | ok
2025-09-23 00:08:32.100035 | 
2025-09-23 00:08:32.100176 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-09-23 00:08:44.716694 | controller | Output suppressed because no_log was given
2025-09-23 00:08:44.733590 | 
2025-09-23 00:08:44.733710 | TASK [include_role : prepare-workspace-openshift]
2025-09-23 00:08:44.749237 | controller | skipping: Conditional result was False
2025-09-23 00:08:44.785671 | 
2025-09-23 00:08:44.785769 | PLAY [all:!appliance]
2025-09-23 00:08:44.839502 | 
2025-09-23 00:08:44.839627 | TASK [Run add-build-sshkey role (RSA)]
2025-09-23 00:08:44.870375 | controller | ok
2025-09-23 00:08:44.886841 | 
2025-09-23 00:08:44.886948 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-23 00:08:45.125220 | controller -> localhost | ok
2025-09-23 00:08:45.132490 | 
2025-09-23 00:08:45.132656 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-23 00:08:45.154324 | controller | ok
2025-09-23 00:08:45.171443 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-23 00:08:45.178554 | 
2025-09-23 00:08:45.178626 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-23 00:08:45.641575 | controller -> localhost | Generating public/private rsa key pair.
2025-09-23 00:08:45.641768 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/f113ce09efd64dcabc054f91d65acbab_id_rsa.
2025-09-23 00:08:45.641801 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/f113ce09efd64dcabc054f91d65acbab_id_rsa.pub.
2025-09-23 00:08:45.641823 | controller -> localhost | The key fingerprint is:
2025-09-23 00:08:45.641841 | controller -> localhost | SHA256:vnu3GoT9Fo9sDf1oVAQzyrwmiJoH5NfFluCYZCgbRz4 zuul-build-sshkey
2025-09-23 00:08:45.641860 | controller -> localhost | The key's randomart image is:
2025-09-23 00:08:45.641878 | controller -> localhost | +---[RSA 2048]----+
2025-09-23 00:08:45.641895 | controller -> localhost | |   ...o .     +..|
2025-09-23 00:08:45.641913 | controller -> localhost | |  o.oo + o + . + |
2025-09-23 00:08:45.641931 | controller -> localhost | |   =E o . = +   .|
2025-09-23 00:08:45.641948 | controller -> localhost | |  .o . o *   o . |
2025-09-23 00:08:45.641966 | controller -> localhost | |    o o S + = o  |
2025-09-23 00:08:45.641994 | controller -> localhost | |     = . . = B o |
2025-09-23 00:08:45.642018 | controller -> localhost | |    o . . . * = .|
2025-09-23 00:08:45.642039 | controller -> localhost | |     .   ..+..   |
2025-09-23 00:08:45.642073 | controller -> localhost | |        oo.o..   |
2025-09-23 00:08:45.642094 | controller -> localhost | +----[SHA256]-----+
2025-09-23 00:08:45.642139 | controller -> localhost | ok: Runtime: 0:00:00.124624
2025-09-23 00:08:45.649216 | 
2025-09-23 00:08:45.649287 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-23 00:08:45.669691 | controller | ok
2025-09-23 00:08:45.679878 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-23 00:08:45.690066 | 
2025-09-23 00:08:45.690139 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-23 00:08:45.704875 | controller | skipping: Conditional result was False
2025-09-23 00:08:45.716772 | 
2025-09-23 00:08:45.716941 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-23 00:08:46.184996 | controller | changed
2025-09-23 00:08:46.200951 | 
2025-09-23 00:08:46.201126 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-23 00:08:46.424547 | controller | ok
2025-09-23 00:08:46.435911 | 
2025-09-23 00:08:46.436056 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-23 00:08:47.050067 | controller | changed
2025-09-23 00:08:47.057932 | 
2025-09-23 00:08:47.058090 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-23 00:08:47.682502 | controller | changed
2025-09-23 00:08:47.695075 | 
2025-09-23 00:08:47.695195 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-23 00:08:47.709952 | controller | skipping: Conditional result was False
2025-09-23 00:08:47.719267 | 
2025-09-23 00:08:47.719527 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-23 00:08:48.076458 | controller -> localhost | changed
2025-09-23 00:08:48.089003 | 
2025-09-23 00:08:48.089124 | TASK [add-build-sshkey : Add back temp key]
2025-09-23 00:08:48.347323 | controller -> localhost | Identity added: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/f113ce09efd64dcabc054f91d65acbab_id_rsa (zuul-build-sshkey)
2025-09-23 00:08:48.347567 | controller -> localhost | ok: Runtime: 0:00:00.014927
2025-09-23 00:08:48.354071 | 
2025-09-23 00:08:48.354175 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-23 00:08:48.730236 | controller | ok
2025-09-23 00:08:48.743747 | 
2025-09-23 00:08:48.743900 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-23 00:08:48.781101 | controller | skipping: Conditional result was False
2025-09-23 00:08:48.809159 | 
2025-09-23 00:08:48.809333 | TASK [Run add-build-sshkey role (ECDSA)]
2025-09-23 00:08:48.844620 | controller | ok
2025-09-23 00:08:48.868560 | 
2025-09-23 00:08:48.868686 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-23 00:08:49.150658 | controller -> localhost | ok
2025-09-23 00:08:49.158593 | 
2025-09-23 00:08:49.158665 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-23 00:08:49.177332 | controller | ok
2025-09-23 00:08:49.188001 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-23 00:08:49.194179 | 
2025-09-23 00:08:49.194248 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-23 00:08:49.452028 | controller -> localhost | Generating public/private ecdsa key pair.
2025-09-23 00:08:49.452257 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/f113ce09efd64dcabc054f91d65acbab_id_ecdsa.
2025-09-23 00:08:49.452301 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/f113ce09efd64dcabc054f91d65acbab_id_ecdsa.pub.
2025-09-23 00:08:49.452344 | controller -> localhost | The key fingerprint is:
2025-09-23 00:08:49.452376 | controller -> localhost | SHA256:MmKBoikvlc/Bf0x95wvIc074C62e2JX227tEorRK+5U zuul-build-sshkey
2025-09-23 00:08:49.452404 | controller -> localhost | The key's randomart image is:
2025-09-23 00:08:49.452428 | controller -> localhost | +---[ECDSA 521]---+
2025-09-23 00:08:49.452452 | controller -> localhost | |                 |
2025-09-23 00:08:49.452479 | controller -> localhost | |   .             |
2025-09-23 00:08:49.452505 | controller -> localhost | |. . .            |
2025-09-23 00:08:49.452530 | controller -> localhost | |.o o .   .       |
2025-09-23 00:08:49.452557 | controller -> localhost | |+ o = o S ...... |
2025-09-23 00:08:49.452583 | controller -> localhost | |.o + + = ..=o++  |
2025-09-23 00:08:49.452609 | controller -> localhost | |. . o . o.*oOE.. |
2025-09-23 00:08:49.452633 | controller -> localhost | | .     ..oo%.o.o |
2025-09-23 00:08:49.452658 | controller -> localhost | |        .+*.+.+++|
2025-09-23 00:08:49.452684 | controller -> localhost | +----[SHA256]-----+
2025-09-23 00:08:49.452764 | controller -> localhost | ok: Runtime: 0:00:00.008301
2025-09-23 00:08:49.461319 | 
2025-09-23 00:08:49.461424 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-23 00:08:49.491298 | controller | ok
2025-09-23 00:08:49.498950 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-23 00:08:49.508075 | 
2025-09-23 00:08:49.508149 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-23 00:08:49.522157 | controller | skipping: Conditional result was False
2025-09-23 00:08:49.528835 | 
2025-09-23 00:08:49.528905 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-23 00:08:49.794973 | controller | changed
2025-09-23 00:08:49.810907 | 
2025-09-23 00:08:49.811085 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-23 00:08:50.060329 | controller | ok
2025-09-23 00:08:50.067492 | 
2025-09-23 00:08:50.067602 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-23 00:08:50.709766 | controller | changed
2025-09-23 00:08:50.728363 | 
2025-09-23 00:08:50.728577 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-23 00:08:51.403394 | controller | changed
2025-09-23 00:08:51.419843 | 
2025-09-23 00:08:51.420087 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-23 00:08:51.459552 | controller | skipping: Conditional result was False
2025-09-23 00:08:51.473935 | 
2025-09-23 00:08:51.474177 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-23 00:08:51.731964 | controller -> localhost | changed
2025-09-23 00:08:51.744821 | 
2025-09-23 00:08:51.744943 | TASK [add-build-sshkey : Add back temp key]
2025-09-23 00:08:52.033843 | controller -> localhost | Identity added: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/f113ce09efd64dcabc054f91d65acbab_id_ecdsa (zuul-build-sshkey)
2025-09-23 00:08:52.034041 | controller -> localhost | ok: Runtime: 0:00:00.013217
2025-09-23 00:08:52.040412 | 
2025-09-23 00:08:52.040479 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-23 00:08:52.253606 | controller | ok
2025-09-23 00:08:52.259031 | 
2025-09-23 00:08:52.259099 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-23 00:08:52.293569 | controller | skipping: Conditional result was False
2025-09-23 00:08:52.319337 | 
2025-09-23 00:08:52.319516 | TASK [include_role : remove-zuul-sshkey]
2025-09-23 00:08:52.334142 | controller | skipping: Conditional result was False
2025-09-23 00:08:52.376653 | 
2025-09-23 00:08:52.376826 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-23 00:08:52.615267 | controller | ok: "logs"
2025-09-23 00:08:52.615836 | controller | ok: All items complete
2025-09-23 00:08:52.615905 | 
2025-09-23 00:08:52.803637 | controller | ok: "artifacts"
2025-09-23 00:08:53.008871 | controller | ok: "docs"
2025-09-23 00:08:53.026549 | 
2025-09-23 00:08:53.026798 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-23 00:08:53.272433 | controller | changed: "logs"
2025-09-23 00:08:53.479113 | controller | changed: "artifacts"
2025-09-23 00:08:53.690173 | controller | changed: "docs"
2025-09-23 00:08:53.735044 | 
2025-09-23 00:08:53.735168 | PLAY RECAP
2025-09-23 00:08:53.735228 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-09-23 00:08:53.735266 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-23 00:08:53.735292 | 
2025-09-23 00:08:53.870332 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-09-23 00:08:53.871986 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-09-23 00:08:54.490198 | 
2025-09-23 00:08:54.490309 | PLAY [all]
2025-09-23 00:08:54.513323 | 
2025-09-23 00:08:54.513475 | TASK [Install binary dependencies]
2025-09-23 00:08:54.583976 | controller | ok
2025-09-23 00:08:54.603816 | 
2025-09-23 00:08:54.603967 | TASK [bindep : Include find tasks]
2025-09-23 00:08:54.634938 | controller | ok
2025-09-23 00:08:54.643089 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-09-23 00:08:54.649969 | 
2025-09-23 00:08:54.650045 | TASK [bindep : Look for bindep.txt]
2025-09-23 00:08:54.996670 | controller | ok
2025-09-23 00:08:55.002594 | 
2025-09-23 00:08:55.002669 | TASK [bindep : Define bindep_file fact]
2025-09-23 00:08:55.027277 | controller | skipping: Conditional result was False
2025-09-23 00:08:55.041115 | 
2025-09-23 00:08:55.041269 | TASK [bindep : Look for other-requirements.txt]
2025-09-23 00:08:55.260799 | controller | ok
2025-09-23 00:08:55.271256 | 
2025-09-23 00:08:55.271396 | TASK [bindep : Define bindep_file fact]
2025-09-23 00:08:55.297042 | controller | skipping: Conditional result was False
2025-09-23 00:08:55.307116 | 
2025-09-23 00:08:55.307484 | TASK [bindep : Look for bindep fallback file]
2025-09-23 00:08:55.332896 | controller | skipping: Conditional result was False
2025-09-23 00:08:55.343537 | 
2025-09-23 00:08:55.343668 | TASK [bindep : Define bindep_file fact]
2025-09-23 00:08:55.369395 | controller | skipping: Conditional result was False
2025-09-23 00:08:55.378671 | 
2025-09-23 00:08:55.378812 | TASK [bindep : Include bindep tasks]
2025-09-23 00:08:55.403644 | controller | skipping: Conditional result was False
2025-09-23 00:08:55.413566 | 
2025-09-23 00:08:55.413698 | TASK [bindep : Include install tasks]
2025-09-23 00:08:55.450258 | controller | skipping: Conditional result was False
2025-09-23 00:08:55.460965 | 
2025-09-23 00:08:55.461094 | LOOP [bindep : Include package tasks]
2025-09-23 00:08:55.550102 | 
2025-09-23 00:08:55.550305 | TASK [Run test-setup role]
2025-09-23 00:08:55.574527 | controller | ok
2025-09-23 00:08:55.598555 | 
2025-09-23 00:08:55.598689 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-09-23 00:08:55.826147 | controller | ok
2025-09-23 00:08:55.835060 | 
2025-09-23 00:08:55.835191 | TASK [test-setup : Run tools/test-setup.sh]
2025-09-23 00:08:56.377522 | controller | skipping: Conditional result was False
2025-09-23 00:08:56.434129 | 
2025-09-23 00:08:56.434274 | PLAY RECAP
2025-09-23 00:08:56.434332 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-09-23 00:08:56.434361 | 
2025-09-23 00:08:56.555867 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-09-23 00:08:56.556739 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-09-23 00:08:57.139713 | 
2025-09-23 00:08:57.139857 | PLAY [controller]
2025-09-23 00:08:57.159994 | 
2025-09-23 00:08:57.160084 | TASK [Create the /root directory]
2025-09-23 00:08:57.549301 | controller | ok
2025-09-23 00:08:57.563187 | 
2025-09-23 00:08:57.563380 | TASK [Install glibc-langpack-en]
2025-09-23 00:09:01.512251 | controller | ok: Nothing to do
2025-09-23 00:09:01.525124 | 
2025-09-23 00:09:01.525305 | TASK [Ensure controller directory exists]
2025-09-23 00:09:01.779243 | controller | changed
2025-09-23 00:09:01.787650 | 
2025-09-23 00:09:01.787765 | TASK [Install container runtime]
2025-09-23 00:09:01.840653 | controller | ok
2025-09-23 00:09:01.893673 | 
2025-09-23 00:09:01.893804 | LOOP [ensure-docker : Gather variables for each operating system]
2025-09-23 00:09:01.946407 | controller | ok: "/var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml"
2025-09-23 00:09:01.954153 | 
2025-09-23 00:09:01.954224 | TASK [ensure-docker : Sanity check for distro selection]
2025-09-23 00:09:01.968096 | controller | skipping: Conditional result was False
2025-09-23 00:09:01.974690 | 
2025-09-23 00:09:01.974800 | TASK [ensure-docker : Sanity check for distro install]
2025-09-23 00:09:01.999019 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.005142 | 
2025-09-23 00:09:02.005226 | TASK [ensure-docker : Sanity check for upstream install]
2025-09-23 00:09:02.028959 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.035179 | 
2025-09-23 00:09:02.035252 | TASK [ensure-docker : Sanity check for upstream install mirrors]
2025-09-23 00:09:02.058978 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.065998 | 
2025-09-23 00:09:02.066074 | TASK [ensure-docker : Include tasks for docker install]
2025-09-23 00:09:02.089105 | controller | ok
2025-09-23 00:09:02.101300 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml
2025-09-23 00:09:02.113152 | 
2025-09-23 00:09:02.113249 | TASK [ensure-docker : Not Implemented]
2025-09-23 00:09:02.128289 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.135013 | 
2025-09-23 00:09:02.135085 | TASK [Set up docker mirrors]
2025-09-23 00:09:02.154245 | controller | ok
2025-09-23 00:09:02.175268 | 
2025-09-23 00:09:02.175376 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info]
2025-09-23 00:09:02.199498 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.206026 | 
2025-09-23 00:09:02.206096 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info]
2025-09-23 00:09:02.230735 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.236699 | 
2025-09-23 00:09:02.236802 | TASK [use-docker-mirror : Set docker_mirror fact]
2025-09-23 00:09:02.260743 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.266875 | 
2025-09-23 00:09:02.266943 | TASK [use-docker-mirror : Set up docker mirrors]
2025-09-23 00:09:02.291350 | controller | skipping: Conditional result was False
2025-09-23 00:09:02.309249 | 
2025-09-23 00:09:02.309466 | TASK [Add all repositories]
2025-09-23 00:09:02.333314 | controller | ok
2025-09-23 00:09:02.364873 | 
2025-09-23 00:09:02.364965 | LOOP [ensure-package-repositories : Install repositories]
2025-09-23 00:09:02.396795 | controller | ok: "/var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml"
2025-09-23 00:09:02.396946 | controller | ok: All items complete
2025-09-23 00:09:02.396972 | 
2025-09-23 00:09:02.408248 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml
2025-09-23 00:09:02.442238 | 
2025-09-23 00:09:02.442358 | TASK [ensure-package-repositories : Create GPG key temp directory]
2025-09-23 00:09:02.771657 | controller | changed
2025-09-23 00:09:02.780636 | 
2025-09-23 00:09:02.780775 | LOOP [ensure-package-repositories : Upload GPG keys]
2025-09-23 00:09:03.727247 | controller | changed:
2025-09-23 00:09:03.727751 | controller | {
2025-09-23 00:09:03.727792 | controller |   "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n"
2025-09-23 00:09:03.727817 | controller | }
2025-09-23 00:09:03.743588 | 
2025-09-23 00:09:03.743655 | LOOP [ensure-package-repositories : Import GPG keys]
2025-09-23 00:09:04.373403 | controller | changed:
2025-09-23 00:09:04.373694 | controller | {
2025-09-23 00:09:04.373837 | controller |   "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n"
2025-09-23 00:09:04.373895 | controller | }
2025-09-23 00:09:04.373957 | controller | changed: All items complete
2025-09-23 00:09:04.374000 | 
2025-09-23 00:09:04.400413 | 
2025-09-23 00:09:04.400794 | TASK [ensure-package-repositories : Remove GPG temp directory]
2025-09-23 00:09:04.633906 | controller | changed
2025-09-23 00:09:04.640854 | 
2025-09-23 00:09:04.640928 | LOOP [ensure-package-repositories : Add repositories]
2025-09-23 00:09:04.967771 | controller | changed:
2025-09-23 00:09:04.968357 | controller | {
2025-09-23 00:09:04.968428 | controller |   "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable",
2025-09-23 00:09:04.968481 | controller |   "description": "Docker CE Stable - $basearch",
2025-09-23 00:09:04.968527 | controller |   "gpgcheck": true,
2025-09-23 00:09:04.968597 | controller |   "name": "docker-ce-stable"
2025-09-23 00:09:04.968644 | controller | }
2025-09-23 00:09:04.999209 | 
2025-09-23 00:09:04.999614 | TASK [ensure-docker : Install pre-reqs]
2025-09-23 00:09:07.892174 | controller | ok: Nothing to do
2025-09-23 00:09:07.898342 | 
2025-09-23 00:09:07.898590 | TASK [ensure-docker : Remove packages]
2025-09-23 00:09:09.190466 | controller | ok: Nothing to do
2025-09-23 00:09:09.200143 | 
2025-09-23 00:09:09.200292 | TASK [ensure-docker : Install upstream docker using package]
2025-09-23 00:09:55.984906 | controller | changed
2025-09-23 00:09:55.998397 | 
2025-09-23 00:09:55.998506 | TASK [ensure-docker : Setup docker]
2025-09-23 00:09:56.021412 | controller | ok
2025-09-23 00:09:56.035541 | controller | included: /var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml
2025-09-23 00:09:56.053007 | 
2025-09-23 00:09:56.053150 | TASK [ensure-docker : Ensure "docker" group exists]
2025-09-23 00:09:56.441442 | controller | ok
2025-09-23 00:09:56.447517 | 
2025-09-23 00:09:56.447595 | TASK [ensure-docker : Add user to docker group]
2025-09-23 00:09:56.966184 | controller | changed
2025-09-23 00:09:56.972478 | 
2025-09-23 00:09:56.972562 | TASK [Update docker daemon proxy configuration]
2025-09-23 00:09:56.996505 | controller | skipping: Conditional result was False
2025-09-23 00:09:57.003545 | 
2025-09-23 00:09:57.003642 | TASK [Lower default MTU]
2025-09-23 00:09:57.027350 | controller | skipping: Conditional result was False
2025-09-23 00:09:57.034593 | 
2025-09-23 00:09:57.034692 | TASK [ensure-docker : Get the status of the docket.socket unit]
2025-09-23 00:09:57.428425 | controller | inactive
2025-09-23 00:09:57.603315 | controller | ok: Runtime: 0:00:00.017061
2025-09-23 00:09:57.618116 | 
2025-09-23 00:09:57.618301 | TASK [ensure-docker : Get the status of the docket unit]
2025-09-23 00:09:57.865133 | controller | inactive
2025-09-23 00:09:58.172090 | controller | ok: Runtime: 0:00:00.008675
2025-09-23 00:09:58.181496 | 
2025-09-23 00:09:58.181604 | TASK [ensure-docker : Restart docker]
2025-09-23 00:09:58.231883 | Trigger a Docker restart
2025-09-23 00:09:58.239990 | 
2025-09-23 00:09:58.240097 | TASK [ensure-docker : Reset ssh connection to pick up docker group]
2025-09-23 00:09:58.276225 | 
2025-09-23 00:09:58.276357 | TASK [ensure-docker : Install docker-compose]
2025-09-23 00:09:58.292783 | controller | skipping: Conditional result was False
2025-09-23 00:09:58.303556 | 
2025-09-23 00:09:58.303809 | TASK [ensure-docker : Flush handlers before role exit]
2025-09-23 00:09:58.319674 | 
2025-09-23 00:09:58.319814 | TASK [ensure-docker : Stop docker.socket to avoid any conflict]
2025-09-23 00:09:59.557644 | controller | changed
2025-09-23 00:09:59.574285 | 
2025-09-23 00:09:59.574428 | TASK [ensure-docker : Assure docker service is running]
2025-09-23 00:10:01.453612 | controller | changed
2025-09-23 00:10:01.471204 | 
2025-09-23 00:10:01.471371 | TASK [ensure-docker : Assure docker.socket service is running]
2025-09-23 00:10:02.465003 | controller | ok
2025-09-23 00:10:02.473050 | 
2025-09-23 00:10:02.473132 | TASK [ensure-docker : Correct group ownership on docker sock]
2025-09-23 00:10:03.082099 | controller | ok
2025-09-23 00:10:03.096137 | 
2025-09-23 00:10:03.096291 | TASK [ensure-docker : Validate ability to talk with docker]
2025-09-23 00:10:03.697806 | controller | CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES
2025-09-23 00:10:04.146001 | controller | ok: Runtime: 0:00:00.049790
2025-09-23 00:10:04.162131 | 
2025-09-23 00:10:04.162360 | TASK [ensure-docker : Get version details]
2025-09-23 00:10:04.808774 | controller | Client: Docker Engine - Community
2025-09-23 00:10:04.808815 | controller |  Version:           24.0.7
2025-09-23 00:10:04.808873 | controller |  API version:       1.43
2025-09-23 00:10:04.808881 | controller |  Go version:        go1.20.10
2025-09-23 00:10:04.808892 | controller |  Git commit:        afdd53b
2025-09-23 00:10:04.808898 | controller |  Built:             Thu Oct 26 09:09:39 2023
2025-09-23 00:10:04.808903 | controller |  OS/Arch:           linux/amd64
2025-09-23 00:10:04.808909 | controller |  Context:           default
2025-09-23 00:10:04.808915 | controller |
2025-09-23 00:10:04.808920 | controller | Server: Docker Engine - Community
2025-09-23 00:10:04.808924 | controller |  Engine:
2025-09-23 00:10:04.808931 | controller |   Version:          24.0.7
2025-09-23 00:10:04.808950 | controller |   API version:      1.43 (minimum version 1.12)
2025-09-23 00:10:04.808968 | controller |   Go version:       go1.20.10
2025-09-23 00:10:04.808972 | controller |   Git commit:       311b9ff
2025-09-23 00:10:04.808977 | controller |   Built:            Thu Oct 26 09:08:11 2023
2025-09-23 00:10:04.808981 | controller |   OS/Arch:          linux/amd64
2025-09-23 00:10:04.808985 | controller |   Experimental:     false
2025-09-23 00:10:04.808990 | controller |  containerd:
2025-09-23 00:10:04.808994 | controller |   Version:          1.6.25
2025-09-23 00:10:04.808999 | controller |   GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
2025-09-23 00:10:04.809003 | controller |  runc:
2025-09-23 00:10:04.809007 | controller |   Version:          1.1.10
2025-09-23 00:10:04.809012 | controller |   GitCommit:        v1.1.10-0-g18a0cb0
2025-09-23 00:10:04.809018 | controller |  docker-init:
2025-09-23 00:10:04.809024 | controller |   Version:          0.19.0
2025-09-23 00:10:04.810176 | controller |   GitCommit:        de40ad0
2025-09-23 00:10:05.231445 | controller | ok: Runtime: 0:00:00.076474
2025-09-23 00:10:05.245827 | 
2025-09-23 00:10:05.246138 | TASK [ensure-docker : Dump installed docker details]
2025-09-23 00:10:05.289093 | {'changed': True, 'stdout': 'Client: Docker Engine - Community\n Version:           24.0.7\n API version:       1.43\n Go version:        go1.20.10\n Git commit:        afdd53b\n Built:             Thu Oct 26 09:09:39 2023\n OS/Arch:           linux/amd64\n Context:           default\n\nServer: Docker Engine - Community\n Engine:\n  Version:          24.0.7\n  API version:      1.43 (minimum version 1.12)\n  Go version:       go1.20.10\n  Git commit:       311b9ff\n  Built:            Thu Oct 26 09:08:11 2023\n  OS/Arch:          linux/amd64\n  Experimental:     false\n containerd:\n  Version:          1.6.25\n  GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f\n runc:\n  Version:          1.1.10\n  GitCommit:        v1.1.10-0-g18a0cb0\n docker-init:\n  Version:          0.19.0\n  GitCommit:        de40ad0', 'stderr': '', 'rc': 0, 'cmd': ['docker', 'version'], 'start': '2025-09-23 00:10:04.733903', 'end': '2025-09-23 00:10:04.810377', 'delta': '0:00:00.076474', 'msg': '', 'zuul_log_id': 'fa163ef9-e89a-2da2-d756-000000000061-1-controller', 'stdout_lines': ['Client: Docker Engine - Community', ' Version:           24.0.7', ' API version:       1.43', ' Go version:        go1.20.10', ' Git commit:        afdd53b', ' Built:             Thu Oct 26 09:09:39 2023', ' OS/Arch:           linux/amd64', ' Context:           default', '', 'Server: Docker Engine - Community', ' Engine:', '  Version:          24.0.7', '  API version:      1.43 (minimum version 1.12)', '  Go version:       go1.20.10', '  Git commit:       311b9ff', '  Built:            Thu Oct 26 09:08:11 2023', '  OS/Arch:          linux/amd64', '  Experimental:     false', ' containerd:', '  Version:          1.6.25', '  GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f', ' runc:', '  Version:          1.1.10', '  GitCommit:        v1.1.10-0-g18a0cb0', ' docker-init:', '  Version:          0.19.0', '  GitCommit:        de40ad0'], 'stderr_lines': [], 'failed': False}
2025-09-23 00:10:05.302501 | 
2025-09-23 00:10:05.302622 | TASK [Use buildset registry]
2025-09-23 00:10:05.328889 | controller | skipping: Conditional result was False
2025-09-23 00:10:05.339943 | 
2025-09-23 00:10:05.340025 | TASK [Ensure python3.8 is present]
2025-09-23 00:10:05.354349 | controller | skipping: Conditional result was False
2025-09-23 00:10:05.361029 | 
2025-09-23 00:10:05.361143 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-09-23 00:10:05.381243 | controller | ok
2025-09-23 00:10:05.400534 | 
2025-09-23 00:10:05.400657 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-09-23 00:10:07.427872 | controller | ok: Nothing to do
2025-09-23 00:10:07.437141 | 
2025-09-23 00:10:07.437253 | TASK [our-ensure-python : Also install python3-devel]
2025-09-23 00:10:18.874561 | controller | changed
2025-09-23 00:10:18.891227 | 
2025-09-23 00:10:18.891360 | TASK [Run ensure-virtualenv role]
2025-09-23 00:10:18.911823 | controller | ok
2025-09-23 00:10:18.933756 | 
2025-09-23 00:10:18.933862 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-09-23 00:10:19.140502 | controller | /usr/bin/virtualenv
2025-09-23 00:10:19.465109 | controller | ok: Runtime: 0:00:00.003386
2025-09-23 00:10:19.479216 | 
2025-09-23 00:10:19.479432 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-09-23 00:10:19.507338 | controller | skipping: Conditional result was False
2025-09-23 00:10:19.507825 | controller | changed: All items complete
2025-09-23 00:10:19.507892 | 
2025-09-23 00:10:19.544756 | 
2025-09-23 00:10:19.544918 | TASK [Find the full path of the Python interpreter]
2025-09-23 00:10:19.773195 | controller | /usr/bin/python3.8
2025-09-23 00:10:20.088365 | controller | ok
2025-09-23 00:10:20.097290 | 
2025-09-23 00:10:20.097448 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-09-23 00:10:21.691613 | controller | created virtual environment CPython3.8.18.final.0-64 in 770ms
2025-09-23 00:10:21.732947 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-09-23 00:10:21.732984 | controller |   seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv)
2025-09-23 00:10:21.732995 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-09-23 00:10:21.733008 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-09-23 00:10:22.144134 | controller | changed
2025-09-23 00:10:22.156684 | 
2025-09-23 00:10:22.156909 | TASK [Set selinux package]
2025-09-23 00:10:22.196536 | controller | ok
2025-09-23 00:10:22.207846 | 
2025-09-23 00:10:22.207979 | TASK [Set selinux package (Fedora)]
2025-09-23 00:10:22.256842 | controller | ok
2025-09-23 00:10:22.268281 | 
2025-09-23 00:10:22.268413 | TASK [Install selinux into virtualenv]
2025-09-23 00:10:49.387049 | controller | Collecting selinux-please-lie-to-me
2025-09-23 00:11:01.642920 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-09-23 00:11:02.275329 | controller | Collecting setuptools<50.0.0
2025-09-23 00:11:02.351290 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-09-23 00:11:02.390645 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.8 MB/s eta 0:00:00
2025-09-23 00:11:02.473454 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-09-23 00:11:02.473598 | controller |   Attempting uninstall: setuptools
2025-09-23 00:11:02.474319 | controller |     Found existing installation: setuptools 62.6.0
2025-09-23 00:11:02.549991 | controller |     Uninstalling setuptools-62.6.0:
2025-09-23 00:11:02.558603 | controller |       Successfully uninstalled setuptools-62.6.0
2025-09-23 00:11:02.865283 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-09-23 00:11:13.980640 | controller |
2025-09-23 00:11:14.056702 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-09-23 00:11:14.056778 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-09-23 00:11:14.344721 | controller | ok: Runtime: 0:00:51.198971
2025-09-23 00:11:14.350915 | 
2025-09-23 00:11:14.350997 | TASK [Install pytest-forked into virtualenv]
2025-09-23 00:11:24.156275 | controller | Collecting pytest-forked
2025-09-23 00:11:36.391281 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-09-23 00:11:36.559897 | controller | Collecting pytest>=3.10
2025-09-23 00:11:36.568631 | controller |   Downloading pytest-8.3.5-py3-none-any.whl (343 kB)
2025-09-23 00:11:36.594946 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 343.6/343.6 kB 15.3 MB/s eta 0:00:00
2025-09-23 00:11:36.671269 | controller | Collecting py
2025-09-23 00:11:36.674845 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-09-23 00:11:36.683231 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 15.2 MB/s eta 0:00:00
2025-09-23 00:11:36.766000 | controller | Collecting exceptiongroup>=1.0.0rc8
2025-09-23 00:11:36.769738 | controller |   Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB)
2025-09-23 00:11:36.834945 | controller | Collecting packaging
2025-09-23 00:11:36.838650 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-09-23 00:11:36.846233 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.0 MB/s eta 0:00:00
2025-09-23 00:11:36.872475 | controller | Collecting iniconfig
2025-09-23 00:11:36.876673 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-09-23 00:11:36.917359 | controller | Collecting tomli>=1
2025-09-23 00:11:36.921679 | controller |   Downloading tomli-2.2.1-py3-none-any.whl (14 kB)
2025-09-23 00:11:36.963121 | controller | Collecting pluggy<2,>=1.5
2025-09-23 00:11:37.016997 | controller |   Downloading pluggy-1.5.0-py3-none-any.whl (20 kB)
2025-09-23 00:11:37.078652 | controller | Collecting typing-extensions>=4.6.0
2025-09-23 00:11:37.083144 | controller |   Downloading typing_extensions-4.13.2-py3-none-any.whl (45 kB)
2025-09-23 00:11:37.088398 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 12.7 MB/s eta 0:00:00
2025-09-23 00:11:37.151193 | controller | Installing collected packages: typing-extensions, tomli, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked
2025-09-23 00:11:37.569531 | controller | Successfully installed exceptiongroup-1.3.0 iniconfig-2.1.0 packaging-25.0 pluggy-1.5.0 py-1.11.0 pytest-8.3.5 pytest-forked-1.6.0 tomli-2.2.1 typing-extensions-4.13.2
2025-09-23 00:11:37.573665 | controller |
2025-09-23 00:11:37.636569 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-09-23 00:11:37.636596 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-09-23 00:11:37.898926 | controller | ok: Runtime: 0:00:23.060452
2025-09-23 00:11:37.905560 | 
2025-09-23 00:11:37.905676 | TASK [Update pip]
2025-09-23 00:11:38.445811 | controller | Requirement already satisfied: pip in ./venv/lib/python3.8/site-packages (22.2.2)
2025-09-23 00:11:48.775719 | controller | Collecting pip
2025-09-23 00:12:01.027868 | controller |   Downloading pip-25.0.1-py3-none-any.whl (1.8 MB)
2025-09-23 00:12:01.091734 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 30.9 MB/s eta 0:00:00
2025-09-23 00:12:01.147084 | controller | Installing collected packages: pip
2025-09-23 00:12:01.147227 | controller |   Attempting uninstall: pip
2025-09-23 00:12:01.147891 | controller |     Found existing installation: pip 22.2.2
2025-09-23 00:12:01.321191 | controller |     Uninstalling pip-22.2.2:
2025-09-23 00:12:01.336862 | controller |       Successfully uninstalled pip-22.2.2
2025-09-23 00:12:02.116564 | controller | Successfully installed pip-25.0.1
2025-09-23 00:12:02.446482 | controller | ok: Runtime: 0:00:24.075177
2025-09-23 00:12:02.454903 | 
2025-09-23 00:12:02.455046 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-09-23 00:12:02.660484 | controller | changed
2025-09-23 00:12:02.672833 | 
2025-09-23 00:12:02.672956 | TASK [Install ansible into virtualenv]
2025-09-23 00:12:03.188223 | controller | Processing ./src/github.com/ansible/ansible
2025-09-23 00:12:03.188975 | controller |   Preparing metadata (setup.py): started
2025-09-23 00:12:03.614023 | controller |   Preparing metadata (setup.py): finished with status 'done'
2025-09-23 00:12:13.296737 | controller | Collecting jinja2 (from ansible-base==2.10.17.post0)
2025-09-23 00:12:23.464432 | controller |   Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB)
2025-09-23 00:12:23.535865 | controller | Collecting PyYAML (from ansible-base==2.10.17.post0)
2025-09-23 00:12:23.572162 | controller |   Downloading PyYAML-6.0.2-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (2.1 kB)
2025-09-23 00:12:23.838656 | controller | Collecting cryptography (from ansible-base==2.10.17.post0)
2025-09-23 00:12:23.867526 | controller |   Downloading cryptography-46.0.1-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB)
2025-09-23 00:12:23.895801 | controller | Requirement already satisfied: packaging in ./venv/lib/python3.8/site-packages (from ansible-base==2.10.17.post0) (25.0)
2025-09-23 00:12:24.058044 | controller | Collecting cffi>=1.14 (from cryptography->ansible-base==2.10.17.post0)
2025-09-23 00:12:24.092346 | controller |   Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (1.5 kB)
2025-09-23 00:12:24.102443 | controller | Requirement already satisfied: typing-extensions>=4.13.2 in ./venv/lib/python3.8/site-packages (from cryptography->ansible-base==2.10.17.post0) (4.13.2)
2025-09-23 00:12:24.172291 | controller | Collecting MarkupSafe>=2.0 (from jinja2->ansible-base==2.10.17.post0)
2025-09-23 00:12:24.184981 | controller |   Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB)
2025-09-23 00:12:24.228862 | controller | Collecting pycparser (from cffi>=1.14->cryptography->ansible-base==2.10.17.post0)
2025-09-23 00:12:24.233016 | controller |   Downloading pycparser-2.23-py3-none-any.whl.metadata (993 bytes)
2025-09-23 00:12:24.254781 | controller | Downloading cryptography-46.0.1-cp38-abi3-manylinux_2_34_x86_64.whl (4.6 MB)
2025-09-23 00:12:24.320898 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.6/4.6 MB 80.7 MB/s eta 0:00:00
2025-09-23 00:12:24.328783 | controller | Downloading jinja2-3.1.6-py3-none-any.whl (134 kB)
2025-09-23 00:12:24.353001 | controller | Downloading PyYAML-6.0.2-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (746 kB)
2025-09-23 00:12:24.376362 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 746.5/746.5 kB 30.2 MB/s eta 0:00:00
2025-09-23 00:12:24.383496 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB)
2025-09-23 00:12:24.402124 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (26 kB)
2025-09-23 00:12:24.418332 | controller | Downloading pycparser-2.23-py3-none-any.whl (118 kB)
2025-09-23 00:12:24.445590 | controller | Building wheels for collected packages: ansible-base
2025-09-23 00:12:24.446230 | controller |   Building wheel for ansible-base (setup.py): started
2025-09-23 00:12:25.653405 | controller |   Building wheel for ansible-base (setup.py): finished with status 'done'
2025-09-23 00:12:25.655585 | controller |   Created wheel for ansible-base: filename=ansible_base-2.10.17.post0-py3-none-any.whl size=1881569 sha256=ae0bad0b11aee76a1c4af732a31c4388f7d48f4561b3ef86e95a237fde5f889b
2025-09-23 00:12:25.655782 | controller |   Stored in directory: /var/tmp/ansible-test-pip/pip-ephem-wheel-cache-qlc2ha8n/wheels/a5/4b/fa/b6deaae105422b0b3b92831e0369d44bf7fca5bb3413d79be7
2025-09-23 00:12:25.664863 | controller | Successfully built ansible-base
2025-09-23 00:12:25.697859 | controller | Installing collected packages: PyYAML, pycparser, MarkupSafe, jinja2, cffi, cryptography, ansible-base
2025-09-23 00:12:27.052358 | controller | Successfully installed MarkupSafe-2.1.5 PyYAML-6.0.2 ansible-base-2.10.17.post0 cffi-1.17.1 cryptography-46.0.1 jinja2-3.1.6 pycparser-2.23
2025-09-23 00:12:27.226033 | controller | ok: Runtime: 0:00:24.236920
2025-09-23 00:12:27.232270 | 
2025-09-23 00:12:27.232373 | TASK [Setup download-artifact-fork role]
2025-09-23 00:12:27.251558 | controller | ok
2025-09-23 00:12:27.274452 | 
2025-09-23 00:12:27.274585 | TASK [download-artifact-fork : Parse inventory response]
2025-09-23 00:12:27.304862 | controller | ok
2025-09-23 00:12:27.311094 | 
2025-09-23 00:12:27.311166 | TASK [download-artifact-fork : Fetch info from Zuul API]
2025-09-23 00:12:27.335176 | controller | skipping: Conditional result was False
2025-09-23 00:12:27.341884 | 
2025-09-23 00:12:27.341988 | TASK [download-artifact-fork : Parse build response]
2025-09-23 00:12:27.366905 | controller | skipping: Conditional result was False
2025-09-23 00:12:27.373136 | 
2025-09-23 00:12:27.373234 | TASK [download-artifact-fork : Ensure artifacts directory exists]
2025-09-23 00:12:27.579562 | controller | changed
2025-09-23 00:12:27.588177 | 
2025-09-23 00:12:27.588299 | LOOP [download-artifact-fork : Download archive by type]
2025-09-23 00:12:27.612930 | controller | skipping: Conditional result was False
2025-09-23 00:12:27.613215 | 
2025-09-23 00:12:28.576193 | controller | changed: OK (20210 bytes)
2025-09-23 00:12:28.604710 | 
2025-09-23 00:12:28.605030 | TASK [deploy-artifacts : define __collections]
2025-09-23 00:12:28.640287 | controller | ok
2025-09-23 00:12:28.649240 | 
2025-09-23 00:12:28.649363 | LOOP [deploy-artifacts : Create list of collections]
2025-09-23 00:12:28.672798 | controller | skipping: Conditional result was False
2025-09-23 00:12:28.679483 | controller | ok:
2025-09-23 00:12:28.679581 | controller | {
2025-09-23 00:12:28.679604 | controller |   "branch": "main",
2025-09-23 00:12:28.679622 | controller |   "job": "build-ansible-collection",
2025-09-23 00:12:28.679639 | controller |   "metadata": {
2025-09-23 00:12:28.679656 | controller |     "type": "ansible_collection",
2025-09-23 00:12:28.679672 | controller |     "version": "5.0.0"
2025-09-23 00:12:28.679688 | controller |   },
2025-09-23 00:12:28.679703 | controller |   "name": "ansible.network",
2025-09-23 00:12:28.679719 | controller |   "project": "ansible-collections/ansible.network",
2025-09-23 00:12:28.679757 | controller |   "url": "https://af01054f635eeb4a9fae-32a02f76c70759d21352b186e3463762.ssl.cf2.rackcdn.com/ansible/d1c4c3323f274a1db5ba0cd2ba3b8841/artifacts/ansible-network-5.0.0.tar.gz"
2025-09-23 00:12:28.679782 | controller | }
2025-09-23 00:12:28.695006 | 
2025-09-23 00:12:28.695164 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy]
2025-09-23 00:12:29.296019 | controller | Starting galaxy collection install process
2025-09-23 00:12:29.296216 | controller | Process install dependency map
2025-09-23 00:17:56.454557 | controller | Starting collection install process
2025-09-23 00:17:56.454718 | controller | Installing 'ansible.network:5.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/network'
2025-09-23 00:17:56.465559 | controller | ansible.network (5.0.0) was installed successfully
2025-09-23 00:17:56.465629 | controller | Installing 'ansible.netcommon:8.1.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2025-09-23 00:17:56.465762 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-netcommon-8.1.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4050drchzlty/tmpxpx3pl84
2025-09-23 00:18:46.520419 | controller | ansible.netcommon (8.1.0) was installed successfully
2025-09-23 00:18:46.520498 | controller | Installing 'ansible.utils:6.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/utils'
2025-09-23 00:18:46.520511 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-utils-6.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4050drchzlty/tmpxpx3pl84
2025-09-23 00:19:27.746949 | controller | ansible.utils (6.0.0) was installed successfully
2025-09-23 00:19:27.747212 | controller | Installing 'arista.eos:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/arista/eos'
2025-09-23 00:19:27.747239 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/arista-eos-12.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4050drchzlty/tmpxpx3pl84
2025-09-23 00:20:11.528650 | controller | arista.eos (12.0.0) was installed successfully
2025-09-23 00:20:11.528742 | controller | Installing 'cisco.ios:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/ios'
2025-09-23 00:20:11.529105 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-ios-11.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4050drchzlty/tmpxpx3pl84
2025-09-23 00:20:54.689298 | controller | cisco.ios (11.0.0) was installed successfully
2025-09-23 00:20:54.689422 | controller | Installing 'cisco.iosxr:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/iosxr'
2025-09-23 00:20:54.689567 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-iosxr-12.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4050drchzlty/tmpxpx3pl84
2025-09-23 00:21:44.025172 | controller | cisco.iosxr (12.0.0) was installed successfully
2025-09-23 00:21:44.025225 | controller | Installing 'cisco.nxos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/nxos'
2025-09-23 00:21:44.025320 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-nxos-11.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4050drchzlty/tmpxpx3pl84
2025-09-23 00:22:42.386230 | controller | cisco.nxos (11.0.0) was installed successfully
2025-09-23 00:22:42.386327 | controller | Installing 'junipernetworks.junos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/junipernetworks/junos'
2025-09-23 00:22:42.386476 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/junipernetworks-junos-11.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4050drchzlty/tmpxpx3pl84
2025-09-23 00:23:26.251214 | controller | junipernetworks.junos (11.0.0) was installed successfully
2025-09-23 00:23:26.563704 | controller | ok: Runtime: 0:10:57.338728
2025-09-23 00:23:26.593377 | 
2025-09-23 00:23:26.593582 | TASK [podman may need iptables kernel modules]
2025-09-23 00:23:27.149574 | controller | ok: Runtime: 0:00:00.003577
2025-09-23 00:23:27.201276 | 
2025-09-23 00:23:27.201510 | PLAY RECAP
2025-09-23 00:23:27.201819 | controller | ok: 46 changed: 26 unreachable: 0 failed: 0 skipped: 17 rescued: 0 ignored: 0
2025-09-23 00:23:27.201897 | 
2025-09-23 00:23:27.360190 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-09-23 00:23:27.362280 | RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-09-23 00:23:28.045965 | 
2025-09-23 00:23:28.046098 | PLAY [controller]
2025-09-23 00:23:28.068946 | 
2025-09-23 00:23:28.069075 | TASK [Copy the galaxy.yml on the controller]
2025-09-23 00:23:29.141557 | controller | changed
2025-09-23 00:23:29.150661 | 
2025-09-23 00:23:29.150836 | TASK [Load information from galaxy.yml]
2025-09-23 00:23:29.186590 | controller | ok
2025-09-23 00:23:29.194465 | 
2025-09-23 00:23:29.194554 | LOOP [Enable FIPS mode]
2025-09-23 00:23:29.219449 | 
2025-09-23 00:23:29.219627 | LOOP [ansible-test : Include branch specific variables.]
2025-09-23 00:23:29.265111 | controller | ok: "/var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/untrusted/project_2/github.com/ansible/ansible-zuul-jobs/roles/ansible-test/vars/default.yaml"
2025-09-23 00:23:29.265743 | 
2025-09-23 00:23:29.285250 | 
2025-09-23 00:23:29.285390 | TASK [ansible-test : Setup --skip-tags for test_options]
2025-09-23 00:23:29.330307 | controller | ok
2025-09-23 00:23:29.338817 | 
2025-09-23 00:23:29.338930 | TASK [ansible-test : Enable --inventory for network-integration]
2025-09-23 00:23:29.355097 | controller | skipping: Conditional result was False
2025-09-23 00:23:29.365505 | 
2025-09-23 00:23:29.365634 | TASK [ansible-test : Enable --retry-on-error]
2025-09-23 00:23:29.381111 | controller | skipping: Conditional result was False
2025-09-23 00:23:29.390870 | 
2025-09-23 00:23:29.391002 | TASK [ansible-test : Enable --continue-on-error]
2025-09-23 00:23:29.425283 | controller | ok
2025-09-23 00:23:29.433565 | 
2025-09-23 00:23:29.433684 | TASK [ansible-test : Enable --requirements]
2025-09-23 00:23:29.449210 | controller | skipping: Conditional result was False
2025-09-23 00:23:29.461116 | 
2025-09-23 00:23:29.461328 | TASK [ansible-test : Adjust options for unit tests]
2025-09-23 00:23:29.487166 | controller | skipping: Conditional result was False
2025-09-23 00:23:29.497240 | 
2025-09-23 00:23:29.497370 | TASK [ansible-test : Install requirements with unit tests]
2025-09-23 00:23:29.530996 | controller | ok
2025-09-23 00:23:29.540307 | 
2025-09-23 00:23:29.540420 | TASK [ansible-test : Set --skip-test]
2025-09-23 00:23:29.586221 | controller | skipping: Conditional result was False
2025-09-23 00:23:29.596284 | 
2025-09-23 00:23:29.596408 | TASK [ansible-test : Reduce verbosity]
2025-09-23 00:23:29.631102 | controller | ok
2025-09-23 00:23:29.639302 | 
2025-09-23 00:23:29.639379 | TASK [ansible-test : Setup --python option]
2025-09-23 00:23:29.655996 | controller | skipping: Conditional result was False
2025-09-23 00:23:29.700900 | 
2025-09-23 00:23:29.701042 | TASK [ansible-test : Setup --docker option]
2025-09-23 00:23:29.733788 | controller | ok
2025-09-23 00:23:29.739146 | 
2025-09-23 00:23:29.739223 | TASK [ansible-test : check if MANIFEST.json exists]
2025-09-23 00:23:30.046680 | controller | ok
2025-09-23 00:23:30.055151 | 
2025-09-23 00:23:30.055295 | TASK [ansible-test : Copy the MANIFEST.json on the controller]
2025-09-23 00:23:30.081793 | controller | skipping: Conditional result was False
2025-09-23 00:23:30.092435 | 
2025-09-23 00:23:30.092588 | TASK [ansible-test : Load information from MANIFEST.json]
2025-09-23 00:23:30.119695 | controller | skipping: Conditional result was False
2025-09-23 00:23:30.131555 | 
2025-09-23 00:23:30.131674 | TASK [ansible-test : Setup location of project for integration tests]
2025-09-23 00:23:30.158146 | controller | skipping: Conditional result was False
2025-09-23 00:23:30.168373 | 
2025-09-23 00:23:30.168499 | TASK [ansible-test : Copy the galaxy.yml on the controller]
2025-09-23 00:23:30.868019 | controller | ok
2025-09-23 00:23:30.880860 | 
2025-09-23 00:23:30.881042 | TASK [ansible-test : Load information from galaxy.yml]
2025-09-23 00:23:30.930901 | controller | ok
2025-09-23 00:23:30.945974 | 
2025-09-23 00:23:30.946123 | TASK [ansible-test : Setup location of project for integration tests]
2025-09-23 00:23:30.996195 | controller | ok
2025-09-23 00:23:31.009061 | 
2025-09-23 00:23:31.009213 | TASK [ansible-test : Setup minimum test requirements]
2025-09-23 00:23:31.049202 | controller | ok
2025-09-23 00:23:31.061669 | 
2025-09-23 00:23:31.061853 | TASK [ansible-test : Ensure pip temp directory exists in /var/tmp]
2025-09-23 00:23:31.590095 | controller | ok
2025-09-23 00:23:31.604853 | 
2025-09-23 00:23:31.604985 | TASK [ansible-test : Install python requirements]
2025-09-23 00:23:42.538602 | controller | Collecting yamllint (from -r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-09-23 00:23:54.859219 | controller |   Downloading yamllint-1.35.1-py3-none-any.whl.metadata (4.2 kB)
2025-09-23 00:23:54.890402 | controller | Collecting pathspec>=0.5.3 (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-09-23 00:23:54.895233 | controller |   Downloading pathspec-0.12.1-py3-none-any.whl.metadata (21 kB)
2025-09-23 00:23:54.910590 | controller | Requirement already satisfied: pyyaml in ./venv/lib64/python3.8/site-packages (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1)) (6.0.2)
2025-09-23 00:23:54.918168 | controller | Downloading yamllint-1.35.1-py3-none-any.whl (66 kB)
2025-09-23 00:23:54.931611 | controller | Downloading pathspec-0.12.1-py3-none-any.whl (31 kB)
2025-09-23 00:23:54.971900 | controller | Installing collected packages: pathspec, yamllint
2025-09-23 00:23:55.023193 | controller | Successfully installed pathspec-0.12.1 yamllint-1.35.1
2025-09-23 00:23:55.167345 | controller | ok: Runtime: 0:00:22.779939
2025-09-23 00:23:55.182452 | 
2025-09-23 00:23:55.182655 | TASK [ansible-test : Copy potential cloud provider configuration for ansible-test in the collection]
2025-09-23 00:23:55.740121 | controller | skipping: Conditional result was False
2025-09-23 00:23:55.749055 | 
2025-09-23 00:23:55.749210 | TASK [ansible-test : Enable persistent connection logging]
2025-09-23 00:23:56.444702 | controller | changed: section and option added
2025-09-23 00:23:56.452215 | 
2025-09-23 00:23:56.452327 | TASK [ansible-test : Set persistent ssh_type value]
2025-09-23 00:23:56.860438 | controller | changed: option added
2025-09-23 00:23:56.868543 | 
2025-09-23 00:23:56.868662 | TASK [ansible-test : Set ansible log path]
2025-09-23 00:23:57.419037 | controller | changed: section and option added
2025-09-23 00:23:57.433962 | 
2025-09-23 00:23:57.434187 | TASK [ansible-test : Identify the changed targets]
2025-09-23 00:23:57.980847 | controller | skipping: Conditional result was False
2025-09-23 00:23:57.995543 | 
2025-09-23 00:23:57.995771 | TASK [ansible-test : set_fact]
2025-09-23 00:23:58.063936 | controller | skipping: Conditional result was False
2025-09-23 00:23:58.079835 | 
2025-09-23 00:23:58.080031 | TASK [ansible-test : Set the targets]
2025-09-23 00:23:58.130537 | controller | ok
2025-09-23 00:23:58.144128 | 
2025-09-23 00:23:58.144320 | TASK [ansible-test : set_fact]
2025-09-23 00:23:58.172810 | controller | skipping: Conditional result was False
2025-09-23 00:23:58.187622 | 
2025-09-23 00:23:58.187869 | TASK [ansible-test : List the targets]
2025-09-23 00:23:58.768435 | controller | skipping: Conditional result was False
2025-09-23 00:23:58.781637 | 
2025-09-23 00:23:58.781805 | TASK [ansible-test : set_fact]
2025-09-23 00:23:58.808256 | controller | skipping: Conditional result was False
2025-09-23 00:23:58.823229 | 
2025-09-23 00:23:58.823423 | TASK [ansible-test : set_fact]
2025-09-23 00:23:58.850306 | controller | skipping: Conditional result was False
2025-09-23 00:23:58.865786 | 
2025-09-23 00:23:58.865984 | LOOP [ansible-test : set_fact]
2025-09-23 00:23:58.929518 | 
2025-09-23 00:23:58.929853 | TASK [ansible-test : set_fact]
2025-09-23 00:23:58.946870 | controller | skipping: Conditional result was False
2025-09-23 00:23:58.957921 | 
2025-09-23 00:23:58.958068 | TASK [ansible-test : debug]
2025-09-23 00:23:58.974318 | controller | skipping: Conditional result was False
2025-09-23 00:23:58.984661 | 
2025-09-23 00:23:58.984834 | TASK [ansible-test : debug]
2025-09-23 00:23:59.019368 | About to run: ansible-test sanity --requirements --docker -v
2025-09-23 00:23:59.027939 | 
2025-09-23 00:23:59.028063 | TASK [ansible-test : Run the test suite]
2025-09-23 00:23:59.574508 | controller | Run command: docker images quay.io/ansible/default-test-container:2.9.0 --format '{{json .}}'
2025-09-23 00:23:59.610877 | controller | Run command: docker pull quay.io/ansible/default-test-container:2.9.0
2025-09-23 00:24:01.317285 | controller | 2.9.0: Pulling from ansible/default-test-container
2025-09-23 00:24:01.318891 | controller | 171857c49d0f: Pulling fs layer
2025-09-23 00:24:01.319001 | controller | 419640447d26: Pulling fs layer
2025-09-23 00:24:01.319011 | controller | 61e52f862619: Pulling fs layer
2025-09-23 00:24:01.319015 | controller | 851de0426e26: Pulling fs layer
2025-09-23 00:24:01.319022 | controller | 37425716ea5b: Pulling fs layer
2025-09-23 00:24:01.319029 | controller | cd9b0c439616: Pulling fs layer
2025-09-23 00:24:01.319033 | controller | d4612dbd8855: Pulling fs layer
2025-09-23 00:24:01.319038 | controller | 554699364730: Pulling fs layer
2025-09-23 00:24:01.319042 | controller | 1ff15d4bdb3e: Pulling fs layer
2025-09-23 00:24:01.319046 | controller | 5f2e4724adea: Pulling fs layer
2025-09-23 00:24:01.319050 | controller | a02d9a95ccb8: Pulling fs layer
2025-09-23 00:24:01.319054 | controller | 989f4ce370cb: Pulling fs layer
2025-09-23 00:24:01.319058 | controller | 0d7f52cdf9df: Pulling fs layer
2025-09-23 00:24:01.319063 | controller | c423742351d5: Pulling fs layer
2025-09-23 00:24:01.319067 | controller | 109236341d21: Pulling fs layer
2025-09-23 00:24:01.319072 | controller | 07a2f61c96b8: Pulling fs layer
2025-09-23 00:24:01.319076 | controller | 041f122f27ae: Pulling fs layer
2025-09-23 00:24:01.319080 | controller | ca6f5098b12e: Pulling fs layer
2025-09-23 00:24:01.319084 | controller | 1eb3e7b2afd9: Pulling fs layer
2025-09-23 00:24:01.319100 | controller | 18a0b750727a: Pulling fs layer
2025-09-23 00:24:01.319115 | controller | 17f2f596716c: Pulling fs layer
2025-09-23 00:24:01.319121 | controller | f35a9998a9bd: Pulling fs layer
2025-09-23 00:24:01.319125 | controller | fdfc10566405: Pulling fs layer
2025-09-23 00:24:01.319129 | controller | 1ff1c442c5fe: Pulling fs layer
2025-09-23 00:24:01.319177 | controller | a3443c4a17ed: Pulling fs layer
2025-09-23 00:24:01.319185 | controller | 0edcf9fb2b15: Pulling fs layer
2025-09-23 00:24:01.319191 | controller | 5af43b69e845: Pulling fs layer
2025-09-23 00:24:01.319197 | controller | 1651773effb2: Pulling fs layer
2025-09-23 00:24:01.319203 | controller | 79e23c5c0fe4: Pulling fs layer
2025-09-23 00:24:01.319212 | controller | e5058b1faaa6: Pulling fs layer
2025-09-23 00:24:01.319218 | controller | 846775490569: Pulling fs layer
2025-09-23 00:24:01.319224 | controller | 07a2f61c96b8: Waiting
2025-09-23 00:24:01.319228 | controller | 041f122f27ae: Waiting
2025-09-23 00:24:01.319232 | controller | ca6f5098b12e: Waiting
2025-09-23 00:24:01.319236 | controller | 1eb3e7b2afd9: Waiting
2025-09-23 00:24:01.319241 | controller | 18a0b750727a: Waiting
2025-09-23 00:24:01.319246 | controller | 17f2f596716c: Waiting
2025-09-23 00:24:01.319254 | controller | f35a9998a9bd: Waiting
2025-09-23 00:24:01.319259 | controller | fdfc10566405: Waiting
2025-09-23 00:24:01.319264 | controller | 1ff1c442c5fe: Waiting
2025-09-23 00:24:01.319269 | controller | a3443c4a17ed: Waiting
2025-09-23 00:24:01.319275 | controller | 0edcf9fb2b15: Waiting
2025-09-23 00:24:01.319281 | controller | 5af43b69e845: Waiting
2025-09-23 00:24:01.319287 | controller | 1651773effb2: Waiting
2025-09-23 00:24:01.319296 | controller | 79e23c5c0fe4: Waiting
2025-09-23 00:24:02.202014 | controller | e5058b1faaa6: Waiting
2025-09-23 00:24:02.202043 | controller | 846775490569: Waiting
2025-09-23 00:24:02.202048 | controller | 1ff15d4bdb3e: Waiting
2025-09-23 00:24:02.202052 | controller | 5f2e4724adea: Waiting
2025-09-23 00:24:02.202061 | controller | a02d9a95ccb8: Waiting
2025-09-23 00:24:02.202065 | controller | 989f4ce370cb: Waiting
2025-09-23 00:24:02.202069 | controller | 0d7f52cdf9df: Waiting
2025-09-23 00:24:02.202073 | controller | c423742351d5: Waiting
2025-09-23 00:24:02.202078 | controller | 109236341d21: Waiting
2025-09-23 00:24:02.202082 | controller | 851de0426e26: Waiting
2025-09-23 00:24:02.202086 | controller | 37425716ea5b: Waiting
2025-09-23 00:24:02.202109 | controller | cd9b0c439616: Waiting
2025-09-23 00:24:02.202114 | controller | d4612dbd8855: Waiting
2025-09-23 00:24:02.202119 | controller | 554699364730: Waiting
2025-09-23 00:24:02.202134 | controller | 419640447d26: Verifying Checksum
2025-09-23 00:24:02.244044 | controller | 419640447d26: Download complete
2025-09-23 00:24:02.244063 | controller | 61e52f862619: Verifying Checksum
2025-09-23 00:24:03.383301 | controller | 61e52f862619: Download complete
2025-09-23 00:24:03.383364 | controller | 171857c49d0f: Verifying Checksum
2025-09-23 00:24:03.425954 | controller | 171857c49d0f: Download complete
2025-09-23 00:24:03.425990 | controller | 851de0426e26: Verifying Checksum
2025-09-23 00:24:04.329250 | controller | 851de0426e26: Download complete
2025-09-23 00:24:04.329289 | controller | cd9b0c439616: Verifying Checksum
2025-09-23 00:24:04.672624 | controller | cd9b0c439616: Download complete
2025-09-23 00:24:04.672664 | controller | d4612dbd8855: Verifying Checksum
2025-09-23 00:24:05.308785 | controller | d4612dbd8855: Download complete
2025-09-23 00:24:05.308823 | controller | 171857c49d0f: Pull complete
2025-09-23 00:24:05.329913 | controller | 419640447d26: Pull complete
2025-09-23 00:24:05.367283 | controller | 61e52f862619: Pull complete
2025-09-23 00:24:05.385791 | controller | 851de0426e26: Pull complete
2025-09-23 00:24:05.952004 | controller | 1ff15d4bdb3e: Verifying Checksum
2025-09-23 00:24:06.914502 | controller | 1ff15d4bdb3e: Download complete
2025-09-23 00:24:06.914551 | controller | 554699364730: Verifying Checksum
2025-09-23 00:24:07.093759 | controller | 554699364730: Download complete
2025-09-23 00:24:07.093828 | controller | 5f2e4724adea: Verifying Checksum
2025-09-23 00:24:08.215470 | controller | 5f2e4724adea: Download complete
2025-09-23 00:24:08.215574 | controller | 989f4ce370cb: Verifying Checksum
2025-09-23 00:24:08.252749 | controller | 989f4ce370cb: Download complete
2025-09-23 00:24:08.252802 | controller | a02d9a95ccb8: Verifying Checksum
2025-09-23 00:24:09.442285 | controller | a02d9a95ccb8: Download complete
2025-09-23 00:24:09.442350 | controller | c423742351d5: Verifying Checksum
2025-09-23 00:24:09.570041 | controller | c423742351d5: Download complete
2025-09-23 00:24:09.570140 | controller | 0d7f52cdf9df: Verifying Checksum
2025-09-23 00:24:10.794908 | controller | 0d7f52cdf9df: Download complete
2025-09-23 00:24:10.794979 | controller | 07a2f61c96b8: Verifying Checksum
2025-09-23 00:24:10.795127 | controller | 07a2f61c96b8: Download complete
2025-09-23 00:24:12.016522 | controller | 041f122f27ae: Verifying Checksum
2025-09-23 00:24:12.016630 | controller | 041f122f27ae: Download complete
2025-09-23 00:24:12.971851 | controller | 109236341d21: Verifying Checksum
2025-09-23 00:24:12.972011 | controller | 109236341d21: Download complete
2025-09-23 00:24:13.611302 | controller | ca6f5098b12e: Verifying Checksum
2025-09-23 00:24:13.611349 | controller | ca6f5098b12e: Download complete
2025-09-23 00:24:14.160485 | controller | 1eb3e7b2afd9: Verifying Checksum
2025-09-23 00:24:14.160568 | controller | 1eb3e7b2afd9: Download complete
2025-09-23 00:24:15.025747 | controller | 18a0b750727a: Verifying Checksum
2025-09-23 00:24:15.300998 | controller | 18a0b750727a: Download complete
2025-09-23 00:24:15.301078 | controller | 17f2f596716c: Verifying Checksum
2025-09-23 00:24:16.143457 | controller | 17f2f596716c: Download complete
2025-09-23 00:24:16.143503 | controller | f35a9998a9bd: Verifying Checksum
2025-09-23 00:24:16.546012 | controller | f35a9998a9bd: Download complete
2025-09-23 00:24:16.546085 | controller | fdfc10566405: Verifying Checksum
2025-09-23 00:24:17.331229 | controller | fdfc10566405: Download complete
2025-09-23 00:24:17.331322 | controller | 1ff1c442c5fe: Verifying Checksum
2025-09-23 00:24:18.220303 | controller | 1ff1c442c5fe: Download complete
2025-09-23 00:24:18.220353 | controller | a3443c4a17ed: Verifying Checksum
2025-09-23 00:24:18.413164 | controller | a3443c4a17ed: Download complete
2025-09-23 00:24:18.413212 | controller | 37425716ea5b: Verifying Checksum
2025-09-23 00:24:18.414339 | controller | 37425716ea5b: Download complete
2025-09-23 00:24:19.235271 | controller | 0edcf9fb2b15: Verifying Checksum
2025-09-23 00:24:19.235327 | controller | 0edcf9fb2b15: Download complete
2025-09-23 00:24:19.771796 | controller | 5af43b69e845: Verifying Checksum
2025-09-23 00:24:20.584515 | controller | 5af43b69e845: Download complete
2025-09-23 00:24:20.584569 | controller | 1651773effb2: Verifying Checksum
2025-09-23 00:24:20.739931 | controller | 1651773effb2: Download complete
2025-09-23 00:24:20.739985 | controller | 79e23c5c0fe4: Verifying Checksum
2025-09-23 00:24:21.463520 | controller | 79e23c5c0fe4: Download complete
2025-09-23 00:24:21.463581 | controller | e5058b1faaa6: Verifying Checksum
2025-09-23 00:24:22.791153 | controller | e5058b1faaa6: Download complete
2025-09-23 00:24:22.791207 | controller | 846775490569: Verifying Checksum
2025-09-23 00:24:22.791290 | controller | 846775490569: Download complete
2025-09-23 00:24:30.898995 | controller | 37425716ea5b: Pull complete
2025-09-23 00:24:30.916919 | controller | cd9b0c439616: Pull complete
2025-09-23 00:24:30.939803 | controller | d4612dbd8855: Pull complete
2025-09-23 00:24:34.148616 | controller | 554699364730: Pull complete
2025-09-23 00:24:34.168948 | controller | 1ff15d4bdb3e: Pull complete
2025-09-23 00:24:34.190386 | controller | 5f2e4724adea: Pull complete
2025-09-23 00:24:34.224918 | controller | a02d9a95ccb8: Pull complete
2025-09-23 00:24:34.245896 | controller | 989f4ce370cb: Pull complete
2025-09-23 00:24:34.266189 | controller | 0d7f52cdf9df: Pull complete
2025-09-23 00:24:34.285122 | controller | c423742351d5: Pull complete
2025-09-23 00:24:35.490620 | controller | 109236341d21: Pull complete
2025-09-23 00:24:35.511087 | controller | 07a2f61c96b8: Pull complete
2025-09-23 00:24:35.536777 | controller | 041f122f27ae: Pull complete
2025-09-23 00:24:35.642213 | controller | ca6f5098b12e: Pull complete
2025-09-23 00:24:35.692618 | controller | 1eb3e7b2afd9: Pull complete
2025-09-23 00:24:35.747420 | controller | 18a0b750727a: Pull complete
2025-09-23 00:24:35.774715 | controller | 17f2f596716c: Pull complete
2025-09-23 00:24:35.796426 | controller | f35a9998a9bd: Pull complete
2025-09-23 00:24:35.832669 | controller | fdfc10566405: Pull complete
2025-09-23 00:24:35.861837 | controller | 1ff1c442c5fe: Pull complete
2025-09-23 00:24:36.816619 | controller | a3443c4a17ed: Pull complete
2025-09-23 00:24:37.885914 | controller | 0edcf9fb2b15: Pull complete
2025-09-23 00:24:39.461924 | controller | 5af43b69e845: Pull complete
2025-09-23 00:24:41.001609 | controller | 1651773effb2: Pull complete
2025-09-23 00:24:42.524181 | controller | 79e23c5c0fe4: Pull complete
2025-09-23 00:24:43.675742 | controller | e5058b1faaa6: Pull complete
2025-09-23 00:24:45.229534 | controller | 846775490569: Pull complete
2025-09-23 00:24:45.249189 | controller | Digest: sha256:923f4b465456ae05243474faf9061abbefa2c2c5b88f24455fa2d5ce3d8d2ab4
2025-09-23 00:24:45.253781 | controller | Status: Downloaded newer image for quay.io/ansible/default-test-container:2.9.0
2025-09-23 00:24:45.259887 | controller | quay.io/ansible/default-test-container:2.9.0
2025-09-23 00:24:45.261999 | controller | Run command: docker images quay.io/ansible/pypi-test-container:1.0.0 --format '{{json .}}'
2025-09-23 00:24:45.285481 | controller | Run command: docker pull quay.io/ansible/pypi-test-container:1.0.0
2025-09-23 00:24:47.152827 | controller | 1.0.0: Pulling from ansible/pypi-test-container
2025-09-23 00:24:47.153228 | controller | 04a5f4cda3ee: Pulling fs layer
2025-09-23 00:24:47.153787 | controller | ff496a88c8ed: Pulling fs layer
2025-09-23 00:24:47.153819 | controller | 0ce83f459fe7: Pulling fs layer
2025-09-23 00:24:47.153830 | controller | 2e5170e1f099: Pulling fs layer
2025-09-23 00:24:47.153841 | controller | 7641eb41b08c: Pulling fs layer
2025-09-23 00:24:47.153851 | controller | ad15fa9da398: Pulling fs layer
2025-09-23 00:24:47.153861 | controller | 087d91352424: Pulling fs layer
2025-09-23 00:24:47.153871 | controller | 8b92efd6a100: Pulling fs layer
2025-09-23 00:24:47.153887 | controller | 2e5170e1f099: Waiting
2025-09-23 00:24:48.030767 | controller | 7641eb41b08c: Waiting
2025-09-23 00:24:48.030832 | controller | ad15fa9da398: Waiting
2025-09-23 00:24:48.030850 | controller | 087d91352424: Waiting
2025-09-23 00:24:48.030864 | controller | 8b92efd6a100: Waiting
2025-09-23 00:24:48.030926 | controller | ff496a88c8ed: Verifying Checksum
2025-09-23 00:24:48.031038 | controller | ff496a88c8ed: Download complete
2025-09-23 00:24:48.301010 | controller | 04a5f4cda3ee: Verifying Checksum
2025-09-23 00:24:48.301106 | controller | 04a5f4cda3ee: Download complete
2025-09-23 00:24:48.303400 | controller | 0ce83f459fe7: Verifying Checksum
2025-09-23 00:24:49.148320 | controller | 0ce83f459fe7: Download complete
2025-09-23 00:24:49.148373 | controller | 2e5170e1f099: Verifying Checksum
2025-09-23 00:24:49.250361 | controller | 2e5170e1f099: Download complete
2025-09-23 00:24:49.250405 | controller | 7641eb41b08c: Verifying Checksum
2025-09-23 00:24:49.250458 | controller | 7641eb41b08c: Download complete
2025-09-23 00:24:49.354439 | controller | ad15fa9da398: Verifying Checksum
2025-09-23 00:24:49.354523 | controller | ad15fa9da398: Download complete
2025-09-23 00:24:50.233121 | controller | 087d91352424: Verifying Checksum
2025-09-23 00:24:50.233179 | controller | 087d91352424: Download complete
2025-09-23 00:24:50.382124 | controller | 8b92efd6a100: Download complete
2025-09-23 00:24:50.382366 | controller | 04a5f4cda3ee: Pull complete
2025-09-23 00:24:50.431702 | controller | ff496a88c8ed: Pull complete
2025-09-23 00:24:50.453639 | controller | 0ce83f459fe7: Pull complete
2025-09-23 00:24:52.116303 | controller | 2e5170e1f099: Pull complete
2025-09-23 00:24:52.137997 | controller | 7641eb41b08c: Pull complete
2025-09-23 00:24:52.159650 | controller | ad15fa9da398: Pull complete
2025-09-23 00:24:52.756243 | controller | 087d91352424: Pull complete
2025-09-23 00:24:52.784485 | controller | 8b92efd6a100: Pull complete
2025-09-23 00:24:52.825400 | controller | Digest: sha256:71042ab0a14971b5608fe75706de54f367fc31db573e3b3955182037f73cadb6
2025-09-23 00:24:52.835243 | controller | Status: Downloaded newer image for quay.io/ansible/pypi-test-container:1.0.0
2025-09-23 00:24:52.846906 | controller | quay.io/ansible/pypi-test-container:1.0.0
2025-09-23 00:24:52.849798 | controller | Run command: docker run --detach quay.io/ansible/pypi-test-container:1.0.0
2025-09-23 00:24:56.350161 | controller | Run command: docker inspect 6ebb45f7a825f9be77ad382c7c6c1579c8ecef9143cc66b50c0ae7fb34e06866
2025-09-23 00:24:56.389071 | controller | Scanning collection root: /home/zuul/.ansible/collections/ansible_collections
2025-09-23 00:24:56.398227 | controller | Including collection: ansible.netcommon (288 files)
2025-09-23 00:24:56.398264 | controller | Including collection: ansible.network (23 files)
2025-09-23 00:24:56.405567 | controller | Including collection: ansible.utils (442 files)
2025-09-23 00:24:56.432216 | controller | Including collection: arista.eos (1022 files)
2025-09-23 00:24:56.460817 | controller | Including collection: cisco.ios (1167 files)
2025-09-23 00:24:56.488359 | controller | Including collection: cisco.iosxr (1037 files)
2025-09-23 00:24:56.534597 | controller | Including collection: cisco.nxos (1680 files)
2025-09-23 00:24:56.561666 | controller | Including collection: junipernetworks.junos (963 files)
2025-09-23 00:24:56.584736 | controller | Creating a payload archive containing 7348 files...
2025-09-23 00:24:58.086332 | controller | Created a 5945130 byte payload archive containing 7348 files in 1 seconds.
2025-09-23 00:24:58.087538 | controller | Assuming Docker is available on localhost.
2025-09-23 00:24:58.087727 | controller | Run command: docker run --detach --volume /sys/fs/cgroup:/sys/fs/cgroup:ro --privileged=false --security-opt seccomp=unconfined --volume /var/run/docker.sock:/var/run/docker.sock quay.io/ansible/default-test-container:2.9.0
2025-09-23 00:24:58.491120 | controller | Run command: docker exec -i dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f dd of=/root/docker.sh bs=65536
2025-09-23 00:24:58.545861 | controller | Run command: docker exec dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f /bin/bash /root/docker.sh
2025-09-23 00:24:58.598498 | controller | Run command: docker exec -i dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f dd of=/root/test.tgz bs=65536
2025-09-23 00:24:58.665586 | controller | Run command: docker exec dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f tar oxzf /root/test.tgz -C /root
2025-09-23 00:24:59.299165 | controller | Run command: docker exec dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f /usr/bin/env ANSIBLE_TEST_CONTENT_ROOT=/root/ansible_collections/ansible/network LC_ALL=en_US.UTF-8 /usr/bin/python3.6 /root/ansible/bin/ansible-test sanity -v --metadata tests/output/.tmp/metadata-ve8l5g2b.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/
2025-09-23 00:24:59.548142 | controller | Injecting custom PyPI hosts entries: /etc/hosts
2025-09-23 00:24:59.548449 | controller | Injecting custom PyPI config: /root/.pip/pip.conf
2025-09-23 00:24:59.549632 | controller | Injecting custom PyPI config: /root/.pydistutils.cfg
2025-09-23 00:24:59.549667 | controller | Running sanity test 'action-plugin-docs' with Python 3.6
2025-09-23 00:24:59.550070 | controller | Read 0 sanity test ignore line(s) for Ansible 2.10 from: tests/sanity/ignore-2.10.txt
2025-09-23 00:24:59.554573 | controller | No tests applicable.
2025-09-23 00:24:59.554743 | controller | Running sanity test 'ansible-doc' with Python 3.6
2025-09-23 00:24:59.554767 | controller | No tests applicable.
2025-09-23 00:24:59.555025 | controller | Running sanity test 'changelog' with Python 3.6
2025-09-23 00:24:59.555053 | controller | Run command: /usr/bin/python3.6 /root/ansible/test/lib/ansible_test/_data/quiet_pip.py install --disable-pip-version-check -r /root/ansible/test/lib/ansible_test/_data/requirements/ansible-test.txt
2025-09-23 00:25:00.154552 | controller | Run command: /usr/bin/python3.6 /root/ansible/test/lib/ansible_test/_data/quiet_pip.py install --disable-pip-version-check -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt -c /root/ansible/test/lib/ansible_test/_data/requirements/constraints.txt
2025-09-23 00:25:00.538546 | controller | Collecting antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2))
2025-09-23 00:25:00.573304 | controller |   ERROR: Could not find a version that satisfies the requirement antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2)) (from versions: none)
2025-09-23 00:25:00.574478 | controller | ERROR: No matching distribution found for antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2))
2025-09-23 00:25:00.613134 | controller | ERROR: Command "/usr/bin/python3.6 /root/ansible/test/lib/ansible_test/_data/quiet_pip.py install --disable-pip-version-check -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt -c /root/ansible/test/lib/ansible_test/_data/requirements/constraints.txt" returned exit status 1.
2025-09-23 00:25:00.613356 | controller | Removing custom PyPI config: /root/.pydistutils.cfg
2025-09-23 00:25:00.613483 | controller | Removing custom PyPI config: /root/.pip/pip.conf
2025-09-23 00:25:00.631440 | controller | Removing custom PyPI hosts entries: /etc/hosts
2025-09-23 00:25:00.631500 | controller | Run command: docker exec dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f tar czf /root/output.tgz --exclude .tmp -C /root/ansible_collections/ansible/network/tests output
2025-09-23 00:25:00.687116 | controller | Run command: docker exec -i dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f dd if=/root/output.tgz bs=65536
2025-09-23 00:25:00.738367 | controller | Run command: tar oxzf /tmp/ansible-result-046u56xr.tgz -C /home/zuul/.ansible/collections/ansible_collections/ansible/network/tests
2025-09-23 00:25:00.747082 | controller | Run command: docker rm -f 6ebb45f7a825f9be77ad382c7c6c1579c8ecef9143cc66b50c0ae7fb34e06866
2025-09-23 00:25:01.523340 | controller | Run command: docker rm -f dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f
2025-09-23 00:25:01.947963 | controller | ERROR: Command "docker exec dd6d5185655d075ef1147f2af0b2c39db301d8613e561f847929efc59005919f /usr/bin/env ANSIBLE_TEST_CONTENT_ROOT=/root/ansible_collections/ansible/network LC_ALL=en_US.UTF-8 /usr/bin/python3.6 /root/ansible/bin/ansible-test sanity -v --metadata tests/output/.tmp/metadata-ve8l5g2b.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/" returned exit status 1.
2025-09-23 00:25:02.117797 | controller | ERROR
2025-09-23 00:25:02.117999 | controller | {
2025-09-23 00:25:02.118035 | controller |   "delta": "0:01:02.555651",
2025-09-23 00:25:02.118060 | controller |   "end": "2025-09-23 00:25:01.970429",
2025-09-23 00:25:02.118083 | controller |   "msg": "non-zero return code",
2025-09-23 00:25:02.118105 | controller |   "rc": 1,
2025-09-23 00:25:02.118127 | controller |   "start": "2025-09-23 00:23:59.414778"
2025-09-23 00:25:02.118148 | controller | }
failure
2025-09-23 00:25:02.123388 | 
2025-09-23 00:25:02.123492 | PLAY RECAP
2025-09-23 00:25:02.123546 | controller | ok: 20 changed: 5 unreachable: 0 failed: 1 skipped: 20 rescued: 0 ignored: 0
2025-09-23 00:25:02.123571 | 
2025-09-23 00:25:02.264296 | RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-09-23 00:25:02.265258 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-09-23 00:25:02.900883 | 
2025-09-23 00:25:02.901026 | PLAY [all]
2025-09-23 00:25:02.925789 | 
2025-09-23 00:25:02.925939 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-09-23 00:25:03.396533 | controller | changed: non-zero return code
2025-09-23 00:25:03.411553 | 
2025-09-23 00:25:03.411835 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-09-23 00:25:03.440056 | controller | skipping: Conditional result was False
2025-09-23 00:25:03.454877 | 
2025-09-23 00:25:03.455081 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-09-23 00:25:03.497378 | 
2025-09-23 00:25:03.497664 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-09-23 00:25:03.537599 | 
2025-09-23 00:25:03.537972 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-09-23 00:25:03.554816 | controller | skipping: Conditional result was False
2025-09-23 00:25:03.570199 | 
2025-09-23 00:25:03.570706 | LOOP [fetch-subunit-output : Generate subunit file]
2025-09-23 00:25:03.611668 | 
2025-09-23 00:25:03.611959 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-09-23 00:25:03.638691 | controller | skipping: Conditional result was False
2025-09-23 00:25:03.649913 | 
2025-09-23 00:25:03.650029 | TASK [fetch-subunit-output : Remove the temporary file]
2025-09-23 00:25:03.666986 | controller | skipping: Conditional result was False
2025-09-23 00:25:03.677484 | 
2025-09-23 00:25:03.677595 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-09-23 00:25:03.691927 | controller | skipping: Conditional result was False
2025-09-23 00:25:03.731328 | 
2025-09-23 00:25:03.731421 | PLAY RECAP
2025-09-23 00:25:03.731463 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-09-23 00:25:03.731491 | 
2025-09-23 00:25:03.834113 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-09-23 00:25:03.835682 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-09-23 00:25:04.453573 | 
2025-09-23 00:25:04.453718 | PLAY [all:!appliance*]
2025-09-23 00:25:04.475257 | 
2025-09-23 00:25:04.475371 | TASK [unregister the node]
2025-09-23 00:25:05.005887 | controller | skipping: Conditional result was False
2025-09-23 00:25:05.011961 | 
2025-09-23 00:25:05.012068 | TASK [include_role : fetch-output]
2025-09-23 00:25:05.045711 | controller | ok
2025-09-23 00:25:05.074470 | 
2025-09-23 00:25:05.074587 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-23 00:25:05.148984 | controller | skipping: Conditional result was False
2025-09-23 00:25:05.155530 | 
2025-09-23 00:25:05.155613 | TASK [fetch-output : Set log path for single node]
2025-09-23 00:25:05.215707 | controller | ok
2025-09-23 00:25:05.221548 | 
2025-09-23 00:25:05.221673 | LOOP [fetch-output : Ensure local output dirs]
2025-09-23 00:25:05.627428 | controller -> localhost | ok: "/var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/logs"
2025-09-23 00:25:05.889852 | controller -> localhost | changed: "/var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/artifacts"
2025-09-23 00:25:06.143081 | controller -> localhost | changed: "/var/lib/zuul/builds/f113ce09efd64dcabc054f91d65acbab/work/docs"
2025-09-23 00:25:06.161352 | 
2025-09-23 00:25:06.161463 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-23 00:25:06.937323 | controller | changed:
2025-09-23 00:25:06.937524 | controller | .d..t...... ./
2025-09-23 00:25:06.937552 | controller | cd+++++++++ controller/
2025-09-23 00:25:06.937585 | controller | changed: All items complete
2025-09-23 00:25:06.937608 | 
2025-09-23 00:25:07.469856 | controller | changed: .d..t...... ./
2025-09-23 00:25:08.031618 | controller | changed: .d..t...... ./
2025-09-23 00:25:08.064393 | 
2025-09-23 00:25:08.064588 | TASK [include_role : fetch-output-openshift]
2025-09-23 00:25:08.083402 | controller | skipping: Conditional result was False
2025-09-23 00:25:08.094465 | 
2025-09-23 00:25:08.094624 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-09-23 00:25:08.132403 | controller | skipping: Conditional result was False
2025-09-23 00:25:08.147522 | controller | skipping: Conditional result was False
2025-09-23 00:25:08.181947 | 
2025-09-23 00:25:08.182067 | PLAY [localhost]
2025-09-23 00:25:08.200185 | 
2025-09-23 00:25:08.200322 | TASK [Run Zuul manifest role]
2025-09-23 00:25:08.220862 | localhost | ok
2025-09-23 00:25:08.243095 | 
2025-09-23 00:25:08.243234 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-09-23 00:25:08.593505 | localhost | changed
2025-09-23 00:25:08.603679 | 
2025-09-23 00:25:08.603852 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-09-23 00:25:08.649219 | localhost | ok
2025-09-23 00:25:08.666809 | 
2025-09-23 00:25:08.666936 | TASK [Set zuul-log-path fact]
2025-09-23 00:25:08.691161 | localhost | ok
2025-09-23 00:25:08.722532 | 
2025-09-23 00:25:08.722701 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-23 00:25:08.753926 | localhost | ok
2025-09-23 00:25:08.765690 | 
2025-09-23 00:25:08.765799 | LOOP [Run upload-logs-swift role]
2025-09-23 00:25:08.813722 | localhost | Output suppressed because no_log was given
2025-09-23 00:25:08.866250 | 
2025-09-23 00:25:08.866391 | TASK [Set zuul-log-path fact]
2025-09-23 00:25:08.892290 | localhost | skipping: Conditional result was False
2025-09-23 00:25:08.897891 | 
2025-09-23 00:25:08.897954 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-09-23 00:25:09.287406 | localhost -> localhost | ok: Runtime: 0:00:00.006039
2025-09-23 00:25:09.322047 | 
2025-09-23 00:25:09.322165 | TASK [upload-logs-swift : Upload logs to swift]