2025-09-28 00:06:57.191435 | Job console starting...
2025-09-28 00:06:57.203201 | Updating repositories
2025-09-28 00:06:57.361872 | Preparing job workspace
2025-09-28 00:07:02.300099 | Running Ansible setup...
2025-09-28 00:07:10.170571 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-09-28 00:07:10.788513 | 
2025-09-28 00:07:10.788627 | PLAY [localhost]
2025-09-28 00:07:10.796877 | 
2025-09-28 00:07:10.796945 | TASK [Gathering Facts]
2025-09-28 00:07:11.733005 | localhost | ok
2025-09-28 00:07:11.747968 | 
2025-09-28 00:07:11.748126 | TASK [Setup log path fact]
2025-09-28 00:07:11.771322 | localhost | ok
2025-09-28 00:07:11.785282 | 
2025-09-28 00:07:11.785569 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-28 00:07:11.816316 | localhost | ok
2025-09-28 00:07:11.828261 | 
2025-09-28 00:07:11.828407 | TASK [emit-job-header : Print job information]
2025-09-28 00:07:11.873584 | # Job Information
2025-09-28 00:07:11.873738 | Ansible Version: 2.15.12
2025-09-28 00:07:11.873770 | Job: ansible-test-sanity-docker-stable-2.10
2025-09-28 00:07:11.873792 | Pipeline: periodic
2025-09-28 00:07:11.873812 | Executor: ze01.softwarefactory-project.io
2025-09-28 00:07:11.873831 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-09-28 00:07:11.873853 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/2c8/ansible/2c8d14e00ead42a7b9ec320eb32ea44d/
2025-09-28 00:07:11.873873 | Event ID: ac2a50b5a9f846e4a242a91e1fee7f50
2025-09-28 00:07:11.877523 | 
2025-09-28 00:07:11.877586 | LOOP [emit-job-header : Print node information]
2025-09-28 00:07:11.983122 | localhost | ok:
2025-09-28 00:07:11.983360 | localhost | # Node Information
2025-09-28 00:07:11.983389 | localhost | Inventory Hostname: controller
2025-09-28 00:07:11.983409 | localhost | Hostname: np0005457725
2025-09-28 00:07:11.983429 | localhost | Username: zuul
2025-09-28 00:07:11.983453 | localhost | Distro: Fedora 37
2025-09-28 00:07:11.983473 | localhost | Provider: ansible-vexxhost-ams1
2025-09-28 00:07:11.983491 | localhost | Region: ams1
2025-09-28 00:07:11.983508 | localhost | Label: ansible-fedora-37-1vcpu
2025-09-28 00:07:11.983525 | localhost | Product Name: OpenStack Nova
2025-09-28 00:07:11.983542 | localhost | Interface IP: 38.129.16.86
2025-09-28 00:07:11.998198 | 
2025-09-28 00:07:11.998322 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-09-28 00:07:12.368148 | localhost -> localhost | changed
2025-09-28 00:07:12.374326 | 
2025-09-28 00:07:12.374414 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-09-28 00:07:13.313374 | localhost -> localhost | changed
2025-09-28 00:07:13.364217 | 
2025-09-28 00:07:13.364320 | PLAY [all:!appliance*]
2025-09-28 00:07:13.386415 | 
2025-09-28 00:07:13.386518 | TASK [include_role : start-zuul-console]
2025-09-28 00:07:13.409269 | controller | ok
2025-09-28 00:07:13.429722 | 
2025-09-28 00:07:13.429838 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-09-28 00:07:14.578086 | controller | ok
2025-09-28 00:07:14.593964 | 
2025-09-28 00:07:14.594274 | TASK [use-our-mirror : Retrieve the IP address]
2025-09-28 00:07:17.182686 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-09-28 00:07:17.199667 | 
2025-09-28 00:07:17.199846 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-09-28 00:07:17.574785 | controller | skipping: Conditional result was False
2025-09-28 00:07:17.592160 | 
2025-09-28 00:07:17.592513 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-09-28 00:07:17.630490 | controller | skipping: Conditional result was False
2025-09-28 00:07:17.645140 | 
2025-09-28 00:07:17.645296 | TASK [use-our-mirror : Create the podman configuration directory]
2025-09-28 00:07:17.673775 | controller | skipping: Conditional result was False
2025-09-28 00:07:17.689736 | 
2025-09-28 00:07:17.689919 | TASK [use-our-mirror : Copy the podman configuration]
2025-09-28 00:07:17.717372 | controller | skipping: Conditional result was False
2025-09-28 00:07:17.728600 | 
2025-09-28 00:07:17.728778 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-09-28 00:07:17.755257 | controller | skipping: Conditional result was False
2025-09-28 00:07:17.764248 | 
2025-09-28 00:07:17.764352 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-09-28 00:07:17.789845 | controller | skipping: Conditional result was False
2025-09-28 00:07:17.806230 | 
2025-09-28 00:07:17.806345 | TASK [Disable Fedora Modular]
2025-09-28 00:07:19.049649 | controller | changed
2025-09-28 00:07:19.061923 | 
2025-09-28 00:07:19.062085 | TASK [Enable EPEL]
2025-09-28 00:07:19.088395 | controller | skipping: Conditional result was False
2025-09-28 00:07:19.101249 | 
2025-09-28 00:07:19.101409 | TASK [Register the RHEL node]
2025-09-28 00:07:19.517752 | 
2025-09-28 00:07:19.517900 | TASK [Show the subscription-manager status]
2025-09-28 00:07:19.899107 | controller | skipping: Conditional result was False
2025-09-28 00:07:19.905455 | 
2025-09-28 00:07:19.905534 | TASK [Enable EPEL on RHEL]
2025-09-28 00:07:20.305098 | controller | skipping: Conditional result was False
2025-09-28 00:07:20.318389 | 
2025-09-28 00:07:20.318575 | TASK [Install git and tox]
2025-09-28 00:10:35.760556 | controller | changed
2025-09-28 00:10:35.766964 | 
2025-09-28 00:10:35.767059 | TASK [include_role : prepare-workspace]
2025-09-28 00:10:35.797418 | controller | ok
2025-09-28 00:10:35.819826 | 
2025-09-28 00:10:35.819950 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-09-28 00:10:36.658678 | controller | ok
2025-09-28 00:10:36.667752 | 
2025-09-28 00:10:36.667870 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-09-28 00:10:52.417316 | controller | Output suppressed because no_log was given
2025-09-28 00:10:52.428281 | 
2025-09-28 00:10:52.428375 | TASK [include_role : prepare-workspace-openshift]
2025-09-28 00:10:52.445449 | controller | skipping: Conditional result was False
2025-09-28 00:10:52.471455 | 
2025-09-28 00:10:52.471577 | PLAY [all:!appliance]
2025-09-28 00:10:52.490006 | 
2025-09-28 00:10:52.490146 | TASK [Run add-build-sshkey role (RSA)]
2025-09-28 00:10:52.520116 | controller | ok
2025-09-28 00:10:52.537540 | 
2025-09-28 00:10:52.537654 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-28 00:10:52.807331 | controller -> localhost | ok
2025-09-28 00:10:52.816815 | 
2025-09-28 00:10:52.816938 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-28 00:10:52.850387 | controller | ok
2025-09-28 00:10:52.872065 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-28 00:10:52.881388 | 
2025-09-28 00:10:52.881526 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-28 00:10:53.481601 | controller -> localhost | Generating public/private rsa key pair.
2025-09-28 00:10:53.481936 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/2c8d14e00ead42a7b9ec320eb32ea44d_id_rsa.
2025-09-28 00:10:53.481980 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/2c8d14e00ead42a7b9ec320eb32ea44d_id_rsa.pub.
2025-09-28 00:10:53.482009 | controller -> localhost | The key fingerprint is:
2025-09-28 00:10:53.482063 | controller -> localhost | SHA256:OSktPbKX9+KZxwQyNVT7dzYCYhFkd+zrQlLHcXgr0nU zuul-build-sshkey
2025-09-28 00:10:53.482092 | controller -> localhost | The key's randomart image is:
2025-09-28 00:10:53.482119 | controller -> localhost | +---[RSA 2048]----+
2025-09-28 00:10:53.482143 | controller -> localhost | |        .*ooo..  |
2025-09-28 00:10:53.482167 | controller -> localhost | |        . = .= +E|
2025-09-28 00:10:53.482192 | controller -> localhost | |         + o= = o|
2025-09-28 00:10:53.482217 | controller -> localhost | |       o+ooo.B . |
2025-09-28 00:10:53.482238 | controller -> localhost | |      + So..o.+.+|
2025-09-28 00:10:53.482277 | controller -> localhost | |       = = ....oo|
2025-09-28 00:10:53.482312 | controller -> localhost | |      . o +o.    |
2025-09-28 00:10:53.482340 | controller -> localhost | |       . ..=o.   |
2025-09-28 00:10:53.482365 | controller -> localhost | |         .+oo    |
2025-09-28 00:10:53.482390 | controller -> localhost | +----[SHA256]-----+
2025-09-28 00:10:53.482458 | controller -> localhost | ok: Runtime: 0:00:00.142053
2025-09-28 00:10:53.491297 | 
2025-09-28 00:10:53.491417 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-28 00:10:53.526772 | controller | ok
2025-09-28 00:10:53.539900 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-28 00:10:53.552272 | 
2025-09-28 00:10:53.552414 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-28 00:10:53.578955 | controller | skipping: Conditional result was False
2025-09-28 00:10:53.586536 | 
2025-09-28 00:10:53.586650 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-28 00:10:54.673542 | controller | changed
2025-09-28 00:10:54.686410 | 
2025-09-28 00:10:54.686550 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-28 00:10:55.360182 | controller | ok
2025-09-28 00:10:55.374231 | 
2025-09-28 00:10:55.374382 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-28 00:10:58.553272 | controller | changed
2025-09-28 00:10:58.561213 | 
2025-09-28 00:10:58.561301 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-28 00:11:01.971488 | controller | changed
2025-09-28 00:11:01.985280 | 
2025-09-28 00:11:01.985450 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-28 00:11:02.013441 | controller | skipping: Conditional result was False
2025-09-28 00:11:02.028356 | 
2025-09-28 00:11:02.029278 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-28 00:11:02.485197 | controller -> localhost | changed
2025-09-28 00:11:02.511438 | 
2025-09-28 00:11:02.511616 | TASK [add-build-sshkey : Add back temp key]
2025-09-28 00:11:02.806127 | controller -> localhost | Identity added: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/2c8d14e00ead42a7b9ec320eb32ea44d_id_rsa (zuul-build-sshkey)
2025-09-28 00:11:02.806628 | controller -> localhost | ok: Runtime: 0:00:00.007273
2025-09-28 00:11:02.823132 | 
2025-09-28 00:11:02.823283 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-28 00:11:03.761562 | controller | ok
2025-09-28 00:11:03.773702 | 
2025-09-28 00:11:03.773839 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-28 00:11:03.811344 | controller | skipping: Conditional result was False
2025-09-28 00:11:03.835527 | 
2025-09-28 00:11:03.835680 | TASK [Run add-build-sshkey role (ECDSA)]
2025-09-28 00:11:03.877268 | controller | ok
2025-09-28 00:11:03.905276 | 
2025-09-28 00:11:03.905368 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-28 00:11:04.185450 | controller -> localhost | ok
2025-09-28 00:11:04.199758 | 
2025-09-28 00:11:04.199896 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-28 00:11:04.240732 | controller | ok
2025-09-28 00:11:04.265502 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-28 00:11:04.274210 | 
2025-09-28 00:11:04.274299 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-28 00:11:04.595453 | controller -> localhost | Generating public/private ecdsa key pair.
2025-09-28 00:11:04.595817 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/2c8d14e00ead42a7b9ec320eb32ea44d_id_ecdsa.
2025-09-28 00:11:04.595888 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/2c8d14e00ead42a7b9ec320eb32ea44d_id_ecdsa.pub.
2025-09-28 00:11:04.595952 | controller -> localhost | The key fingerprint is:
2025-09-28 00:11:04.596001 | controller -> localhost | SHA256:n/JndqQsrEu8DOJFyLkNuQLKhJ1qH05AYzKbddRHXik zuul-build-sshkey
2025-09-28 00:11:04.596098 | controller -> localhost | The key's randomart image is:
2025-09-28 00:11:04.596146 | controller -> localhost | +---[ECDSA 521]---+
2025-09-28 00:11:04.596191 | controller -> localhost | |    .. .. ..     |
2025-09-28 00:11:04.596234 | controller -> localhost | |   .  ..E..      |
2025-09-28 00:11:04.596276 | controller -> localhost | |o+. .  ...       |
2025-09-28 00:11:04.596319 | controller -> localhost | |=*.+ +           |
2025-09-28 00:11:04.596362 | controller -> localhost | |=oo * . S        |
2025-09-28 00:11:04.596403 | controller -> localhost | |+o.  * . . .  .  |
2025-09-28 00:11:04.596443 | controller -> localhost | |oo.o+ + +.o. o   |
2025-09-28 00:11:04.596485 | controller -> localhost | |. +o.o + +o * .  |
2025-09-28 00:11:04.596526 | controller -> localhost | |   o.   =o.= .   |
2025-09-28 00:11:04.596567 | controller -> localhost | +----[SHA256]-----+
2025-09-28 00:11:04.596671 | controller -> localhost | ok: Runtime: 0:00:00.014201
2025-09-28 00:11:04.611720 | 
2025-09-28 00:11:04.611861 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-28 00:11:04.651280 | controller | ok
2025-09-28 00:11:04.668734 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-28 00:11:04.685858 | 
2025-09-28 00:11:04.685942 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-28 00:11:04.711469 | controller | skipping: Conditional result was False
2025-09-28 00:11:04.751721 | 
2025-09-28 00:11:04.751864 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-28 00:11:05.766195 | controller | changed
2025-09-28 00:11:05.778064 | 
2025-09-28 00:11:05.778173 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-28 00:11:06.491693 | controller | ok
2025-09-28 00:11:06.506541 | 
2025-09-28 00:11:06.506716 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-28 00:11:09.681709 | controller | changed
2025-09-28 00:11:09.694909 | 
2025-09-28 00:11:09.695126 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-28 00:11:12.813900 | controller | changed
2025-09-28 00:11:12.826715 | 
2025-09-28 00:11:12.826899 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-28 00:11:12.854080 | controller | skipping: Conditional result was False
2025-09-28 00:11:12.868376 | 
2025-09-28 00:11:12.868566 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-28 00:11:13.161369 | controller -> localhost | changed
2025-09-28 00:11:13.181322 | 
2025-09-28 00:11:13.181507 | TASK [add-build-sshkey : Add back temp key]
2025-09-28 00:11:13.535145 | controller -> localhost | Identity added: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/2c8d14e00ead42a7b9ec320eb32ea44d_id_ecdsa (zuul-build-sshkey)
2025-09-28 00:11:13.535348 | controller -> localhost | ok: Runtime: 0:00:00.015397
2025-09-28 00:11:13.542114 | 
2025-09-28 00:11:13.542201 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-28 00:11:14.326509 | controller | ok
2025-09-28 00:11:14.334309 | 
2025-09-28 00:11:14.334408 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-28 00:11:14.369651 | controller | skipping: Conditional result was False
2025-09-28 00:11:14.387074 | 
2025-09-28 00:11:14.387211 | TASK [include_role : remove-zuul-sshkey]
2025-09-28 00:11:14.412512 | controller | skipping: Conditional result was False
2025-09-28 00:11:14.422088 | 
2025-09-28 00:11:14.422190 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-28 00:11:15.119410 | controller | ok: "logs"
2025-09-28 00:11:15.120004 | controller | ok: All items complete
2025-09-28 00:11:15.120114 | 
2025-09-28 00:11:15.791009 | controller | ok: "artifacts"
2025-09-28 00:11:16.443186 | controller | ok: "docs"
2025-09-28 00:11:16.464569 | 
2025-09-28 00:11:16.464773 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-28 00:11:17.149467 | controller | changed: "logs"
2025-09-28 00:11:17.793159 | controller | changed: "artifacts"
2025-09-28 00:11:18.431947 | controller | changed: "docs"
2025-09-28 00:11:18.477172 | 
2025-09-28 00:11:18.477297 | PLAY RECAP
2025-09-28 00:11:18.477354 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-09-28 00:11:18.477392 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-28 00:11:18.477420 | 
2025-09-28 00:11:18.592056 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-09-28 00:11:18.593718 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-09-28 00:11:19.230207 | 
2025-09-28 00:11:19.230346 | PLAY [all]
2025-09-28 00:11:19.253542 | 
2025-09-28 00:11:19.253676 | TASK [Install binary dependencies]
2025-09-28 00:11:19.324186 | controller | ok
2025-09-28 00:11:19.345906 | 
2025-09-28 00:11:19.346061 | TASK [bindep : Include find tasks]
2025-09-28 00:11:19.386393 | controller | ok
2025-09-28 00:11:19.394485 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-09-28 00:11:19.400747 | 
2025-09-28 00:11:19.400820 | TASK [bindep : Look for bindep.txt]
2025-09-28 00:11:20.386128 | controller | ok
2025-09-28 00:11:20.398800 | 
2025-09-28 00:11:20.399000 | TASK [bindep : Define bindep_file fact]
2025-09-28 00:11:20.426404 | controller | skipping: Conditional result was False
2025-09-28 00:11:20.439435 | 
2025-09-28 00:11:20.439598 | TASK [bindep : Look for other-requirements.txt]
2025-09-28 00:11:21.124161 | controller | ok
2025-09-28 00:11:21.130251 | 
2025-09-28 00:11:21.130317 | TASK [bindep : Define bindep_file fact]
2025-09-28 00:11:21.164268 | controller | skipping: Conditional result was False
2025-09-28 00:11:21.170301 | 
2025-09-28 00:11:21.170364 | TASK [bindep : Look for bindep fallback file]
2025-09-28 00:11:21.214307 | controller | skipping: Conditional result was False
2025-09-28 00:11:21.220775 | 
2025-09-28 00:11:21.220845 | TASK [bindep : Define bindep_file fact]
2025-09-28 00:11:21.254759 | controller | skipping: Conditional result was False
2025-09-28 00:11:21.261281 | 
2025-09-28 00:11:21.261347 | TASK [bindep : Include bindep tasks]
2025-09-28 00:11:21.285328 | controller | skipping: Conditional result was False
2025-09-28 00:11:21.291771 | 
2025-09-28 00:11:21.291845 | TASK [bindep : Include install tasks]
2025-09-28 00:11:21.326641 | controller | skipping: Conditional result was False
2025-09-28 00:11:21.332753 | 
2025-09-28 00:11:21.332826 | LOOP [bindep : Include package tasks]
2025-09-28 00:11:21.412412 | 
2025-09-28 00:11:21.412647 | TASK [Run test-setup role]
2025-09-28 00:11:21.435811 | controller | ok
2025-09-28 00:11:21.454423 | 
2025-09-28 00:11:21.454533 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-09-28 00:11:22.241170 | controller | ok
2025-09-28 00:11:22.254567 | 
2025-09-28 00:11:22.254715 | TASK [test-setup : Run tools/test-setup.sh]
2025-09-28 00:11:22.627997 | controller | skipping: Conditional result was False
2025-09-28 00:11:22.687900 | 
2025-09-28 00:11:22.688051 | PLAY RECAP
2025-09-28 00:11:22.688120 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-09-28 00:11:22.688152 | 
2025-09-28 00:11:22.807732 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-09-28 00:11:22.808570 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-09-28 00:11:23.409631 | 
2025-09-28 00:11:23.409777 | PLAY [controller]
2025-09-28 00:11:23.430941 | 
2025-09-28 00:11:23.431110 | TASK [Create the /root directory]
2025-09-28 00:11:24.509657 | controller | ok
2025-09-28 00:11:24.518659 | 
2025-09-28 00:11:24.518784 | TASK [Install glibc-langpack-en]
2025-09-28 00:11:33.605250 | controller | ok: Nothing to do
2025-09-28 00:11:33.618066 | 
2025-09-28 00:11:33.618214 | TASK [Ensure controller directory exists]
2025-09-28 00:11:34.485788 | controller | changed
2025-09-28 00:11:34.502186 | 
2025-09-28 00:11:34.502306 | TASK [Install container runtime]
2025-09-28 00:11:34.565998 | controller | ok
2025-09-28 00:11:34.625140 | 
2025-09-28 00:11:34.625281 | LOOP [ensure-docker : Gather variables for each operating system]
2025-09-28 00:11:34.657466 | controller | ok: "/var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml"
2025-09-28 00:11:34.667481 | 
2025-09-28 00:11:34.667577 | TASK [ensure-docker : Sanity check for distro selection]
2025-09-28 00:11:34.681581 | controller | skipping: Conditional result was False
2025-09-28 00:11:34.688053 | 
2025-09-28 00:11:34.688163 | TASK [ensure-docker : Sanity check for distro install]
2025-09-28 00:11:34.702598 | controller | skipping: Conditional result was False
2025-09-28 00:11:34.709449 | 
2025-09-28 00:11:34.709543 | TASK [ensure-docker : Sanity check for upstream install]
2025-09-28 00:11:34.743006 | controller | skipping: Conditional result was False
2025-09-28 00:11:34.749194 | 
2025-09-28 00:11:34.749268 | TASK [ensure-docker : Sanity check for upstream install mirrors]
2025-09-28 00:11:34.783315 | controller | skipping: Conditional result was False
2025-09-28 00:11:34.795979 | 
2025-09-28 00:11:34.796138 | TASK [ensure-docker : Include tasks for docker install]
2025-09-28 00:11:34.818953 | controller | ok
2025-09-28 00:11:34.833688 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml
2025-09-28 00:11:34.846342 | 
2025-09-28 00:11:34.846452 | TASK [ensure-docker : Not Implemented]
2025-09-28 00:11:34.861262 | controller | skipping: Conditional result was False
2025-09-28 00:11:34.870443 | 
2025-09-28 00:11:34.870558 | TASK [Set up docker mirrors]
2025-09-28 00:11:34.892822 | controller | ok
2025-09-28 00:11:34.922899 | 
2025-09-28 00:11:34.923004 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info]
2025-09-28 00:11:34.978055 | controller | skipping: Conditional result was False
2025-09-28 00:11:35.009149 | 
2025-09-28 00:11:35.009267 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info]
2025-09-28 00:11:35.033153 | controller | skipping: Conditional result was False
2025-09-28 00:11:35.039270 | 
2025-09-28 00:11:35.039345 | TASK [use-docker-mirror : Set docker_mirror fact]
2025-09-28 00:11:35.063468 | controller | skipping: Conditional result was False
2025-09-28 00:11:35.069734 | 
2025-09-28 00:11:35.069810 | TASK [use-docker-mirror : Set up docker mirrors]
2025-09-28 00:11:35.093383 | controller | skipping: Conditional result was False
2025-09-28 00:11:35.104596 | 
2025-09-28 00:11:35.104701 | TASK [Add all repositories]
2025-09-28 00:11:35.123663 | controller | ok
2025-09-28 00:11:35.148461 | 
2025-09-28 00:11:35.148561 | LOOP [ensure-package-repositories : Install repositories]
2025-09-28 00:11:35.169591 | controller | ok: "/var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml"
2025-09-28 00:11:35.169747 | controller | ok: All items complete
2025-09-28 00:11:35.169774 | 
2025-09-28 00:11:35.180924 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml
2025-09-28 00:11:35.187158 | 
2025-09-28 00:11:35.187225 | TASK [ensure-package-repositories : Create GPG key temp directory]
2025-09-28 00:11:36.122072 | controller | changed
2025-09-28 00:11:36.132866 | 
2025-09-28 00:11:36.132983 | LOOP [ensure-package-repositories : Upload GPG keys]
2025-09-28 00:11:39.415759 | controller | changed:
2025-09-28 00:11:39.416079 | controller | {
2025-09-28 00:11:39.416141 | 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-28 00:11:39.416190 | controller | }
2025-09-28 00:11:39.434978 | 
2025-09-28 00:11:39.435234 | LOOP [ensure-package-repositories : Import GPG keys]
2025-09-28 00:11:40.792805 | controller | changed:
2025-09-28 00:11:40.793224 | controller | {
2025-09-28 00:11:40.793436 | 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-28 00:11:40.793509 | controller | }
2025-09-28 00:11:40.793582 | controller | changed: All items complete
2025-09-28 00:11:40.793633 | 
2025-09-28 00:11:40.809484 | 
2025-09-28 00:11:40.809692 | TASK [ensure-package-repositories : Remove GPG temp directory]
2025-09-28 00:11:41.512662 | controller | changed
2025-09-28 00:11:41.520746 | 
2025-09-28 00:11:41.520949 | LOOP [ensure-package-repositories : Add repositories]
2025-09-28 00:11:42.436471 | controller | changed:
2025-09-28 00:11:42.436966 | controller | {
2025-09-28 00:11:42.437072 | controller |   "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable",
2025-09-28 00:11:42.437119 | controller |   "description": "Docker CE Stable - $basearch",
2025-09-28 00:11:42.437157 | controller |   "gpgcheck": true,
2025-09-28 00:11:42.437191 | controller |   "name": "docker-ce-stable"
2025-09-28 00:11:42.437225 | controller | }
2025-09-28 00:11:42.472073 | 
2025-09-28 00:11:42.472257 | TASK [ensure-docker : Install pre-reqs]
2025-09-28 00:11:47.994928 | controller | ok: Nothing to do
2025-09-28 00:11:48.004450 | 
2025-09-28 00:11:48.004593 | TASK [ensure-docker : Remove packages]
2025-09-28 00:11:51.285922 | controller | ok: Nothing to do
2025-09-28 00:11:51.292424 | 
2025-09-28 00:11:51.292499 | TASK [ensure-docker : Install upstream docker using package]
2025-09-28 00:13:25.329190 | controller | changed
2025-09-28 00:13:25.337335 | 
2025-09-28 00:13:25.337426 | TASK [ensure-docker : Setup docker]
2025-09-28 00:13:25.360404 | controller | ok
2025-09-28 00:13:25.374969 | controller | included: /var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml
2025-09-28 00:13:25.415347 | 
2025-09-28 00:13:25.415472 | TASK [ensure-docker : Ensure "docker" group exists]
2025-09-28 00:13:26.466942 | controller | ok
2025-09-28 00:13:26.472590 | 
2025-09-28 00:13:26.472661 | TASK [ensure-docker : Add user to docker group]
2025-09-28 00:13:27.544787 | controller | changed
2025-09-28 00:13:27.560830 | 
2025-09-28 00:13:27.561072 | TASK [Update docker daemon proxy configuration]
2025-09-28 00:13:27.590818 | controller | skipping: Conditional result was False
2025-09-28 00:13:27.608339 | 
2025-09-28 00:13:27.608723 | TASK [Lower default MTU]
2025-09-28 00:13:27.638395 | controller | skipping: Conditional result was False
2025-09-28 00:13:27.654960 | 
2025-09-28 00:13:27.655272 | TASK [ensure-docker : Get the status of the docket.socket unit]
2025-09-28 00:13:28.586392 | controller | inactive
2025-09-28 00:13:29.032460 | controller | ok: Runtime: 0:00:00.019787
2025-09-28 00:13:29.043295 | 
2025-09-28 00:13:29.043440 | TASK [ensure-docker : Get the status of the docket unit]
2025-09-28 00:13:29.883459 | controller | inactive
2025-09-28 00:13:30.422505 | controller | ok: Runtime: 0:00:00.025589
2025-09-28 00:13:30.437063 | 
2025-09-28 00:13:30.437240 | TASK [ensure-docker : Restart docker]
2025-09-28 00:13:30.493230 | Trigger a Docker restart
2025-09-28 00:13:30.501583 | 
2025-09-28 00:13:30.501688 | TASK [ensure-docker : Reset ssh connection to pick up docker group]
2025-09-28 00:13:30.543662 | 
2025-09-28 00:13:30.543786 | TASK [ensure-docker : Install docker-compose]
2025-09-28 00:13:30.558726 | controller | skipping: Conditional result was False
2025-09-28 00:13:30.568112 | 
2025-09-28 00:13:30.568230 | TASK [ensure-docker : Flush handlers before role exit]
2025-09-28 00:13:30.583572 | 
2025-09-28 00:13:30.583658 | TASK [ensure-docker : Stop docker.socket to avoid any conflict]
2025-09-28 00:13:34.389400 | controller | changed
2025-09-28 00:13:34.396751 | 
2025-09-28 00:13:34.396822 | TASK [ensure-docker : Assure docker service is running]
2025-09-28 00:13:38.707679 | controller | changed
2025-09-28 00:13:38.726329 | 
2025-09-28 00:13:38.726531 | TASK [ensure-docker : Assure docker.socket service is running]
2025-09-28 00:13:40.118011 | controller | ok
2025-09-28 00:13:40.129931 | 
2025-09-28 00:13:40.130060 | TASK [ensure-docker : Correct group ownership on docker sock]
2025-09-28 00:13:40.859957 | controller | ok
2025-09-28 00:13:40.873354 | 
2025-09-28 00:13:40.873508 | TASK [ensure-docker : Validate ability to talk with docker]
2025-09-28 00:13:41.548188 | controller | CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES
2025-09-28 00:13:41.750428 | controller | ok: Runtime: 0:00:00.046108
2025-09-28 00:13:41.764353 | 
2025-09-28 00:13:41.764631 | TASK [ensure-docker : Get version details]
2025-09-28 00:13:42.484316 | controller | Client: Docker Engine - Community
2025-09-28 00:13:42.486049 | controller |  Version:           24.0.7
2025-09-28 00:13:42.486068 | controller |  API version:       1.43
2025-09-28 00:13:42.486075 | controller |  Go version:        go1.20.10
2025-09-28 00:13:42.486092 | controller |  Git commit:        afdd53b
2025-09-28 00:13:42.486100 | controller |  Built:             Thu Oct 26 09:09:39 2023
2025-09-28 00:13:42.486107 | controller |  OS/Arch:           linux/amd64
2025-09-28 00:13:42.486115 | controller |  Context:           default
2025-09-28 00:13:42.486125 | controller |
2025-09-28 00:13:42.486131 | controller | Server: Docker Engine - Community
2025-09-28 00:13:42.486138 | controller |  Engine:
2025-09-28 00:13:42.486144 | controller |   Version:          24.0.7
2025-09-28 00:13:42.486150 | controller |   API version:      1.43 (minimum version 1.12)
2025-09-28 00:13:42.486156 | controller |   Go version:       go1.20.10
2025-09-28 00:13:42.486162 | controller |   Git commit:       311b9ff
2025-09-28 00:13:42.486169 | controller |   Built:            Thu Oct 26 09:08:11 2023
2025-09-28 00:13:42.486176 | controller |   OS/Arch:          linux/amd64
2025-09-28 00:13:42.486182 | controller |   Experimental:     false
2025-09-28 00:13:42.486188 | controller |  containerd:
2025-09-28 00:13:42.486194 | controller |   Version:          1.6.25
2025-09-28 00:13:42.486200 | controller |   GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
2025-09-28 00:13:42.486206 | controller |  runc:
2025-09-28 00:13:42.486212 | controller |   Version:          1.1.10
2025-09-28 00:13:42.486218 | controller |   GitCommit:        v1.1.10-0-g18a0cb0
2025-09-28 00:13:42.486229 | controller |  docker-init:
2025-09-28 00:13:42.486245 | controller |   Version:          0.19.0
2025-09-28 00:13:42.486251 | controller |   GitCommit:        de40ad0
2025-09-28 00:13:42.676620 | controller | ok: Runtime: 0:00:00.045128
2025-09-28 00:13:42.690317 | 
2025-09-28 00:13:42.690484 | TASK [ensure-docker : Dump installed docker details]
2025-09-28 00:13:42.721437 | {'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-28 00:13:42.441485', 'end': '2025-09-28 00:13:42.486613', 'delta': '0:00:00.045128', 'msg': '', 'zuul_log_id': 'fa163ec2-ffbe-1c84-f927-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-28 00:13:42.736901 | 
2025-09-28 00:13:42.737082 | TASK [Use buildset registry]
2025-09-28 00:13:42.763240 | controller | skipping: Conditional result was False
2025-09-28 00:13:42.779531 | 
2025-09-28 00:13:42.779657 | TASK [Ensure python3.8 is present]
2025-09-28 00:13:42.804604 | controller | skipping: Conditional result was False
2025-09-28 00:13:42.814192 | 
2025-09-28 00:13:42.814316 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-09-28 00:13:42.838984 | controller | ok
2025-09-28 00:13:42.869708 | 
2025-09-28 00:13:42.869838 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-09-28 00:13:49.323227 | controller | ok: Nothing to do
2025-09-28 00:13:49.336594 | 
2025-09-28 00:13:49.336752 | TASK [our-ensure-python : Also install python3-devel]
2025-09-28 00:14:09.212408 | controller | changed
2025-09-28 00:14:09.226632 | 
2025-09-28 00:14:09.226743 | TASK [Run ensure-virtualenv role]
2025-09-28 00:14:09.249766 | controller | ok
2025-09-28 00:14:09.276253 | 
2025-09-28 00:14:09.276348 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-09-28 00:14:10.038676 | controller | /usr/bin/virtualenv
2025-09-28 00:14:10.631650 | controller | ok: Runtime: 0:00:00.005781
2025-09-28 00:14:10.644398 | 
2025-09-28 00:14:10.644565 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-09-28 00:14:10.681932 | controller | skipping: Conditional result was False
2025-09-28 00:14:10.682472 | controller | changed: All items complete
2025-09-28 00:14:10.682533 | 
2025-09-28 00:14:10.757842 | 
2025-09-28 00:14:10.758004 | TASK [Find the full path of the Python interpreter]
2025-09-28 00:14:11.601513 | controller | /usr/bin/python3.8
2025-09-28 00:14:12.115882 | controller | ok
2025-09-28 00:14:12.129517 | 
2025-09-28 00:14:12.129806 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-09-28 00:14:14.428451 | controller | created virtual environment CPython3.8.18.final.0-64 in 1246ms
2025-09-28 00:14:14.483866 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-09-28 00:14:14.483921 | 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-28 00:14:14.483936 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-09-28 00:14:14.483956 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-09-28 00:14:15.037463 | controller | changed
2025-09-28 00:14:15.051151 | 
2025-09-28 00:14:15.051329 | TASK [Set selinux package]
2025-09-28 00:14:15.085844 | controller | ok
2025-09-28 00:14:15.098473 | 
2025-09-28 00:14:15.098614 | TASK [Set selinux package (Fedora)]
2025-09-28 00:14:15.136721 | controller | ok
2025-09-28 00:14:15.144583 | 
2025-09-28 00:14:15.144671 | TASK [Install selinux into virtualenv]
2025-09-28 00:14:20.761102 | controller | Collecting selinux-please-lie-to-me
2025-09-28 00:14:20.853128 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-09-28 00:14:22.242317 | controller | Collecting setuptools<50.0.0
2025-09-28 00:14:22.249706 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-09-28 00:14:22.301175 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 19.5 MB/s eta 0:00:00
2025-09-28 00:14:22.453941 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-09-28 00:14:22.454311 | controller |   Attempting uninstall: setuptools
2025-09-28 00:14:22.455536 | controller |     Found existing installation: setuptools 62.6.0
2025-09-28 00:14:22.607272 | controller |     Uninstalling setuptools-62.6.0:
2025-09-28 00:14:22.627586 | controller |       Successfully uninstalled setuptools-62.6.0
2025-09-28 00:14:23.489844 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-09-28 00:14:23.700797 | controller |
2025-09-28 00:14:24.000213 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-09-28 00:14:24.000268 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-09-28 00:14:24.525610 | controller | ok: Runtime: 0:00:07.334025
2025-09-28 00:14:24.538328 | 
2025-09-28 00:14:24.538483 | TASK [Install pytest-forked into virtualenv]
2025-09-28 00:14:26.220835 | controller | Collecting pytest-forked
2025-09-28 00:14:26.310618 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-09-28 00:14:26.415393 | controller | Collecting py
2025-09-28 00:14:26.426453 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-09-28 00:14:26.464064 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.5 MB/s eta 0:00:00
2025-09-28 00:14:26.690745 | controller | Collecting pytest>=3.10
2025-09-28 00:14:26.698427 | controller |   Downloading pytest-8.3.5-py3-none-any.whl (343 kB)
2025-09-28 00:14:26.743457 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 343.6/343.6 kB 8.8 MB/s eta 0:00:00
2025-09-28 00:14:26.841905 | controller | Collecting tomli>=1
2025-09-28 00:14:26.848864 | controller |   Downloading tomli-2.2.1-py3-none-any.whl (14 kB)
2025-09-28 00:14:26.943388 | controller | Collecting packaging
2025-09-28 00:14:26.950265 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-09-28 00:14:26.964845 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 5.2 MB/s eta 0:00:00
2025-09-28 00:14:26.996425 | controller | Collecting iniconfig
2025-09-28 00:14:27.003347 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-09-28 00:14:27.075891 | controller | Collecting pluggy<2,>=1.5
2025-09-28 00:14:27.082973 | controller |   Downloading pluggy-1.5.0-py3-none-any.whl (20 kB)
2025-09-28 00:14:27.142850 | controller | Collecting exceptiongroup>=1.0.0rc8
2025-09-28 00:14:27.150138 | controller |   Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB)
2025-09-28 00:14:27.267130 | controller | Collecting typing-extensions>=4.6.0
2025-09-28 00:14:27.275038 | controller |   Downloading typing_extensions-4.13.2-py3-none-any.whl (45 kB)
2025-09-28 00:14:27.287750 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 3.9 MB/s eta 0:00:00
2025-09-28 00:14:27.431395 | controller | Installing collected packages: typing-extensions, tomli, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked
2025-09-28 00:14:28.555134 | 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-28 00:14:28.569072 | controller |
2025-09-28 00:14:28.832447 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-09-28 00:14:28.832498 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-09-28 00:14:29.428933 | controller | ok: Runtime: 0:00:03.464350
2025-09-28 00:14:29.441794 | 
2025-09-28 00:14:29.442185 | TASK [Update pip]
2025-09-28 00:14:31.651472 | controller | Requirement already satisfied: pip in ./venv/lib/python3.8/site-packages (22.2.2)
2025-09-28 00:14:32.144524 | controller | Collecting pip
2025-09-28 00:14:32.213263 | controller |   Downloading pip-25.0.1-py3-none-any.whl (1.8 MB)
2025-09-28 00:14:32.303315 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 22.7 MB/s eta 0:00:00
2025-09-28 00:14:32.435652 | controller | Installing collected packages: pip
2025-09-28 00:14:32.435885 | controller |   Attempting uninstall: pip
2025-09-28 00:14:32.436980 | controller |     Found existing installation: pip 22.2.2
2025-09-28 00:14:33.019118 | controller |     Uninstalling pip-22.2.2:
2025-09-28 00:14:33.093597 | controller |       Successfully uninstalled pip-22.2.2
2025-09-28 00:14:35.731162 | controller | Successfully installed pip-25.0.1
2025-09-28 00:14:36.348279 | controller | ok: Runtime: 0:00:05.616810
2025-09-28 00:14:36.361723 | 
2025-09-28 00:14:36.361899 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-09-28 00:14:37.471557 | controller | changed
2025-09-28 00:14:37.489784 | 
2025-09-28 00:14:37.490002 | TASK [Install ansible into virtualenv]
2025-09-28 00:14:39.589296 | controller | Processing ./src/github.com/ansible/ansible
2025-09-28 00:14:39.594309 | controller |   Preparing metadata (setup.py): started
2025-09-28 00:14:40.516858 | controller |   Preparing metadata (setup.py): finished with status 'done'
2025-09-28 00:14:40.578851 | controller | Collecting jinja2 (from ansible-base==2.10.17.post0)
2025-09-28 00:14:40.592728 | controller |   Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB)
2025-09-28 00:14:40.692122 | controller | Collecting PyYAML (from ansible-base==2.10.17.post0)
2025-09-28 00:14:40.698253 | controller |   Downloading pyyaml-6.0.3.tar.gz (130 kB)
2025-09-28 00:14:41.067634 | controller |   Installing build dependencies: started
2025-09-28 00:14:46.962870 | controller |   Installing build dependencies: finished with status 'done'
2025-09-28 00:14:46.964242 | controller |   Getting requirements to build wheel: started
2025-09-28 00:14:49.218445 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-09-28 00:14:49.220372 | controller |   Preparing metadata (pyproject.toml): started
2025-09-28 00:14:49.772992 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-09-28 00:14:50.197887 | controller | Collecting cryptography (from ansible-base==2.10.17.post0)
2025-09-28 00:14:50.205438 | controller |   Downloading cryptography-46.0.1-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB)
2025-09-28 00:14:50.231453 | controller | Requirement already satisfied: packaging in ./venv/lib/python3.8/site-packages (from ansible-base==2.10.17.post0) (25.0)
2025-09-28 00:14:50.488570 | controller | Collecting cffi>=1.14 (from cryptography->ansible-base==2.10.17.post0)
2025-09-28 00:14:50.495469 | controller |   Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (1.5 kB)
2025-09-28 00:14:50.507974 | 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-28 00:14:50.632471 | controller | Collecting MarkupSafe>=2.0 (from jinja2->ansible-base==2.10.17.post0)
2025-09-28 00:14:50.639476 | controller |   Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB)
2025-09-28 00:14:50.677043 | controller | Collecting pycparser (from cffi>=1.14->cryptography->ansible-base==2.10.17.post0)
2025-09-28 00:14:50.683052 | controller |   Downloading pycparser-2.23-py3-none-any.whl.metadata (993 bytes)
2025-09-28 00:14:50.709676 | controller | Downloading cryptography-46.0.1-cp38-abi3-manylinux_2_34_x86_64.whl (4.6 MB)
2025-09-28 00:14:50.774348 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.6/4.6 MB 77.5 MB/s eta 0:00:00
2025-09-28 00:14:50.781916 | controller | Downloading jinja2-3.1.6-py3-none-any.whl (134 kB)
2025-09-28 00:14:50.805183 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB)
2025-09-28 00:14:50.835348 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (26 kB)
2025-09-28 00:14:50.849153 | controller | Downloading pycparser-2.23-py3-none-any.whl (118 kB)
2025-09-28 00:14:50.880408 | controller | Building wheels for collected packages: ansible-base, PyYAML
2025-09-28 00:14:50.881407 | controller |   Building wheel for ansible-base (setup.py): started
2025-09-28 00:14:53.110999 | controller |   Building wheel for ansible-base (setup.py): finished with status 'done'
2025-09-28 00:14:53.116266 | controller |   Created wheel for ansible-base: filename=ansible_base-2.10.17.post0-py3-none-any.whl size=1881569 sha256=cbea57287e7b4deb98d27507c856976768c66f978ee3b4cc0adc3d0ee7f77f70
2025-09-28 00:14:53.136936 | controller |   Stored in directory: /var/tmp/ansible-test-pip/pip-ephem-wheel-cache-771k_kgk/wheels/a5/4b/fa/b6deaae105422b0b3b92831e0369d44bf7fca5bb3413d79be7
2025-09-28 00:14:53.136987 | controller |   Building wheel for PyYAML (pyproject.toml): started
2025-09-28 00:14:53.983304 | controller |   Building wheel for PyYAML (pyproject.toml): finished with status 'done'
2025-09-28 00:14:53.984945 | controller |   Created wheel for PyYAML: filename=PyYAML-6.0.3-cp38-cp38-linux_x86_64.whl size=45364 sha256=b4ec64c333ae1cee11bdd260baaf9df00fefe2508e66bf892fbc956bf8e20f8c
2025-09-28 00:14:53.985262 | controller |   Stored in directory: /home/zuul/.cache/pip/wheels/60/9b/bc/8c54c7c157a008210f4d6ddfce9e9c5274162b18c5832f8e24
2025-09-28 00:14:53.990080 | controller | Successfully built ansible-base PyYAML
2025-09-28 00:14:54.055413 | controller | Installing collected packages: PyYAML, pycparser, MarkupSafe, jinja2, cffi, cryptography, ansible-base
2025-09-28 00:14:57.069947 | controller | Successfully installed MarkupSafe-2.1.5 PyYAML-6.0.3 ansible-base-2.10.17.post0 cffi-1.17.1 cryptography-46.0.1 jinja2-3.1.6 pycparser-2.23
2025-09-28 00:14:57.875232 | controller | ok: Runtime: 0:00:19.056271
2025-09-28 00:14:57.888301 | 
2025-09-28 00:14:57.888591 | TASK [Setup download-artifact-fork role]
2025-09-28 00:14:57.927746 | controller | ok
2025-09-28 00:14:57.984976 | 
2025-09-28 00:14:57.985319 | TASK [download-artifact-fork : Parse inventory response]
2025-09-28 00:14:58.051569 | controller | ok
2025-09-28 00:14:58.067239 | 
2025-09-28 00:14:58.067435 | TASK [download-artifact-fork : Fetch info from Zuul API]
2025-09-28 00:14:58.106586 | controller | skipping: Conditional result was False
2025-09-28 00:14:58.117509 | 
2025-09-28 00:14:58.117627 | TASK [download-artifact-fork : Parse build response]
2025-09-28 00:14:58.155424 | controller | skipping: Conditional result was False
2025-09-28 00:14:58.165551 | 
2025-09-28 00:14:58.165651 | TASK [download-artifact-fork : Ensure artifacts directory exists]
2025-09-28 00:14:59.055323 | controller | changed
2025-09-28 00:14:59.070646 | 
2025-09-28 00:14:59.070851 | LOOP [download-artifact-fork : Download archive by type]
2025-09-28 00:14:59.109900 | controller | skipping: Conditional result was False
2025-09-28 00:14:59.110388 | 
2025-09-28 00:15:01.525515 | controller | changed: OK (20214 bytes)
2025-09-28 00:15:01.564625 | 
2025-09-28 00:15:01.564915 | TASK [deploy-artifacts : define __collections]
2025-09-28 00:15:01.598437 | controller | ok
2025-09-28 00:15:01.613756 | 
2025-09-28 00:15:01.614010 | LOOP [deploy-artifacts : Create list of collections]
2025-09-28 00:15:01.643786 | controller | skipping: Conditional result was False
2025-09-28 00:15:01.654914 | controller | ok:
2025-09-28 00:15:01.655007 | controller | {
2025-09-28 00:15:01.655073 | controller |   "branch": "main",
2025-09-28 00:15:01.655109 | controller |   "job": "build-ansible-collection",
2025-09-28 00:15:01.655138 | controller |   "metadata": {
2025-09-28 00:15:01.655165 | controller |     "type": "ansible_collection",
2025-09-28 00:15:01.655191 | controller |     "version": "5.0.0"
2025-09-28 00:15:01.655217 | controller |   },
2025-09-28 00:15:01.655242 | controller |   "name": "ansible.network",
2025-09-28 00:15:01.655267 | controller |   "project": "ansible-collections/ansible.network",
2025-09-28 00:15:01.655347 | controller |   "url": "https://3942cfc17c443ac7d082-fd029069d88de500c01373b7478d9381.ssl.cf2.rackcdn.com/ansible/6ae644ab2b644bac8f712010bf44f0ae/artifacts/ansible-network-5.0.0.tar.gz"
2025-09-28 00:15:01.655398 | controller | }
2025-09-28 00:15:01.671405 | 
2025-09-28 00:15:01.671653 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy]
2025-09-28 00:15:06.623920 | controller | Starting galaxy collection install process
2025-09-28 00:15:06.624345 | controller | Process install dependency map
2025-09-28 00:15:22.193619 | controller | Starting collection install process
2025-09-28 00:15:22.193832 | controller | Installing 'ansible.network:5.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/network'
2025-09-28 00:15:22.211086 | controller | ansible.network (5.0.0) was installed successfully
2025-09-28 00:15:22.211234 | controller | Installing 'ansible.netcommon:8.1.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2025-09-28 00:15:22.211434 | 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-4029yoe_vs7s/tmp691hfqv4
2025-09-28 00:15:23.781743 | controller | ansible.netcommon (8.1.0) was installed successfully
2025-09-28 00:15:23.781886 | controller | Installing 'ansible.utils:6.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/utils'
2025-09-28 00:15:23.782083 | 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-4029yoe_vs7s/tmp691hfqv4
2025-09-28 00:15:25.841849 | controller | ansible.utils (6.0.0) was installed successfully
2025-09-28 00:15:25.841990 | controller | Installing 'arista.eos:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/arista/eos'
2025-09-28 00:15:25.842288 | 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-4029yoe_vs7s/tmp691hfqv4
2025-09-28 00:15:28.572101 | controller | arista.eos (12.0.0) was installed successfully
2025-09-28 00:15:28.572152 | controller | Installing 'cisco.ios:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/ios'
2025-09-28 00:15:28.572435 | 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-4029yoe_vs7s/tmp691hfqv4
2025-09-28 00:15:31.845688 | controller | cisco.ios (11.0.0) was installed successfully
2025-09-28 00:15:31.845884 | controller | Installing 'cisco.iosxr:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/iosxr'
2025-09-28 00:15:31.846458 | 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-4029yoe_vs7s/tmp691hfqv4
2025-09-28 00:15:34.495462 | controller | cisco.iosxr (12.0.0) was installed successfully
2025-09-28 00:15:34.495583 | controller | Installing 'cisco.nxos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/nxos'
2025-09-28 00:15:34.496950 | 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-4029yoe_vs7s/tmp691hfqv4
2025-09-28 00:15:38.517719 | controller | cisco.nxos (11.0.0) was installed successfully
2025-09-28 00:15:38.517897 | controller | Installing 'junipernetworks.junos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/junipernetworks/junos'
2025-09-28 00:15:38.518280 | 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-4029yoe_vs7s/tmp691hfqv4
2025-09-28 00:15:41.291063 | controller | junipernetworks.junos (11.0.0) was installed successfully
2025-09-28 00:15:41.581500 | controller | ok: Runtime: 0:00:38.854769
2025-09-28 00:15:41.604865 | 
2025-09-28 00:15:41.605004 | TASK [podman may need iptables kernel modules]
2025-09-28 00:15:42.981949 | controller | ok: Runtime: 0:00:00.007971
2025-09-28 00:15:43.028096 | 
2025-09-28 00:15:43.028243 | PLAY RECAP
2025-09-28 00:15:43.028323 | controller | ok: 46 changed: 26 unreachable: 0 failed: 0 skipped: 17 rescued: 0 ignored: 0
2025-09-28 00:15:43.028368 | 
2025-09-28 00:15:43.179988 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-09-28 00:15:43.182686 | RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-09-28 00:15:43.866454 | 
2025-09-28 00:15:43.866589 | PLAY [controller]
2025-09-28 00:15:43.890716 | 
2025-09-28 00:15:43.890819 | TASK [Copy the galaxy.yml on the controller]
2025-09-28 00:15:47.750641 | controller | changed
2025-09-28 00:15:47.759754 | 
2025-09-28 00:15:47.759921 | TASK [Load information from galaxy.yml]
2025-09-28 00:15:47.795820 | controller | ok
2025-09-28 00:15:47.805824 | 
2025-09-28 00:15:47.805970 | LOOP [Enable FIPS mode]
2025-09-28 00:15:47.832003 | 
2025-09-28 00:15:47.835066 | LOOP [ansible-test : Include branch specific variables.]
2025-09-28 00:15:47.889947 | controller | ok: "/var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/untrusted/project_2/github.com/ansible/ansible-zuul-jobs/roles/ansible-test/vars/default.yaml"
2025-09-28 00:15:47.890118 | 
2025-09-28 00:15:47.898088 | 
2025-09-28 00:15:47.898222 | TASK [ansible-test : Setup --skip-tags for test_options]
2025-09-28 00:15:47.929511 | controller | ok
2025-09-28 00:15:47.938621 | 
2025-09-28 00:15:47.938727 | TASK [ansible-test : Enable --inventory for network-integration]
2025-09-28 00:15:47.963163 | controller | skipping: Conditional result was False
2025-09-28 00:15:47.971232 | 
2025-09-28 00:15:47.971388 | TASK [ansible-test : Enable --retry-on-error]
2025-09-28 00:15:47.985734 | controller | skipping: Conditional result was False
2025-09-28 00:15:47.993630 | 
2025-09-28 00:15:47.993738 | TASK [ansible-test : Enable --continue-on-error]
2025-09-28 00:15:48.026510 | controller | ok
2025-09-28 00:15:48.032050 | 
2025-09-28 00:15:48.032115 | TASK [ansible-test : Enable --requirements]
2025-09-28 00:15:48.055988 | controller | skipping: Conditional result was False
2025-09-28 00:15:48.062795 | 
2025-09-28 00:15:48.062866 | TASK [ansible-test : Adjust options for unit tests]
2025-09-28 00:15:48.087331 | controller | skipping: Conditional result was False
2025-09-28 00:15:48.093985 | 
2025-09-28 00:15:48.094068 | TASK [ansible-test : Install requirements with unit tests]
2025-09-28 00:15:48.151916 | controller | ok
2025-09-28 00:15:48.157661 | 
2025-09-28 00:15:48.157731 | TASK [ansible-test : Set --skip-test]
2025-09-28 00:15:48.202281 | controller | skipping: Conditional result was False
2025-09-28 00:15:48.208732 | 
2025-09-28 00:15:48.208832 | TASK [ansible-test : Reduce verbosity]
2025-09-28 00:15:48.238055 | controller | ok
2025-09-28 00:15:48.243434 | 
2025-09-28 00:15:48.243498 | TASK [ansible-test : Setup --python option]
2025-09-28 00:15:48.267035 | controller | skipping: Conditional result was False
2025-09-28 00:15:48.273257 | 
2025-09-28 00:15:48.273324 | TASK [ansible-test : Setup --docker option]
2025-09-28 00:15:48.312509 | controller | ok
2025-09-28 00:15:48.319268 | 
2025-09-28 00:15:48.319333 | TASK [ansible-test : check if MANIFEST.json exists]
2025-09-28 00:15:49.394177 | controller | ok
2025-09-28 00:15:49.408111 | 
2025-09-28 00:15:49.408262 | TASK [ansible-test : Copy the MANIFEST.json on the controller]
2025-09-28 00:15:49.435639 | controller | skipping: Conditional result was False
2025-09-28 00:15:49.451083 | 
2025-09-28 00:15:49.451225 | TASK [ansible-test : Load information from MANIFEST.json]
2025-09-28 00:15:49.478635 | controller | skipping: Conditional result was False
2025-09-28 00:15:49.497214 | 
2025-09-28 00:15:49.497439 | TASK [ansible-test : Setup location of project for integration tests]
2025-09-28 00:15:49.524191 | controller | skipping: Conditional result was False
2025-09-28 00:15:49.538399 | 
2025-09-28 00:15:49.538560 | TASK [ansible-test : Copy the galaxy.yml on the controller]
2025-09-28 00:15:51.035339 | controller | ok
2025-09-28 00:15:51.047479 | 
2025-09-28 00:15:51.047612 | TASK [ansible-test : Load information from galaxy.yml]
2025-09-28 00:15:51.111602 | controller | ok
2025-09-28 00:15:51.124197 | 
2025-09-28 00:15:51.124375 | TASK [ansible-test : Setup location of project for integration tests]
2025-09-28 00:15:51.167797 | controller | ok
2025-09-28 00:15:51.175480 | 
2025-09-28 00:15:51.175567 | TASK [ansible-test : Setup minimum test requirements]
2025-09-28 00:15:51.215799 | controller | ok
2025-09-28 00:15:51.221572 | 
2025-09-28 00:15:51.221639 | TASK [ansible-test : Ensure pip temp directory exists in /var/tmp]
2025-09-28 00:15:52.219349 | controller | ok
2025-09-28 00:15:52.232974 | 
2025-09-28 00:15:52.233144 | TASK [ansible-test : Install python requirements]
2025-09-28 00:15:53.805437 | controller | Collecting yamllint (from -r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-09-28 00:15:54.126111 | controller |   Downloading yamllint-1.35.1-py3-none-any.whl.metadata (4.2 kB)
2025-09-28 00:15:54.173187 | controller | Collecting pathspec>=0.5.3 (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-09-28 00:15:54.179993 | controller |   Downloading pathspec-0.12.1-py3-none-any.whl.metadata (21 kB)
2025-09-28 00:15:54.191844 | 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.3)
2025-09-28 00:15:54.201262 | controller | Downloading yamllint-1.35.1-py3-none-any.whl (66 kB)
2025-09-28 00:15:54.218524 | controller | Downloading pathspec-0.12.1-py3-none-any.whl (31 kB)
2025-09-28 00:15:54.288052 | controller | Installing collected packages: pathspec, yamllint
2025-09-28 00:15:54.400674 | controller | Successfully installed pathspec-0.12.1 yamllint-1.35.1
2025-09-28 00:15:55.104935 | controller | ok: Runtime: 0:00:01.390028
2025-09-28 00:15:55.114159 | 
2025-09-28 00:15:55.114248 | TASK [ansible-test : Copy potential cloud provider configuration for ansible-test in the collection]
2025-09-28 00:15:55.476810 | controller | skipping: Conditional result was False
2025-09-28 00:15:55.486552 | 
2025-09-28 00:15:55.486915 | TASK [ansible-test : Enable persistent connection logging]
2025-09-28 00:15:56.673580 | controller | changed: section and option added
2025-09-28 00:15:56.679373 | 
2025-09-28 00:15:56.679455 | TASK [ansible-test : Set persistent ssh_type value]
2025-09-28 00:15:57.770062 | controller | changed: option added
2025-09-28 00:15:57.784193 | 
2025-09-28 00:15:57.784368 | TASK [ansible-test : Set ansible log path]
2025-09-28 00:15:58.846242 | controller | changed: section and option added
2025-09-28 00:15:58.854302 | 
2025-09-28 00:15:58.854406 | TASK [ansible-test : Identify the changed targets]
2025-09-28 00:15:59.223201 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.237348 | 
2025-09-28 00:15:59.237528 | TASK [ansible-test : set_fact]
2025-09-28 00:15:59.284836 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.298241 | 
2025-09-28 00:15:59.298425 | TASK [ansible-test : Set the targets]
2025-09-28 00:15:59.332372 | controller | ok
2025-09-28 00:15:59.340195 | 
2025-09-28 00:15:59.340339 | TASK [ansible-test : set_fact]
2025-09-28 00:15:59.365592 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.375833 | 
2025-09-28 00:15:59.375997 | TASK [ansible-test : List the targets]
2025-09-28 00:15:59.749771 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.763659 | 
2025-09-28 00:15:59.763822 | TASK [ansible-test : set_fact]
2025-09-28 00:15:59.780804 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.832453 | 
2025-09-28 00:15:59.832591 | TASK [ansible-test : set_fact]
2025-09-28 00:15:59.848151 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.857944 | 
2025-09-28 00:15:59.858094 | LOOP [ansible-test : set_fact]
2025-09-28 00:15:59.924306 | 
2025-09-28 00:15:59.924510 | TASK [ansible-test : set_fact]
2025-09-28 00:15:59.939785 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.951056 | 
2025-09-28 00:15:59.951181 | TASK [ansible-test : debug]
2025-09-28 00:15:59.966486 | controller | skipping: Conditional result was False
2025-09-28 00:15:59.975830 | 
2025-09-28 00:15:59.975937 | TASK [ansible-test : debug]
2025-09-28 00:16:00.009811 | About to run: ansible-test sanity --requirements --docker -v
2025-09-28 00:16:00.020127 | 
2025-09-28 00:16:00.020254 | TASK [ansible-test : Run the test suite]
2025-09-28 00:16:01.481045 | controller | Run command: docker images quay.io/ansible/default-test-container:2.9.0 --format '{{json .}}'
2025-09-28 00:16:01.521135 | controller | Run command: docker pull quay.io/ansible/default-test-container:2.9.0
2025-09-28 00:16:03.241678 | controller | 2.9.0: Pulling from ansible/default-test-container
2025-09-28 00:16:03.600378 | controller | 171857c49d0f: Pulling fs layer
2025-09-28 00:16:03.600447 | controller | 419640447d26: Pulling fs layer
2025-09-28 00:16:03.600456 | controller | 61e52f862619: Pulling fs layer
2025-09-28 00:16:03.600463 | controller | 851de0426e26: Pulling fs layer
2025-09-28 00:16:03.600473 | controller | 37425716ea5b: Pulling fs layer
2025-09-28 00:16:03.600484 | controller | cd9b0c439616: Pulling fs layer
2025-09-28 00:16:03.600490 | controller | d4612dbd8855: Pulling fs layer
2025-09-28 00:16:03.600497 | controller | 554699364730: Pulling fs layer
2025-09-28 00:16:03.600503 | controller | 1ff15d4bdb3e: Pulling fs layer
2025-09-28 00:16:03.600509 | controller | 5f2e4724adea: Pulling fs layer
2025-09-28 00:16:03.600515 | controller | a02d9a95ccb8: Pulling fs layer
2025-09-28 00:16:03.600521 | controller | 989f4ce370cb: Pulling fs layer
2025-09-28 00:16:03.600527 | controller | 0d7f52cdf9df: Pulling fs layer
2025-09-28 00:16:03.600533 | controller | c423742351d5: Pulling fs layer
2025-09-28 00:16:03.600539 | controller | 109236341d21: Pulling fs layer
2025-09-28 00:16:03.600546 | controller | 07a2f61c96b8: Pulling fs layer
2025-09-28 00:16:03.600552 | controller | 041f122f27ae: Pulling fs layer
2025-09-28 00:16:03.600558 | controller | ca6f5098b12e: Pulling fs layer
2025-09-28 00:16:03.600564 | controller | 1eb3e7b2afd9: Pulling fs layer
2025-09-28 00:16:03.600570 | controller | 18a0b750727a: Pulling fs layer
2025-09-28 00:16:03.600577 | controller | 17f2f596716c: Pulling fs layer
2025-09-28 00:16:03.600587 | controller | f35a9998a9bd: Pulling fs layer
2025-09-28 00:16:03.600593 | controller | fdfc10566405: Pulling fs layer
2025-09-28 00:16:03.600599 | controller | 1ff1c442c5fe: Pulling fs layer
2025-09-28 00:16:03.600606 | controller | a3443c4a17ed: Pulling fs layer
2025-09-28 00:16:03.600612 | controller | 0edcf9fb2b15: Pulling fs layer
2025-09-28 00:16:03.600618 | controller | 5af43b69e845: Pulling fs layer
2025-09-28 00:16:03.600625 | controller | 1651773effb2: Pulling fs layer
2025-09-28 00:16:03.600631 | controller | 79e23c5c0fe4: Pulling fs layer
2025-09-28 00:16:03.600640 | controller | e5058b1faaa6: Pulling fs layer
2025-09-28 00:16:03.600647 | controller | 851de0426e26: Waiting
2025-09-28 00:16:03.600654 | controller | 37425716ea5b: Waiting
2025-09-28 00:16:03.600660 | controller | cd9b0c439616: Waiting
2025-09-28 00:16:03.600666 | controller | d4612dbd8855: Waiting
2025-09-28 00:16:03.600673 | controller | 554699364730: Waiting
2025-09-28 00:16:03.600679 | controller | 1ff15d4bdb3e: Waiting
2025-09-28 00:16:03.600685 | controller | 5f2e4724adea: Waiting
2025-09-28 00:16:03.600694 | controller | a02d9a95ccb8: Waiting
2025-09-28 00:16:03.600701 | controller | 989f4ce370cb: Waiting
2025-09-28 00:16:03.600707 | controller | 0d7f52cdf9df: Waiting
2025-09-28 00:16:03.600713 | controller | c423742351d5: Waiting
2025-09-28 00:16:03.600720 | controller | 109236341d21: Waiting
2025-09-28 00:16:03.600726 | controller | 07a2f61c96b8: Waiting
2025-09-28 00:16:03.600732 | controller | 041f122f27ae: Waiting
2025-09-28 00:16:03.600738 | controller | ca6f5098b12e: Waiting
2025-09-28 00:16:03.600745 | controller | 1eb3e7b2afd9: Waiting
2025-09-28 00:16:03.600751 | controller | 18a0b750727a: Waiting
2025-09-28 00:16:03.600757 | controller | 17f2f596716c: Waiting
2025-09-28 00:16:03.600764 | controller | f35a9998a9bd: Waiting
2025-09-28 00:16:03.600790 | controller | fdfc10566405: Waiting
2025-09-28 00:16:03.600797 | controller | 1ff1c442c5fe: Waiting
2025-09-28 00:16:03.600803 | controller | a3443c4a17ed: Waiting
2025-09-28 00:16:03.600810 | controller | 0edcf9fb2b15: Waiting
2025-09-28 00:16:03.600816 | controller | 5af43b69e845: Waiting
2025-09-28 00:16:03.600822 | controller | 1651773effb2: Waiting
2025-09-28 00:16:03.600828 | controller | 79e23c5c0fe4: Waiting
2025-09-28 00:16:03.600835 | controller | 846775490569: Pulling fs layer
2025-09-28 00:16:03.600841 | controller | e5058b1faaa6: Waiting
2025-09-28 00:16:03.600847 | controller | 846775490569: Waiting
2025-09-28 00:16:03.600865 | controller | 61e52f862619: Verifying Checksum
2025-09-28 00:16:03.685976 | controller | 61e52f862619: Download complete
2025-09-28 00:16:03.686041 | controller | 419640447d26: Verifying Checksum
2025-09-28 00:16:03.911708 | controller | 419640447d26: Download complete
2025-09-28 00:16:03.911785 | controller | 171857c49d0f: Verifying Checksum
2025-09-28 00:16:04.350719 | controller | 171857c49d0f: Download complete
2025-09-28 00:16:04.350802 | controller | cd9b0c439616: Verifying Checksum
2025-09-28 00:16:04.668322 | controller | cd9b0c439616: Download complete
2025-09-28 00:16:04.668381 | controller | 851de0426e26: Verifying Checksum
2025-09-28 00:16:05.370503 | controller | 851de0426e26: Download complete
2025-09-28 00:16:05.370736 | controller | d4612dbd8855: Verifying Checksum
2025-09-28 00:16:06.524311 | controller | d4612dbd8855: Download complete
2025-09-28 00:16:06.524371 | controller | 1ff15d4bdb3e: Verifying Checksum
2025-09-28 00:16:07.655994 | controller | 1ff15d4bdb3e: Download complete
2025-09-28 00:16:07.656052 | controller | 5f2e4724adea: Verifying Checksum
2025-09-28 00:16:07.656266 | controller | 5f2e4724adea: Download complete
2025-09-28 00:16:09.594295 | controller | a02d9a95ccb8: Verifying Checksum
2025-09-28 00:16:09.931306 | controller | a02d9a95ccb8: Download complete
2025-09-28 00:16:09.931369 | controller | 171857c49d0f: Pull complete
2025-09-28 00:16:09.979668 | controller | 554699364730: Verifying Checksum
2025-09-28 00:16:09.979714 | controller | 554699364730: Download complete
2025-09-28 00:16:09.990858 | controller | 419640447d26: Pull complete
2025-09-28 00:16:10.025873 | controller | 61e52f862619: Pull complete
2025-09-28 00:16:10.064641 | controller | 851de0426e26: Pull complete
2025-09-28 00:16:10.650275 | controller | 989f4ce370cb: Verifying Checksum
2025-09-28 00:16:10.971398 | controller | 989f4ce370cb: Download complete
2025-09-28 00:16:10.971473 | controller | 0d7f52cdf9df: Verifying Checksum
2025-09-28 00:16:11.620254 | controller | 0d7f52cdf9df: Download complete
2025-09-28 00:16:11.620318 | controller | c423742351d5: Verifying Checksum
2025-09-28 00:16:12.612947 | controller | c423742351d5: Download complete
2025-09-28 00:16:12.613013 | controller | 109236341d21: Verifying Checksum
2025-09-28 00:16:12.653925 | controller | 109236341d21: Download complete
2025-09-28 00:16:12.653988 | controller | 07a2f61c96b8: Verifying Checksum
2025-09-28 00:16:13.821515 | controller | 07a2f61c96b8: Download complete
2025-09-28 00:16:13.821580 | controller | 041f122f27ae: Verifying Checksum
2025-09-28 00:16:13.824707 | controller | 041f122f27ae: Download complete
2025-09-28 00:16:13.872468 | controller | ca6f5098b12e: Verifying Checksum
2025-09-28 00:16:14.721268 | controller | ca6f5098b12e: Download complete
2025-09-28 00:16:14.721327 | controller | 1eb3e7b2afd9: Verifying Checksum
2025-09-28 00:16:15.659326 | controller | 1eb3e7b2afd9: Download complete
2025-09-28 00:16:15.659383 | controller | 17f2f596716c: Verifying Checksum
2025-09-28 00:16:15.785073 | controller | 17f2f596716c: Download complete
2025-09-28 00:16:15.785140 | controller | 18a0b750727a: Verifying Checksum
2025-09-28 00:16:16.592885 | controller | 18a0b750727a: Download complete
2025-09-28 00:16:16.592947 | controller | f35a9998a9bd: Verifying Checksum
2025-09-28 00:16:16.620039 | controller | f35a9998a9bd: Download complete
2025-09-28 00:16:16.620102 | controller | fdfc10566405: Verifying Checksum
2025-09-28 00:16:17.679829 | controller | fdfc10566405: Download complete
2025-09-28 00:16:17.679889 | controller | 1ff1c442c5fe: Verifying Checksum
2025-09-28 00:16:18.466901 | controller | 1ff1c442c5fe: Download complete
2025-09-28 00:16:18.466960 | controller | a3443c4a17ed: Verifying Checksum
2025-09-28 00:16:24.017934 | controller | a3443c4a17ed: Download complete
2025-09-28 00:16:24.017999 | controller | 0edcf9fb2b15: Verifying Checksum
2025-09-28 00:16:25.209342 | controller | 0edcf9fb2b15: Download complete
2025-09-28 00:16:25.209405 | controller | 5af43b69e845: Verifying Checksum
2025-09-28 00:16:26.808257 | controller | 5af43b69e845: Download complete
2025-09-28 00:16:26.808347 | controller | 1651773effb2: Verifying Checksum
2025-09-28 00:16:26.808391 | controller | 1651773effb2: Download complete
2025-09-28 00:16:27.595921 | controller | 79e23c5c0fe4: Verifying Checksum
2025-09-28 00:16:27.596136 | controller | 79e23c5c0fe4: Download complete
2025-09-28 00:16:29.386422 | controller | 37425716ea5b: Download complete
2025-09-28 00:16:31.478169 | controller | e5058b1faaa6: Verifying Checksum
2025-09-28 00:16:34.639315 | controller | e5058b1faaa6: Download complete
2025-09-28 00:16:34.639378 | controller | 846775490569: Verifying Checksum
2025-09-28 00:16:54.432610 | controller | 846775490569: Download complete
2025-09-28 00:16:54.432709 | controller | 37425716ea5b: Pull complete
2025-09-28 00:16:54.463543 | controller | cd9b0c439616: Pull complete
2025-09-28 00:16:54.505055 | controller | d4612dbd8855: Pull complete
2025-09-28 00:17:00.666207 | controller | 554699364730: Pull complete
2025-09-28 00:17:00.688925 | controller | 1ff15d4bdb3e: Pull complete
2025-09-28 00:17:00.711357 | controller | 5f2e4724adea: Pull complete
2025-09-28 00:17:00.766541 | controller | a02d9a95ccb8: Pull complete
2025-09-28 00:17:00.803851 | controller | 989f4ce370cb: Pull complete
2025-09-28 00:17:00.829436 | controller | 0d7f52cdf9df: Pull complete
2025-09-28 00:17:00.853032 | controller | c423742351d5: Pull complete
2025-09-28 00:17:03.394920 | controller | 109236341d21: Pull complete
2025-09-28 00:17:03.421476 | controller | 07a2f61c96b8: Pull complete
2025-09-28 00:17:03.453978 | controller | 041f122f27ae: Pull complete
2025-09-28 00:17:03.611209 | controller | ca6f5098b12e: Pull complete
2025-09-28 00:17:03.674006 | controller | 1eb3e7b2afd9: Pull complete
2025-09-28 00:17:03.721182 | controller | 18a0b750727a: Pull complete
2025-09-28 00:17:03.744740 | controller | 17f2f596716c: Pull complete
2025-09-28 00:17:03.776116 | controller | f35a9998a9bd: Pull complete
2025-09-28 00:17:03.814500 | controller | fdfc10566405: Pull complete
2025-09-28 00:17:03.838509 | controller | 1ff1c442c5fe: Pull complete
2025-09-28 00:17:05.690305 | controller | a3443c4a17ed: Pull complete
2025-09-28 00:17:07.694316 | controller | 0edcf9fb2b15: Pull complete
2025-09-28 00:17:10.609760 | controller | 5af43b69e845: Pull complete
2025-09-28 00:17:13.636944 | controller | 1651773effb2: Pull complete
2025-09-28 00:17:16.714412 | controller | 79e23c5c0fe4: Pull complete
2025-09-28 00:17:21.163414 | controller | e5058b1faaa6: Pull complete
2025-09-28 00:17:24.238967 | controller | 846775490569: Pull complete
2025-09-28 00:17:24.292012 | controller | Digest: sha256:923f4b465456ae05243474faf9061abbefa2c2c5b88f24455fa2d5ce3d8d2ab4
2025-09-28 00:17:24.299589 | controller | Status: Downloaded newer image for quay.io/ansible/default-test-container:2.9.0
2025-09-28 00:17:24.310712 | controller | quay.io/ansible/default-test-container:2.9.0
2025-09-28 00:17:24.316856 | controller | Run command: docker images quay.io/ansible/pypi-test-container:1.0.0 --format '{{json .}}'
2025-09-28 00:17:24.361041 | controller | Run command: docker pull quay.io/ansible/pypi-test-container:1.0.0
2025-09-28 00:17:25.867480 | controller | 1.0.0: Pulling from ansible/pypi-test-container
2025-09-28 00:17:25.868028 | controller | 04a5f4cda3ee: Pulling fs layer
2025-09-28 00:17:25.868045 | controller | ff496a88c8ed: Pulling fs layer
2025-09-28 00:17:25.868052 | controller | 0ce83f459fe7: Pulling fs layer
2025-09-28 00:17:25.868058 | controller | 2e5170e1f099: Pulling fs layer
2025-09-28 00:17:25.868064 | controller | 7641eb41b08c: Pulling fs layer
2025-09-28 00:17:25.868070 | controller | ad15fa9da398: Pulling fs layer
2025-09-28 00:17:25.868076 | controller | 087d91352424: Pulling fs layer
2025-09-28 00:17:25.868094 | controller | 8b92efd6a100: Pulling fs layer
2025-09-28 00:17:25.868104 | controller | 2e5170e1f099: Waiting
2025-09-28 00:17:26.630596 | controller | 7641eb41b08c: Waiting
2025-09-28 00:17:26.630664 | controller | ad15fa9da398: Waiting
2025-09-28 00:17:26.630671 | controller | 087d91352424: Waiting
2025-09-28 00:17:26.630678 | controller | 8b92efd6a100: Waiting
2025-09-28 00:17:26.630693 | controller | ff496a88c8ed: Verifying Checksum
2025-09-28 00:17:26.630766 | controller | ff496a88c8ed: Download complete
2025-09-28 00:17:26.740368 | controller | 0ce83f459fe7: Verifying Checksum
2025-09-28 00:17:27.513810 | controller | 0ce83f459fe7: Download complete
2025-09-28 00:17:27.514021 | controller | 7641eb41b08c: Verifying Checksum
2025-09-28 00:17:28.276199 | controller | 7641eb41b08c: Download complete
2025-09-28 00:17:28.276274 | controller | ad15fa9da398: Verifying Checksum
2025-09-28 00:17:28.276332 | controller | ad15fa9da398: Download complete
2025-09-28 00:17:29.941912 | controller | 087d91352424: Verifying Checksum
2025-09-28 00:17:29.942106 | controller | 087d91352424: Download complete
2025-09-28 00:17:30.703503 | controller | 8b92efd6a100: Verifying Checksum
2025-09-28 00:17:30.703587 | controller | 8b92efd6a100: Download complete
2025-09-28 00:17:30.828416 | controller | 2e5170e1f099: Verifying Checksum
2025-09-28 00:17:30.828595 | controller | 2e5170e1f099: Download complete
2025-09-28 00:17:33.403839 | controller | 04a5f4cda3ee: Verifying Checksum
2025-09-28 00:17:33.403890 | controller | 04a5f4cda3ee: Download complete
2025-09-28 00:17:35.688263 | controller | 04a5f4cda3ee: Pull complete
2025-09-28 00:17:35.722961 | controller | ff496a88c8ed: Pull complete
2025-09-28 00:17:35.751486 | controller | 0ce83f459fe7: Pull complete
2025-09-28 00:17:37.374855 | controller | 2e5170e1f099: Pull complete
2025-09-28 00:17:37.398261 | controller | 7641eb41b08c: Pull complete
2025-09-28 00:17:37.430073 | controller | ad15fa9da398: Pull complete
2025-09-28 00:17:38.470825 | controller | 087d91352424: Pull complete
2025-09-28 00:17:38.507549 | controller | 8b92efd6a100: Pull complete
2025-09-28 00:17:38.531516 | controller | Digest: sha256:71042ab0a14971b5608fe75706de54f367fc31db573e3b3955182037f73cadb6
2025-09-28 00:17:38.538609 | controller | Status: Downloaded newer image for quay.io/ansible/pypi-test-container:1.0.0
2025-09-28 00:17:38.552057 | controller | quay.io/ansible/pypi-test-container:1.0.0
2025-09-28 00:17:38.555865 | controller | Run command: docker run --detach quay.io/ansible/pypi-test-container:1.0.0
2025-09-28 00:17:46.448378 | controller | Run command: docker inspect 00b29af01ce5f99425e643bf02f5ea2e7e4718eb6dd56520f84289bb1ffc08af
2025-09-28 00:17:46.519244 | controller | Scanning collection root: /home/zuul/.ansible/collections/ansible_collections
2025-09-28 00:17:46.536465 | controller | Including collection: ansible.netcommon (288 files)
2025-09-28 00:17:46.536545 | controller | Including collection: ansible.network (23 files)
2025-09-28 00:17:46.551248 | controller | Including collection: ansible.utils (442 files)
2025-09-28 00:17:46.601640 | controller | Including collection: arista.eos (1022 files)
2025-09-28 00:17:46.658437 | controller | Including collection: cisco.ios (1167 files)
2025-09-28 00:17:46.722058 | controller | Including collection: cisco.iosxr (1037 files)
2025-09-28 00:17:46.813136 | controller | Including collection: cisco.nxos (1680 files)
2025-09-28 00:17:46.870898 | controller | Including collection: junipernetworks.junos (963 files)
2025-09-28 00:17:46.928081 | controller | Creating a payload archive containing 7348 files...
2025-09-28 00:17:49.308858 | controller | Created a 5946051 byte payload archive containing 7348 files in 2 seconds.
2025-09-28 00:17:49.312571 | controller | Assuming Docker is available on localhost.
2025-09-28 00:17:49.312863 | 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-28 00:17:49.878387 | controller | Run command: docker exec -i a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 dd of=/root/docker.sh bs=65536
2025-09-28 00:17:49.969733 | controller | Run command: docker exec a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 /bin/bash /root/docker.sh
2025-09-28 00:17:50.048181 | controller | Run command: docker exec -i a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 dd of=/root/test.tgz bs=65536
2025-09-28 00:17:50.152912 | controller | Run command: docker exec a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 tar oxzf /root/test.tgz -C /root
2025-09-28 00:17:51.301837 | controller | Run command: docker exec a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 /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-u1eqrva9.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/
2025-09-28 00:17:51.811916 | controller | Injecting custom PyPI hosts entries: /etc/hosts
2025-09-28 00:17:51.812425 | controller | Injecting custom PyPI config: /root/.pip/pip.conf
2025-09-28 00:17:51.812899 | controller | Injecting custom PyPI config: /root/.pydistutils.cfg
2025-09-28 00:17:51.815086 | controller | Running sanity test 'action-plugin-docs' with Python 3.6
2025-09-28 00:17:51.815993 | controller | Read 0 sanity test ignore line(s) for Ansible 2.10 from: tests/sanity/ignore-2.10.txt
2025-09-28 00:17:51.822958 | controller | No tests applicable.
2025-09-28 00:17:51.823170 | controller | Running sanity test 'ansible-doc' with Python 3.6
2025-09-28 00:17:51.823526 | controller | No tests applicable.
2025-09-28 00:17:51.823714 | controller | Running sanity test 'changelog' with Python 3.6
2025-09-28 00:17:51.824975 | 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-28 00:17:52.914101 | 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-28 00:17:53.619151 | controller | Collecting antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2))
2025-09-28 00:18:08.639127 | controller |   WARNING: Retrying (Retry(total=4, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-09-28 00:18:24.156415 | controller |   WARNING: Retrying (Retry(total=3, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-09-28 00:18:40.180353 | controller |   WARNING: Retrying (Retry(total=2, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-09-28 00:18:57.198262 | controller |   WARNING: Retrying (Retry(total=1, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-09-28 00:19:16.218944 | controller |   WARNING: Retrying (Retry(total=0, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='172.17.0.2', port=3141): Read timed out. (read timeout=15)",)': /root/pypi/+simple/antsibull-changelog/
2025-09-28 00:19:31.235004 | 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-28 00:19:31.235701 | 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-28 00:19:31.357957 | 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-28 00:19:31.358124 | controller | Removing custom PyPI config: /root/.pydistutils.cfg
2025-09-28 00:19:31.358245 | controller | Removing custom PyPI config: /root/.pip/pip.conf
2025-09-28 00:19:31.358338 | controller | Removing custom PyPI hosts entries: /etc/hosts
2025-09-28 00:19:31.409864 | controller | Run command: docker exec a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 tar czf /root/output.tgz --exclude .tmp -C /root/ansible_collections/ansible/network/tests output
2025-09-28 00:19:31.493017 | controller | Run command: docker exec -i a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 dd if=/root/output.tgz bs=65536
2025-09-28 00:19:31.580614 | controller | Run command: tar oxzf /tmp/ansible-result-28kcp2ze.tgz -C /home/zuul/.ansible/collections/ansible_collections/ansible/network/tests
2025-09-28 00:19:31.598008 | controller | Run command: docker rm -f 00b29af01ce5f99425e643bf02f5ea2e7e4718eb6dd56520f84289bb1ffc08af
2025-09-28 00:19:31.933596 | controller | Run command: docker rm -f a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3
2025-09-28 00:19:32.758749 | controller | ERROR: Command "docker exec a0826e4aaddfc7b861880ef3efd562e709f59f5fc8d65ff6973f79392c3fb1d3 /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-u1eqrva9.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/" returned exit status 1.
2025-09-28 00:19:33.116051 | controller | ERROR
2025-09-28 00:19:33.116266 | controller | {
2025-09-28 00:19:33.116312 | controller |   "delta": "0:03:31.706028",
2025-09-28 00:19:33.116339 | controller |   "end": "2025-09-28 00:19:32.834450",
2025-09-28 00:19:33.116363 | controller |   "msg": "non-zero return code",
2025-09-28 00:19:33.116386 | controller |   "rc": 1,
2025-09-28 00:19:33.116409 | controller |   "start": "2025-09-28 00:16:01.128422"
2025-09-28 00:19:33.116431 | controller | }
failure
2025-09-28 00:19:33.122834 | 
2025-09-28 00:19:33.122913 | PLAY RECAP
2025-09-28 00:19:33.122977 | controller | ok: 20 changed: 5 unreachable: 0 failed: 1 skipped: 20 rescued: 0 ignored: 0
2025-09-28 00:19:33.123034 | 
2025-09-28 00:19:33.273456 | RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-09-28 00:19:33.274367 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-09-28 00:19:33.888633 | 
2025-09-28 00:19:33.888752 | PLAY [all]
2025-09-28 00:19:33.910007 | 
2025-09-28 00:19:33.910116 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-09-28 00:19:36.950490 | controller | changed: non-zero return code
2025-09-28 00:19:36.959072 | 
2025-09-28 00:19:36.959207 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-09-28 00:19:36.975659 | controller | skipping: Conditional result was False
2025-09-28 00:19:36.982805 | 
2025-09-28 00:19:36.982881 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-09-28 00:19:37.013658 | 
2025-09-28 00:19:37.013810 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-09-28 00:19:37.046082 | 
2025-09-28 00:19:37.046248 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-09-28 00:19:37.062804 | controller | skipping: Conditional result was False
2025-09-28 00:19:37.073485 | 
2025-09-28 00:19:37.073649 | LOOP [fetch-subunit-output : Generate subunit file]
2025-09-28 00:19:37.102440 | 
2025-09-28 00:19:37.102649 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-09-28 00:19:37.117911 | controller | skipping: Conditional result was False
2025-09-28 00:19:37.129572 | 
2025-09-28 00:19:37.129825 | TASK [fetch-subunit-output : Remove the temporary file]
2025-09-28 00:19:37.144776 | controller | skipping: Conditional result was False
2025-09-28 00:19:37.153575 | 
2025-09-28 00:19:37.153666 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-09-28 00:19:37.168805 | controller | skipping: Conditional result was False
2025-09-28 00:19:37.204330 | 
2025-09-28 00:19:37.204475 | PLAY RECAP
2025-09-28 00:19:37.204539 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-09-28 00:19:37.204562 | 
2025-09-28 00:19:37.301310 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-09-28 00:19:37.303065 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-09-28 00:19:37.894489 | 
2025-09-28 00:19:37.894597 | PLAY [all:!appliance*]
2025-09-28 00:19:37.916141 | 
2025-09-28 00:19:37.916250 | TASK [unregister the node]
2025-09-28 00:19:38.273327 | controller | skipping: Conditional result was False
2025-09-28 00:19:38.285688 | 
2025-09-28 00:19:38.285876 | TASK [include_role : fetch-output]
2025-09-28 00:19:38.334841 | controller | ok
2025-09-28 00:19:38.377857 | 
2025-09-28 00:19:38.378073 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-28 00:19:38.455259 | controller | skipping: Conditional result was False
2025-09-28 00:19:38.468952 | 
2025-09-28 00:19:38.469282 | TASK [fetch-output : Set log path for single node]
2025-09-28 00:19:38.529362 | controller | ok
2025-09-28 00:19:38.541743 | 
2025-09-28 00:19:38.541912 | LOOP [fetch-output : Ensure local output dirs]
2025-09-28 00:19:38.997989 | controller -> localhost | ok: "/var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/logs"
2025-09-28 00:19:39.246713 | controller -> localhost | changed: "/var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/artifacts"
2025-09-28 00:19:39.517720 | controller -> localhost | changed: "/var/lib/zuul/builds/2c8d14e00ead42a7b9ec320eb32ea44d/work/docs"
2025-09-28 00:19:39.536956 | 
2025-09-28 00:19:39.537100 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-28 00:19:41.860500 | controller | changed:
2025-09-28 00:19:41.861208 | controller | .d..t...... ./
2025-09-28 00:19:41.861335 | controller | cd+++++++++ controller/
2025-09-28 00:19:41.861442 | controller | changed: All items complete
2025-09-28 00:19:41.861538 | 
2025-09-28 00:19:43.980608 | controller | changed: .d..t...... ./
2025-09-28 00:19:46.001611 | controller | changed: .d..t...... ./
2025-09-28 00:19:46.033246 | 
2025-09-28 00:19:46.033394 | TASK [include_role : fetch-output-openshift]
2025-09-28 00:19:46.059100 | controller | skipping: Conditional result was False
2025-09-28 00:19:46.074105 | 
2025-09-28 00:19:46.074295 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-09-28 00:19:46.121082 | controller | skipping: Conditional result was False
2025-09-28 00:19:46.139515 | controller | skipping: Conditional result was False
2025-09-28 00:19:46.181129 | 
2025-09-28 00:19:46.181279 | PLAY [localhost]
2025-09-28 00:19:46.200294 | 
2025-09-28 00:19:46.200428 | TASK [Run Zuul manifest role]
2025-09-28 00:19:46.223126 | localhost | ok
2025-09-28 00:19:46.249333 | 
2025-09-28 00:19:46.249591 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-09-28 00:19:46.643043 | localhost | changed
2025-09-28 00:19:46.653757 | 
2025-09-28 00:19:46.653913 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-09-28 00:19:46.691575 | localhost | ok
2025-09-28 00:19:46.708365 | 
2025-09-28 00:19:46.708479 | TASK [Set zuul-log-path fact]
2025-09-28 00:19:46.783001 | localhost | ok
2025-09-28 00:19:46.809515 | 
2025-09-28 00:19:46.809693 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-28 00:19:46.852640 | localhost | ok
2025-09-28 00:19:46.867148 | 
2025-09-28 00:19:46.867282 | LOOP [Run upload-logs-swift role]
2025-09-28 00:19:46.904156 | localhost | Output suppressed because no_log was given
2025-09-28 00:19:46.947802 | 
2025-09-28 00:19:46.947926 | TASK [Set zuul-log-path fact]
2025-09-28 00:19:46.983951 | localhost | skipping: Conditional result was False
2025-09-28 00:19:46.992186 | 
2025-09-28 00:19:46.992368 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-09-28 00:19:47.466294 | localhost -> localhost | ok: Runtime: 0:00:00.006442
2025-09-28 00:19:47.478279 | 
2025-09-28 00:19:47.478440 | TASK [upload-logs-swift : Upload logs to swift]