2025-11-01 00:06:50.827912 | Job console starting...
2025-11-01 00:06:50.839791 | Updating repositories
2025-11-01 00:06:51.102147 | Preparing job workspace
2025-11-01 00:06:55.412668 | Running Ansible setup...
2025-11-01 00:07:07.645465 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-01 00:07:08.322844 | 
2025-11-01 00:07:08.322976 | PLAY [localhost]
2025-11-01 00:07:08.340913 | 
2025-11-01 00:07:08.341026 | TASK [Gathering Facts]
2025-11-01 00:07:09.368526 | localhost | ok
2025-11-01 00:07:09.394826 | 
2025-11-01 00:07:09.395037 | TASK [Setup log path fact]
2025-11-01 00:07:09.413612 | localhost | ok
2025-11-01 00:07:09.425979 | 
2025-11-01 00:07:09.426047 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-01 00:07:09.466205 | localhost | ok
2025-11-01 00:07:09.479130 | 
2025-11-01 00:07:09.479240 | TASK [emit-job-header : Print job information]
2025-11-01 00:07:09.512172 | # Job Information
2025-11-01 00:07:09.512379 | Ansible Version: 2.15.12
2025-11-01 00:07:09.512430 | Job: ansible-test-sanity-docker-stable-2.10
2025-11-01 00:07:09.512462 | Pipeline: periodic
2025-11-01 00:07:09.512488 | Executor: ze02.softwarefactory-project.io
2025-11-01 00:07:09.512515 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-01 00:07:09.512548 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/9ab/ansible/9ab7a3f508b1416d907450455dabe3ca/
2025-11-01 00:07:09.512576 | Event ID: a664f74adefa4145bbf2cab5da247121
2025-11-01 00:07:09.519543 | 
2025-11-01 00:07:09.519636 | LOOP [emit-job-header : Print node information]
2025-11-01 00:07:09.663796 | localhost | ok:
2025-11-01 00:07:09.663984 | localhost | # Node Information
2025-11-01 00:07:09.664012 | localhost | Inventory Hostname: controller
2025-11-01 00:07:09.664033 | localhost | Hostname: np0005508779
2025-11-01 00:07:09.664053 | localhost | Username: zuul
2025-11-01 00:07:09.664074 | localhost | Distro: Fedora 37
2025-11-01 00:07:09.664092 | localhost | Provider: ansible-vexxhost-ams1
2025-11-01 00:07:09.664110 | localhost | Region: ams1
2025-11-01 00:07:09.664128 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-01 00:07:09.664145 | localhost | Product Name: OpenStack Nova
2025-11-01 00:07:09.664162 | localhost | Interface IP: 38.129.16.87
2025-11-01 00:07:09.679529 | 
2025-11-01 00:07:09.679654 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-01 00:07:10.070277 | localhost -> localhost | changed
2025-11-01 00:07:10.075767 | 
2025-11-01 00:07:10.075848 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-01 00:07:10.886787 | localhost -> localhost | changed
2025-11-01 00:07:10.906923 | 
2025-11-01 00:07:10.906984 | PLAY [all:!appliance*]
2025-11-01 00:07:10.924017 | 
2025-11-01 00:07:10.924091 | TASK [include_role : start-zuul-console]
2025-11-01 00:07:10.943908 | controller | ok
2025-11-01 00:07:10.958429 | 
2025-11-01 00:07:10.958512 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-01 00:07:11.995869 | controller | ok
2025-11-01 00:07:12.007284 | 
2025-11-01 00:07:12.007362 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-01 00:07:13.889483 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-01 00:07:13.905060 | 
2025-11-01 00:07:13.905246 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-01 00:07:14.276901 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.285239 | 
2025-11-01 00:07:14.285367 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-01 00:07:14.310592 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.319905 | 
2025-11-01 00:07:14.320035 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-01 00:07:14.344015 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.353069 | 
2025-11-01 00:07:14.353199 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-01 00:07:14.378182 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.387132 | 
2025-11-01 00:07:14.387264 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-01 00:07:14.411464 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.420127 | 
2025-11-01 00:07:14.420263 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-01 00:07:14.435083 | controller | skipping: Conditional result was False
2025-11-01 00:07:14.446191 | 
2025-11-01 00:07:14.446282 | TASK [Disable Fedora Modular]
2025-11-01 00:07:15.551054 | controller | changed
2025-11-01 00:07:15.559484 | 
2025-11-01 00:07:15.559578 | TASK [Enable EPEL]
2025-11-01 00:07:15.585093 | controller | skipping: Conditional result was False
2025-11-01 00:07:15.598123 | 
2025-11-01 00:07:15.598296 | TASK [Register the RHEL node]
2025-11-01 00:07:16.009449 | 
2025-11-01 00:07:16.009578 | TASK [Show the subscription-manager status]
2025-11-01 00:07:16.363709 | controller | skipping: Conditional result was False
2025-11-01 00:07:16.384941 | 
2025-11-01 00:07:16.385110 | TASK [Enable EPEL on RHEL]
2025-11-01 00:07:16.767210 | controller | skipping: Conditional result was False
2025-11-01 00:07:16.781520 | 
2025-11-01 00:07:16.781727 | TASK [Install git and tox]
2025-11-01 00:09:05.619962 | controller | changed
2025-11-01 00:09:05.634912 | 
2025-11-01 00:09:05.635100 | TASK [include_role : prepare-workspace]
2025-11-01 00:09:05.674024 | controller | ok
2025-11-01 00:09:05.713121 | 
2025-11-01 00:09:05.713259 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-01 00:09:06.556501 | controller | ok
2025-11-01 00:09:06.571158 | 
2025-11-01 00:09:06.571300 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-01 00:09:22.695918 | controller | Output suppressed because no_log was given
2025-11-01 00:09:22.712529 | 
2025-11-01 00:09:22.712650 | TASK [include_role : prepare-workspace-openshift]
2025-11-01 00:09:22.728960 | controller | skipping: Conditional result was False
2025-11-01 00:09:22.760326 | 
2025-11-01 00:09:22.760425 | PLAY [all:!appliance]
2025-11-01 00:09:22.783931 | 
2025-11-01 00:09:22.784060 | TASK [Run add-build-sshkey role (RSA)]
2025-11-01 00:09:22.816271 | controller | ok
2025-11-01 00:09:22.834373 | 
2025-11-01 00:09:22.834468 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-01 00:09:23.074162 | controller -> localhost | ok
2025-11-01 00:09:23.090875 | 
2025-11-01 00:09:23.091048 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-01 00:09:23.116174 | controller | ok
2025-11-01 00:09:23.133853 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-01 00:09:23.142472 | 
2025-11-01 00:09:23.142549 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-01 00:09:23.624133 | controller -> localhost | Generating public/private rsa key pair.
2025-11-01 00:09:23.624461 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/9ab7a3f508b1416d907450455dabe3ca_id_rsa.
2025-11-01 00:09:23.624509 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/9ab7a3f508b1416d907450455dabe3ca_id_rsa.pub.
2025-11-01 00:09:23.624541 | controller -> localhost | The key fingerprint is:
2025-11-01 00:09:23.624570 | controller -> localhost | SHA256:aHbBq9ZxLwxlobR4ccpFLtuNVwK3/dt0QyYPTUTxUNM zuul-build-sshkey
2025-11-01 00:09:23.624600 | controller -> localhost | The key's randomart image is:
2025-11-01 00:09:23.624629 | controller -> localhost | +---[RSA 2048]----+
2025-11-01 00:09:23.624656 | controller -> localhost | |        o.* . +B+|
2025-11-01 00:09:23.624713 | controller -> localhost | |       = O + oo.E|
2025-11-01 00:09:23.624744 | controller -> localhost | |      . X + ooo+.|
2025-11-01 00:09:23.624771 | controller -> localhost | |       o O o o*. |
2025-11-01 00:09:23.624798 | controller -> localhost | |      + S + o  o+|
2025-11-01 00:09:23.624836 | controller -> localhost | |     o + = o   .=|
2025-11-01 00:09:23.624869 | controller -> localhost | |      o . o .  ..|
2025-11-01 00:09:23.624900 | controller -> localhost | |     .     .     |
2025-11-01 00:09:23.624932 | controller -> localhost | |                 |
2025-11-01 00:09:23.624977 | controller -> localhost | +----[SHA256]-----+
2025-11-01 00:09:23.625069 | controller -> localhost | ok: Runtime: 0:00:00.116598
2025-11-01 00:09:23.635929 | 
2025-11-01 00:09:23.636037 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-01 00:09:23.659643 | controller | ok
2025-11-01 00:09:23.674987 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-01 00:09:23.688630 | 
2025-11-01 00:09:23.688761 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-01 00:09:23.702623 | controller | skipping: Conditional result was False
2025-11-01 00:09:23.709602 | 
2025-11-01 00:09:23.709717 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-01 00:09:24.764044 | controller | changed
2025-11-01 00:09:24.780319 | 
2025-11-01 00:09:24.780541 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-01 00:09:25.440790 | controller | ok
2025-11-01 00:09:25.455637 | 
2025-11-01 00:09:25.455842 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-01 00:09:28.459173 | controller | changed
2025-11-01 00:09:28.465353 | 
2025-11-01 00:09:28.465417 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-01 00:09:31.437553 | controller | changed
2025-11-01 00:09:31.455258 | 
2025-11-01 00:09:31.455802 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-01 00:09:31.482287 | controller | skipping: Conditional result was False
2025-11-01 00:09:31.495842 | 
2025-11-01 00:09:31.495968 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-01 00:09:31.971014 | controller -> localhost | changed
2025-11-01 00:09:32.004779 | 
2025-11-01 00:09:32.004980 | TASK [add-build-sshkey : Add back temp key]
2025-11-01 00:09:32.306944 | controller -> localhost | Identity added: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/9ab7a3f508b1416d907450455dabe3ca_id_rsa (zuul-build-sshkey)
2025-11-01 00:09:32.307150 | controller -> localhost | ok: Runtime: 0:00:00.008842
2025-11-01 00:09:32.313661 | 
2025-11-01 00:09:32.313743 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-01 00:09:33.215102 | controller | ok
2025-11-01 00:09:33.223782 | 
2025-11-01 00:09:33.223876 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-01 00:09:33.248435 | controller | skipping: Conditional result was False
2025-11-01 00:09:33.265581 | 
2025-11-01 00:09:33.265731 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-01 00:09:33.286449 | controller | ok
2025-11-01 00:09:33.303646 | 
2025-11-01 00:09:33.303763 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-01 00:09:33.542061 | controller -> localhost | ok
2025-11-01 00:09:33.560330 | 
2025-11-01 00:09:33.560499 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-01 00:09:33.596388 | controller | ok
2025-11-01 00:09:33.615434 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-01 00:09:33.624867 | 
2025-11-01 00:09:33.624976 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-01 00:09:33.886409 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-01 00:09:33.886608 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/9ab7a3f508b1416d907450455dabe3ca_id_ecdsa.
2025-11-01 00:09:33.886645 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/9ab7a3f508b1416d907450455dabe3ca_id_ecdsa.pub.
2025-11-01 00:09:33.886706 | controller -> localhost | The key fingerprint is:
2025-11-01 00:09:33.886737 | controller -> localhost | SHA256:ycr7uH5wU72Dupi8SXNH/1n+tVt+D2r4sjB17o1Wb6o zuul-build-sshkey
2025-11-01 00:09:33.886765 | controller -> localhost | The key's randomart image is:
2025-11-01 00:09:33.886789 | controller -> localhost | +---[ECDSA 521]---+
2025-11-01 00:09:33.886814 | controller -> localhost | |                 |
2025-11-01 00:09:33.886839 | controller -> localhost | |                 |
2025-11-01 00:09:33.886861 | controller -> localhost | |           .     |
2025-11-01 00:09:33.886883 | controller -> localhost | |       . .. .    |
2025-11-01 00:09:33.886909 | controller -> localhost | |        S.o...   |
2025-11-01 00:09:33.886932 | controller -> localhost | |     ...oo.+o .  |
2025-11-01 00:09:33.886954 | controller -> localhost | |      =o+o..oo..+|
2025-11-01 00:09:33.886980 | controller -> localhost | |     o Oo+o.o= *B|
2025-11-01 00:09:33.887003 | controller -> localhost | |     .@=o..*E.==X|
2025-11-01 00:09:33.887025 | controller -> localhost | +----[SHA256]-----+
2025-11-01 00:09:33.887081 | controller -> localhost | ok: Runtime: 0:00:00.008882
2025-11-01 00:09:33.895833 | 
2025-11-01 00:09:33.895919 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-01 00:09:33.923115 | controller | ok
2025-11-01 00:09:33.936152 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-01 00:09:33.950361 | 
2025-11-01 00:09:33.950480 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-01 00:09:33.975547 | controller | skipping: Conditional result was False
2025-11-01 00:09:33.983189 | 
2025-11-01 00:09:33.983273 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-01 00:09:34.859241 | controller | changed
2025-11-01 00:09:34.873702 | 
2025-11-01 00:09:34.873961 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-01 00:09:35.519390 | controller | ok
2025-11-01 00:09:35.535847 | 
2025-11-01 00:09:35.536048 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-01 00:09:39.041048 | controller | changed
2025-11-01 00:09:39.047568 | 
2025-11-01 00:09:39.047697 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-01 00:09:42.001725 | controller | changed
2025-11-01 00:09:42.007974 | 
2025-11-01 00:09:42.008057 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-01 00:09:42.032247 | controller | skipping: Conditional result was False
2025-11-01 00:09:42.039570 | 
2025-11-01 00:09:42.039695 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-01 00:09:42.267033 | controller -> localhost | changed
2025-11-01 00:09:42.278935 | 
2025-11-01 00:09:42.279041 | TASK [add-build-sshkey : Add back temp key]
2025-11-01 00:09:42.629903 | controller -> localhost | Identity added: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/9ab7a3f508b1416d907450455dabe3ca_id_ecdsa (zuul-build-sshkey)
2025-11-01 00:09:42.630114 | controller -> localhost | ok: Runtime: 0:00:00.007104
2025-11-01 00:09:42.636918 | 
2025-11-01 00:09:42.636998 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-01 00:09:43.309120 | controller | ok
2025-11-01 00:09:43.319895 | 
2025-11-01 00:09:43.320029 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-01 00:09:43.346802 | controller | skipping: Conditional result was False
2025-11-01 00:09:43.361276 | 
2025-11-01 00:09:43.361387 | TASK [include_role : remove-zuul-sshkey]
2025-11-01 00:09:43.387127 | controller | skipping: Conditional result was False
2025-11-01 00:09:43.396141 | 
2025-11-01 00:09:43.396272 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-01 00:09:44.021225 | controller | ok: "logs"
2025-11-01 00:09:44.021749 | controller | ok: All items complete
2025-11-01 00:09:44.021786 | 
2025-11-01 00:09:44.600510 | controller | ok: "artifacts"
2025-11-01 00:09:45.177642 | controller | ok: "docs"
2025-11-01 00:09:45.185322 | 
2025-11-01 00:09:45.185420 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-01 00:09:45.822437 | controller | changed: "logs"
2025-11-01 00:09:46.402367 | controller | changed: "artifacts"
2025-11-01 00:09:47.028245 | controller | changed: "docs"
2025-11-01 00:09:47.067900 | 
2025-11-01 00:09:47.068023 | PLAY RECAP
2025-11-01 00:09:47.068083 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-01 00:09:47.068122 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-01 00:09:47.068150 | 
2025-11-01 00:09:47.199848 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-01 00:09:47.200904 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-01 00:09:47.845128 | 
2025-11-01 00:09:47.845258 | PLAY [all]
2025-11-01 00:09:47.869251 | 
2025-11-01 00:09:47.869530 | TASK [Install binary dependencies]
2025-11-01 00:09:47.940088 | controller | ok
2025-11-01 00:09:47.969685 | 
2025-11-01 00:09:47.969828 | TASK [bindep : Include find tasks]
2025-11-01 00:09:47.999564 | controller | ok
2025-11-01 00:09:48.008439 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-01 00:09:48.015332 | 
2025-11-01 00:09:48.015435 | TASK [bindep : Look for bindep.txt]
2025-11-01 00:09:48.964337 | controller | ok
2025-11-01 00:09:48.978168 | 
2025-11-01 00:09:48.978355 | TASK [bindep : Define bindep_file fact]
2025-11-01 00:09:49.006405 | controller | skipping: Conditional result was False
2025-11-01 00:09:49.023043 | 
2025-11-01 00:09:49.023277 | TASK [bindep : Look for other-requirements.txt]
2025-11-01 00:09:49.626471 | controller | ok
2025-11-01 00:09:49.632994 | 
2025-11-01 00:09:49.633094 | TASK [bindep : Define bindep_file fact]
2025-11-01 00:09:49.658875 | controller | skipping: Conditional result was False
2025-11-01 00:09:49.669255 | 
2025-11-01 00:09:49.669408 | TASK [bindep : Look for bindep fallback file]
2025-11-01 00:09:49.695032 | controller | skipping: Conditional result was False
2025-11-01 00:09:49.705723 | 
2025-11-01 00:09:49.705875 | TASK [bindep : Define bindep_file fact]
2025-11-01 00:09:49.731933 | controller | skipping: Conditional result was False
2025-11-01 00:09:49.743137 | 
2025-11-01 00:09:49.743289 | TASK [bindep : Include bindep tasks]
2025-11-01 00:09:49.769165 | controller | skipping: Conditional result was False
2025-11-01 00:09:49.780893 | 
2025-11-01 00:09:49.781043 | TASK [bindep : Include install tasks]
2025-11-01 00:09:49.806274 | controller | skipping: Conditional result was False
2025-11-01 00:09:49.817945 | 
2025-11-01 00:09:49.818120 | LOOP [bindep : Include package tasks]
2025-11-01 00:09:49.879061 | 
2025-11-01 00:09:49.879228 | TASK [Run test-setup role]
2025-11-01 00:09:49.899083 | controller | ok
2025-11-01 00:09:49.924868 | 
2025-11-01 00:09:49.925021 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-01 00:09:50.624487 | controller | ok
2025-11-01 00:09:50.641647 | 
2025-11-01 00:09:50.641826 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-01 00:09:51.010958 | controller | skipping: Conditional result was False
2025-11-01 00:09:51.040561 | 
2025-11-01 00:09:51.040686 | PLAY RECAP
2025-11-01 00:09:51.040736 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-01 00:09:51.040759 | 
2025-11-01 00:09:51.154746 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-01 00:09:51.155903 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-01 00:09:51.855195 | 
2025-11-01 00:09:51.855325 | PLAY [controller]
2025-11-01 00:09:51.887873 | 
2025-11-01 00:09:51.888004 | TASK [Create the /root directory]
2025-11-01 00:09:52.912271 | controller | ok
2025-11-01 00:09:52.921058 | 
2025-11-01 00:09:52.921203 | TASK [Install glibc-langpack-en]
2025-11-01 00:10:00.805495 | controller | ok: Nothing to do
2025-11-01 00:10:00.816016 | 
2025-11-01 00:10:00.816132 | TASK [Ensure controller directory exists]
2025-11-01 00:10:01.664760 | controller | changed
2025-11-01 00:10:01.675626 | 
2025-11-01 00:10:01.676244 | TASK [Install container runtime]
2025-11-01 00:10:01.768879 | controller | ok
2025-11-01 00:10:01.863263 | 
2025-11-01 00:10:01.863404 | LOOP [ensure-docker : Gather variables for each operating system]
2025-11-01 00:10:01.947540 | controller | ok: "/var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml"
2025-11-01 00:10:01.956451 | 
2025-11-01 00:10:01.956581 | TASK [ensure-docker : Sanity check for distro selection]
2025-11-01 00:10:01.993223 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.001613 | 
2025-11-01 00:10:02.001752 | TASK [ensure-docker : Sanity check for distro install]
2025-11-01 00:10:02.056601 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.066210 | 
2025-11-01 00:10:02.066339 | TASK [ensure-docker : Sanity check for upstream install]
2025-11-01 00:10:02.116516 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.124384 | 
2025-11-01 00:10:02.124495 | TASK [ensure-docker : Sanity check for upstream install mirrors]
2025-11-01 00:10:02.172634 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.181730 | 
2025-11-01 00:10:02.181847 | TASK [ensure-docker : Include tasks for docker install]
2025-11-01 00:10:02.224359 | controller | ok
2025-11-01 00:10:02.239252 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml
2025-11-01 00:10:02.250454 | 
2025-11-01 00:10:02.250595 | TASK [ensure-docker : Not Implemented]
2025-11-01 00:10:02.275860 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.287202 | 
2025-11-01 00:10:02.287354 | TASK [Set up docker mirrors]
2025-11-01 00:10:02.318278 | controller | ok
2025-11-01 00:10:02.353823 | 
2025-11-01 00:10:02.353984 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info]
2025-11-01 00:10:02.400459 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.411112 | 
2025-11-01 00:10:02.411267 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info]
2025-11-01 00:10:02.483192 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.495011 | 
2025-11-01 00:10:02.495155 | TASK [use-docker-mirror : Set docker_mirror fact]
2025-11-01 00:10:02.653838 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.730407 | 
2025-11-01 00:10:02.730540 | TASK [use-docker-mirror : Set up docker mirrors]
2025-11-01 00:10:02.897795 | controller | skipping: Conditional result was False
2025-11-01 00:10:02.909218 | 
2025-11-01 00:10:02.909326 | TASK [Add all repositories]
2025-11-01 00:10:02.970156 | controller | ok
2025-11-01 00:10:03.055955 | 
2025-11-01 00:10:03.056064 | LOOP [ensure-package-repositories : Install repositories]
2025-11-01 00:10:03.165778 | controller | ok: "/var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml"
2025-11-01 00:10:03.165984 | controller | ok: All items complete
2025-11-01 00:10:03.166019 | 
2025-11-01 00:10:03.179358 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml
2025-11-01 00:10:03.194133 | 
2025-11-01 00:10:03.194247 | TASK [ensure-package-repositories : Create GPG key temp directory]
2025-11-01 00:10:04.403651 | controller | changed
2025-11-01 00:10:04.424323 | 
2025-11-01 00:10:04.424444 | LOOP [ensure-package-repositories : Upload GPG keys]
2025-11-01 00:10:08.249419 | controller | changed:
2025-11-01 00:10:08.249582 | controller | {
2025-11-01 00:10:08.249610 | 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-11-01 00:10:08.249683 | controller | }
2025-11-01 00:10:08.270300 | 
2025-11-01 00:10:08.270468 | LOOP [ensure-package-repositories : Import GPG keys]
2025-11-01 00:10:09.777985 | controller | changed:
2025-11-01 00:10:09.778158 | controller | {
2025-11-01 00:10:09.778185 | 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-11-01 00:10:09.778209 | controller | }
2025-11-01 00:10:09.778238 | controller | changed: All items complete
2025-11-01 00:10:09.778258 | 
2025-11-01 00:10:09.788345 | 
2025-11-01 00:10:09.788443 | TASK [ensure-package-repositories : Remove GPG temp directory]
2025-11-01 00:10:10.436545 | controller | changed
2025-11-01 00:10:10.445030 | 
2025-11-01 00:10:10.445103 | LOOP [ensure-package-repositories : Add repositories]
2025-11-01 00:10:11.280151 | controller | changed:
2025-11-01 00:10:11.281042 | controller | {
2025-11-01 00:10:11.281092 | controller |   "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable",
2025-11-01 00:10:11.281116 | controller |   "description": "Docker CE Stable - $basearch",
2025-11-01 00:10:11.281133 | controller |   "gpgcheck": true,
2025-11-01 00:10:11.281149 | controller |   "name": "docker-ce-stable"
2025-11-01 00:10:11.281167 | controller | }
2025-11-01 00:10:11.305284 | 
2025-11-01 00:10:11.305404 | TASK [ensure-docker : Install pre-reqs]
2025-11-01 00:10:16.386414 | controller | ok: Nothing to do
2025-11-01 00:10:16.399135 | 
2025-11-01 00:10:16.399269 | TASK [ensure-docker : Remove packages]
2025-11-01 00:10:19.271011 | controller | ok: Nothing to do
2025-11-01 00:10:19.277152 | 
2025-11-01 00:10:19.277234 | TASK [ensure-docker : Install upstream docker using package]
2025-11-01 00:11:37.241578 | controller | changed
2025-11-01 00:11:37.256041 | 
2025-11-01 00:11:37.256200 | TASK [ensure-docker : Setup docker]
2025-11-01 00:11:37.324330 | controller | ok
2025-11-01 00:11:37.338586 | controller | included: /var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml
2025-11-01 00:11:37.354506 | 
2025-11-01 00:11:37.354611 | TASK [ensure-docker : Ensure "docker" group exists]
2025-11-01 00:11:38.347570 | controller | ok
2025-11-01 00:11:38.358583 | 
2025-11-01 00:11:38.358764 | TASK [ensure-docker : Add user to docker group]
2025-11-01 00:11:39.407058 | controller | changed
2025-11-01 00:11:39.421175 | 
2025-11-01 00:11:39.421302 | TASK [Update docker daemon proxy configuration]
2025-11-01 00:11:39.448312 | controller | skipping: Conditional result was False
2025-11-01 00:11:39.463697 | 
2025-11-01 00:11:39.463876 | TASK [Lower default MTU]
2025-11-01 00:11:39.491165 | controller | skipping: Conditional result was False
2025-11-01 00:11:39.506109 | 
2025-11-01 00:11:39.506396 | TASK [ensure-docker : Get the status of the docket.socket unit]
2025-11-01 00:11:40.328571 | controller | inactive
2025-11-01 00:11:40.885287 | controller | ok: Runtime: 0:00:00.030571
2025-11-01 00:11:40.906854 | 
2025-11-01 00:11:40.907020 | TASK [ensure-docker : Get the status of the docket unit]
2025-11-01 00:11:41.612875 | controller | inactive
2025-11-01 00:11:41.789033 | controller | ok: Runtime: 0:00:00.019878
2025-11-01 00:11:41.799265 | 
2025-11-01 00:11:41.799357 | TASK [ensure-docker : Restart docker]
2025-11-01 00:11:41.849075 | Trigger a Docker restart
2025-11-01 00:11:41.857727 | 
2025-11-01 00:11:41.857817 | TASK [ensure-docker : Reset ssh connection to pick up docker group]
2025-11-01 00:11:41.894288 | 
2025-11-01 00:11:41.894394 | TASK [ensure-docker : Install docker-compose]
2025-11-01 00:11:41.909871 | controller | skipping: Conditional result was False
2025-11-01 00:11:41.920300 | 
2025-11-01 00:11:41.920394 | TASK [ensure-docker : Flush handlers before role exit]
2025-11-01 00:11:41.934490 | 
2025-11-01 00:11:41.934615 | TASK [ensure-docker : Stop docker.socket to avoid any conflict]
2025-11-01 00:11:45.287363 | controller | changed
2025-11-01 00:11:45.305866 | 
2025-11-01 00:11:45.305963 | TASK [ensure-docker : Assure docker service is running]
2025-11-01 00:11:49.017933 | controller | changed
2025-11-01 00:11:49.030221 | 
2025-11-01 00:11:49.030332 | TASK [ensure-docker : Assure docker.socket service is running]
2025-11-01 00:11:51.073264 | controller | ok
2025-11-01 00:11:51.085070 | 
2025-11-01 00:11:51.085202 | TASK [ensure-docker : Correct group ownership on docker sock]
2025-11-01 00:11:51.972286 | controller | ok
2025-11-01 00:11:51.981815 | 
2025-11-01 00:11:51.981962 | TASK [ensure-docker : Validate ability to talk with docker]
2025-11-01 00:11:52.605851 | controller | CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES
2025-11-01 00:11:52.840806 | controller | ok: Runtime: 0:00:00.037696
2025-11-01 00:11:52.850154 | 
2025-11-01 00:11:52.850276 | TASK [ensure-docker : Get version details]
2025-11-01 00:11:53.543036 | controller | Client: Docker Engine - Community
2025-11-01 00:11:53.543149 | controller |  Version:           24.0.7
2025-11-01 00:11:53.543161 | controller |  API version:       1.43
2025-11-01 00:11:53.543168 | controller |  Go version:        go1.20.10
2025-11-01 00:11:53.543189 | controller |  Git commit:        afdd53b
2025-11-01 00:11:53.543197 | controller |  Built:             Thu Oct 26 09:09:39 2023
2025-11-01 00:11:53.543207 | controller |  OS/Arch:           linux/amd64
2025-11-01 00:11:53.543217 | controller |  Context:           default
2025-11-01 00:11:53.543226 | controller |
2025-11-01 00:11:53.543237 | controller | Server: Docker Engine - Community
2025-11-01 00:11:53.543266 | controller |  Engine:
2025-11-01 00:11:53.545282 | controller |   Version:          24.0.7
2025-11-01 00:11:53.545304 | controller |   API version:      1.43 (minimum version 1.12)
2025-11-01 00:11:53.545311 | controller |   Go version:       go1.20.10
2025-11-01 00:11:53.545317 | controller |   Git commit:       311b9ff
2025-11-01 00:11:53.545324 | controller |   Built:            Thu Oct 26 09:08:11 2023
2025-11-01 00:11:53.545331 | controller |   OS/Arch:          linux/amd64
2025-11-01 00:11:53.545337 | controller |   Experimental:     false
2025-11-01 00:11:53.545343 | controller |  containerd:
2025-11-01 00:11:53.545349 | controller |   Version:          1.6.25
2025-11-01 00:11:53.545356 | controller |   GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
2025-11-01 00:11:53.545362 | controller |  runc:
2025-11-01 00:11:53.545368 | controller |   Version:          1.1.10
2025-11-01 00:11:53.545374 | controller |   GitCommit:        v1.1.10-0-g18a0cb0
2025-11-01 00:11:53.545384 | controller |  docker-init:
2025-11-01 00:11:53.545390 | controller |   Version:          0.19.0
2025-11-01 00:11:53.545396 | controller |   GitCommit:        de40ad0
2025-11-01 00:11:53.756287 | controller | ok: Runtime: 0:00:00.048145
2025-11-01 00:11:53.770571 | 
2025-11-01 00:11:53.770752 | TASK [ensure-docker : Dump installed docker details]
2025-11-01 00:11:53.813209 | {'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-11-01 00:11:53.497987', 'end': '2025-11-01 00:11:53.546132', 'delta': '0:00:00.048145', 'msg': '', 'zuul_log_id': 'fa163efc-24cc-8011-44b5-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-11-01 00:11:53.827359 | 
2025-11-01 00:11:53.827700 | TASK [Use buildset registry]
2025-11-01 00:11:53.856016 | controller | skipping: Conditional result was False
2025-11-01 00:11:53.872304 | 
2025-11-01 00:11:53.872395 | TASK [Ensure python3.8 is present]
2025-11-01 00:11:53.897296 | controller | skipping: Conditional result was False
2025-11-01 00:11:53.906383 | 
2025-11-01 00:11:53.906537 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-01 00:11:53.932923 | controller | ok
2025-11-01 00:11:53.960993 | 
2025-11-01 00:11:53.961107 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-01 00:12:01.348281 | controller | ok: Nothing to do
2025-11-01 00:12:01.362069 | 
2025-11-01 00:12:01.362847 | TASK [our-ensure-python : Also install python3-devel]
2025-11-01 00:12:15.625138 | controller | changed
2025-11-01 00:12:15.656049 | 
2025-11-01 00:12:15.656132 | TASK [Run ensure-virtualenv role]
2025-11-01 00:12:15.679747 | controller | ok
2025-11-01 00:12:15.708897 | 
2025-11-01 00:12:15.709003 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-01 00:12:16.473966 | controller | /usr/bin/virtualenv
2025-11-01 00:12:17.067127 | controller | ok: Runtime: 0:00:00.008649
2025-11-01 00:12:17.073186 | 
2025-11-01 00:12:17.073255 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-01 00:12:17.110546 | controller | skipping: Conditional result was False
2025-11-01 00:12:17.110826 | controller | changed: All items complete
2025-11-01 00:12:17.110856 | 
2025-11-01 00:12:17.131508 | 
2025-11-01 00:12:17.131677 | TASK [Find the full path of the Python interpreter]
2025-11-01 00:12:17.925180 | controller | /usr/bin/python3.8
2025-11-01 00:12:18.507685 | controller | ok
2025-11-01 00:12:18.513910 | 
2025-11-01 00:12:18.514004 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-01 00:12:21.063301 | controller | created virtual environment CPython3.8.18.final.0-64 in 1188ms
2025-11-01 00:12:21.115855 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-01 00:12:21.115887 | 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-11-01 00:12:21.115912 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-01 00:12:21.115933 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-01 00:12:21.375729 | controller | changed
2025-11-01 00:12:21.392439 | 
2025-11-01 00:12:21.392715 | TASK [Set selinux package]
2025-11-01 00:12:21.442417 | controller | ok
2025-11-01 00:12:21.448457 | 
2025-11-01 00:12:21.448537 | TASK [Set selinux package (Fedora)]
2025-11-01 00:12:21.479560 | controller | ok
2025-11-01 00:12:21.485986 | 
2025-11-01 00:12:21.486065 | TASK [Install selinux into virtualenv]
2025-11-01 00:12:27.056152 | controller | Collecting selinux-please-lie-to-me
2025-11-01 00:12:27.179856 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-01 00:12:28.536802 | controller | Collecting setuptools<50.0.0
2025-11-01 00:12:28.549327 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-01 00:12:28.658225 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 7.9 MB/s eta 0:00:00
2025-11-01 00:12:28.782481 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-01 00:12:28.782744 | controller |   Attempting uninstall: setuptools
2025-11-01 00:12:28.783908 | controller |     Found existing installation: setuptools 62.6.0
2025-11-01 00:12:28.905398 | controller |     Uninstalling setuptools-62.6.0:
2025-11-01 00:12:28.921840 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-01 00:12:29.593048 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-01 00:12:29.786759 | controller |
2025-11-01 00:12:30.021541 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-11-01 00:12:30.021571 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-11-01 00:12:30.355247 | controller | ok: Runtime: 0:00:07.565308
2025-11-01 00:12:30.361511 | 
2025-11-01 00:12:30.361586 | TASK [Install pytest-forked into virtualenv]
2025-11-01 00:12:32.092869 | controller | Collecting pytest-forked
2025-11-01 00:12:32.146251 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-01 00:12:32.205379 | controller | Collecting py
2025-11-01 00:12:32.210192 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-01 00:12:32.242711 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.1 MB/s eta 0:00:00
2025-11-01 00:12:32.417681 | controller | Collecting pytest>=3.10
2025-11-01 00:12:32.460392 | controller |   Downloading pytest-8.3.5-py3-none-any.whl (343 kB)
2025-11-01 00:12:32.480734 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 343.6/343.6 kB 21.2 MB/s eta 0:00:00
2025-11-01 00:12:32.553101 | controller | Collecting pluggy<2,>=1.5
2025-11-01 00:12:32.558367 | controller |   Downloading pluggy-1.5.0-py3-none-any.whl (20 kB)
2025-11-01 00:12:32.606892 | controller | Collecting exceptiongroup>=1.0.0rc8
2025-11-01 00:12:32.612094 | controller |   Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB)
2025-11-01 00:12:32.644483 | controller | Collecting iniconfig
2025-11-01 00:12:32.649269 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-11-01 00:12:32.723249 | controller | Collecting tomli>=1
2025-11-01 00:12:32.728247 | controller |   Downloading tomli-2.3.0-py3-none-any.whl (14 kB)
2025-11-01 00:12:32.792381 | controller | Collecting packaging
2025-11-01 00:12:32.797125 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-01 00:12:32.805599 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.1 MB/s eta 0:00:00
2025-11-01 00:12:32.874915 | controller | Collecting typing-extensions>=4.6.0
2025-11-01 00:12:32.880148 | controller |   Downloading typing_extensions-4.13.2-py3-none-any.whl (45 kB)
2025-11-01 00:12:32.891081 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 4.9 MB/s eta 0:00:00
2025-11-01 00:12:32.990552 | controller | Installing collected packages: typing-extensions, tomli, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked
2025-11-01 00:12:33.689377 | 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.3.0 typing-extensions-4.13.2
2025-11-01 00:12:33.694576 | controller |
2025-11-01 00:12:33.872554 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-11-01 00:12:33.872610 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-11-01 00:12:34.241201 | controller | ok: Runtime: 0:00:02.508993
2025-11-01 00:12:34.258304 | 
2025-11-01 00:12:34.258507 | TASK [Update pip]
2025-11-01 00:12:37.120236 | controller | Requirement already satisfied: pip in ./venv/lib/python3.8/site-packages (22.2.2)
2025-11-01 00:12:37.631499 | controller | Collecting pip
2025-11-01 00:12:37.697555 | controller |   Downloading pip-25.0.1-py3-none-any.whl (1.8 MB)
2025-11-01 00:12:37.758796 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 32.4 MB/s eta 0:00:00
2025-11-01 00:12:37.893301 | controller | Installing collected packages: pip
2025-11-01 00:12:37.893539 | controller |   Attempting uninstall: pip
2025-11-01 00:12:37.894599 | controller |     Found existing installation: pip 22.2.2
2025-11-01 00:12:38.498876 | controller |     Uninstalling pip-22.2.2:
2025-11-01 00:12:38.588150 | controller |       Successfully uninstalled pip-22.2.2
2025-11-01 00:12:41.172628 | controller | Successfully installed pip-25.0.1
2025-11-01 00:12:41.656202 | controller | ok: Runtime: 0:00:05.867435
2025-11-01 00:12:41.670601 | 
2025-11-01 00:12:41.670832 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-01 00:12:42.815016 | controller | changed
2025-11-01 00:12:42.831885 | 
2025-11-01 00:12:42.832060 | TASK [Install ansible into virtualenv]
2025-11-01 00:12:44.515583 | controller | Processing ./src/github.com/ansible/ansible
2025-11-01 00:12:44.517052 | controller |   Preparing metadata (setup.py): started
2025-11-01 00:12:45.243908 | controller |   Preparing metadata (setup.py): finished with status 'done'
2025-11-01 00:12:45.303527 | controller | Collecting jinja2 (from ansible-base==2.10.17.post0)
2025-11-01 00:12:45.316566 | controller |   Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB)
2025-11-01 00:12:45.400124 | controller | Collecting PyYAML (from ansible-base==2.10.17.post0)
2025-11-01 00:12:45.405319 | controller |   Downloading PyYAML-6.0.3-cp38-cp38-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl.metadata (2.1 kB)
2025-11-01 00:12:45.800900 | controller | Collecting cryptography (from ansible-base==2.10.17.post0)
2025-11-01 00:12:45.808711 | controller |   Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB)
2025-11-01 00:12:45.830903 | controller | Requirement already satisfied: packaging in ./venv/lib/python3.8/site-packages (from ansible-base==2.10.17.post0) (25.0)
2025-11-01 00:12:46.037052 | controller | Collecting cffi>=1.14 (from cryptography->ansible-base==2.10.17.post0)
2025-11-01 00:12:46.042235 | controller |   Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (1.5 kB)
2025-11-01 00:12:46.053372 | 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-11-01 00:12:46.168194 | controller | Collecting MarkupSafe>=2.0 (from jinja2->ansible-base==2.10.17.post0)
2025-11-01 00:12:46.175324 | controller |   Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB)
2025-11-01 00:12:46.208409 | controller | Collecting pycparser (from cffi>=1.14->cryptography->ansible-base==2.10.17.post0)
2025-11-01 00:12:46.214336 | controller |   Downloading pycparser-2.23-py3-none-any.whl.metadata (993 bytes)
2025-11-01 00:12:46.230813 | controller | Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl (4.5 MB)
2025-11-01 00:12:46.282546 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.5/4.5 MB 99.7 MB/s eta 0:00:00
2025-11-01 00:12:46.289213 | controller | Downloading jinja2-3.1.6-py3-none-any.whl (134 kB)
2025-11-01 00:12:46.301947 | controller | Downloading PyYAML-6.0.3-cp38-cp38-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl (806 kB)
2025-11-01 00:12:46.318612 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 806.0/806.0 kB 45.5 MB/s eta 0:00:00
2025-11-01 00:12:46.323550 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB)
2025-11-01 00:12:46.342564 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (26 kB)
2025-11-01 00:12:46.357794 | controller | Downloading pycparser-2.23-py3-none-any.whl (118 kB)
2025-11-01 00:12:46.388868 | controller | Building wheels for collected packages: ansible-base
2025-11-01 00:12:46.390880 | controller |   Building wheel for ansible-base (setup.py): started
2025-11-01 00:12:48.452897 | controller |   Building wheel for ansible-base (setup.py): finished with status 'done'
2025-11-01 00:12:48.455103 | controller |   Created wheel for ansible-base: filename=ansible_base-2.10.17.post0-py3-none-any.whl size=1881569 sha256=4de17e9a6c1c79661e55fc9fe8c742b85f0f975cb8703243e5babe6289ee928c
2025-11-01 00:12:48.455449 | controller |   Stored in directory: /var/tmp/ansible-test-pip/pip-ephem-wheel-cache-4jt9abpn/wheels/a5/4b/fa/b6deaae105422b0b3b92831e0369d44bf7fca5bb3413d79be7
2025-11-01 00:12:48.469303 | controller | Successfully built ansible-base
2025-11-01 00:12:48.522914 | controller | Installing collected packages: PyYAML, pycparser, MarkupSafe, jinja2, cffi, cryptography, ansible-base
2025-11-01 00:12:51.041081 | controller | Successfully installed MarkupSafe-2.1.5 PyYAML-6.0.3 ansible-base-2.10.17.post0 cffi-1.17.1 cryptography-46.0.3 jinja2-3.1.6 pycparser-2.23
2025-11-01 00:12:51.715630 | controller | ok: Runtime: 0:00:07.412495
2025-11-01 00:12:51.728058 | 
2025-11-01 00:12:51.728190 | TASK [Setup download-artifact-fork role]
2025-11-01 00:12:51.758615 | controller | ok
2025-11-01 00:12:51.782876 | 
2025-11-01 00:12:51.782994 | TASK [download-artifact-fork : Parse inventory response]
2025-11-01 00:12:51.837551 | controller | ok
2025-11-01 00:12:51.854946 | 
2025-11-01 00:12:51.855121 | TASK [download-artifact-fork : Fetch info from Zuul API]
2025-11-01 00:12:51.900890 | controller | skipping: Conditional result was False
2025-11-01 00:12:51.910215 | 
2025-11-01 00:12:51.910337 | TASK [download-artifact-fork : Parse build response]
2025-11-01 00:12:51.935148 | controller | skipping: Conditional result was False
2025-11-01 00:12:51.946093 | 
2025-11-01 00:12:51.946249 | TASK [download-artifact-fork : Ensure artifacts directory exists]
2025-11-01 00:12:52.744977 | controller | changed
2025-11-01 00:12:52.796250 | 
2025-11-01 00:12:52.796374 | LOOP [download-artifact-fork : Download archive by type]
2025-11-01 00:12:52.821266 | controller | skipping: Conditional result was False
2025-11-01 00:12:52.821682 | 
2025-11-01 00:12:55.265773 | controller | changed: OK (20195 bytes)
2025-11-01 00:12:55.280359 | 
2025-11-01 00:12:55.280507 | TASK [deploy-artifacts : define __collections]
2025-11-01 00:12:55.312230 | controller | ok
2025-11-01 00:12:55.318199 | 
2025-11-01 00:12:55.318265 | LOOP [deploy-artifacts : Create list of collections]
2025-11-01 00:12:55.350333 | controller | skipping: Conditional result was False
2025-11-01 00:12:55.359845 | controller | ok:
2025-11-01 00:12:55.359916 | controller | {
2025-11-01 00:12:55.359939 | controller |   "branch": "main",
2025-11-01 00:12:55.359956 | controller |   "job": "build-ansible-collection",
2025-11-01 00:12:55.359972 | controller |   "metadata": {
2025-11-01 00:12:55.359989 | controller |     "type": "ansible_collection",
2025-11-01 00:12:55.360004 | controller |     "version": "5.0.0"
2025-11-01 00:12:55.360020 | controller |   },
2025-11-01 00:12:55.360035 | controller |   "name": "ansible.network",
2025-11-01 00:12:55.360050 | controller |   "project": "ansible-collections/ansible.network",
2025-11-01 00:12:55.360066 | controller |   "url": "https://9394b742839ff234e4eb-ef798df73aa4a2c34d0c454baba00769.ssl.cf1.rackcdn.com/ansible/13e68b360c224f4b8df7e0540a7bfa0e/artifacts/ansible-network-5.0.0.tar.gz"
2025-11-01 00:12:55.360088 | controller | }
2025-11-01 00:12:55.371783 | 
2025-11-01 00:12:55.371910 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy]
2025-11-01 00:12:56.697754 | controller | Starting galaxy collection install process
2025-11-01 00:12:56.698212 | controller | Process install dependency map
2025-11-01 00:13:10.332956 | controller | Starting collection install process
2025-11-01 00:13:10.333234 | controller | Installing 'ansible.network:5.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/network'
2025-11-01 00:13:10.346952 | controller | ansible.network (5.0.0) was installed successfully
2025-11-01 00:13:10.347092 | controller | Installing 'ansible.netcommon:8.1.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2025-11-01 00:13:10.347317 | 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-4020_ucfn49n/tmppzq5iy_h
2025-11-01 00:13:11.877450 | controller | ansible.netcommon (8.1.0) was installed successfully
2025-11-01 00:13:11.877614 | controller | Installing 'ansible.utils:6.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/utils'
2025-11-01 00:13:11.877920 | 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-4020_ucfn49n/tmppzq5iy_h
2025-11-01 00:13:13.752877 | controller | ansible.utils (6.0.0) was installed successfully
2025-11-01 00:13:13.753062 | controller | Installing 'arista.eos:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/arista/eos'
2025-11-01 00:13:13.753337 | 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-4020_ucfn49n/tmppzq5iy_h
2025-11-01 00:13:16.280220 | controller | arista.eos (12.0.0) was installed successfully
2025-11-01 00:13:16.280489 | controller | Installing 'cisco.ios:11.1.1' to '/home/zuul/.ansible/collections/ansible_collections/cisco/ios'
2025-11-01 00:13:16.280513 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-ios-11.1.1.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4020_ucfn49n/tmppzq5iy_h
2025-11-01 00:13:18.907102 | controller | cisco.ios (11.1.1) was installed successfully
2025-11-01 00:13:18.907272 | controller | Installing 'cisco.iosxr:12.1.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/iosxr'
2025-11-01 00:13:18.907289 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-iosxr-12.1.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4020_ucfn49n/tmppzq5iy_h
2025-11-01 00:13:22.016601 | controller | cisco.iosxr (12.1.0) was installed successfully
2025-11-01 00:13:22.016784 | controller | Installing 'cisco.nxos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/nxos'
2025-11-01 00:13:22.017186 | 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-4020_ucfn49n/tmppzq5iy_h
2025-11-01 00:13:25.389955 | controller | cisco.nxos (11.0.0) was installed successfully
2025-11-01 00:13:25.390147 | controller | Installing 'junipernetworks.junos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/junipernetworks/junos'
2025-11-01 00:13:25.390629 | 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-4020_ucfn49n/tmppzq5iy_h
2025-11-01 00:13:27.705032 | controller | junipernetworks.junos (11.0.0) was installed successfully
2025-11-01 00:13:28.248114 | controller | ok: Runtime: 0:00:31.758510
2025-11-01 00:13:28.274894 | 
2025-11-01 00:13:28.275069 | TASK [podman may need iptables kernel modules]
2025-11-01 00:13:29.650409 | controller | ok: Runtime: 0:00:00.011848
2025-11-01 00:13:29.684154 | 
2025-11-01 00:13:29.684312 | PLAY RECAP
2025-11-01 00:13:29.684399 | controller | ok: 46 changed: 26 unreachable: 0 failed: 0 skipped: 17 rescued: 0 ignored: 0
2025-11-01 00:13:29.684444 | 
2025-11-01 00:13:29.930393 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-01 00:13:29.931967 | RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-11-01 00:13:30.535695 | 
2025-11-01 00:13:30.535803 | PLAY [controller]
2025-11-01 00:13:30.558719 | 
2025-11-01 00:13:30.558823 | TASK [Copy the galaxy.yml on the controller]
2025-11-01 00:13:34.563644 | controller | changed
2025-11-01 00:13:34.570472 | 
2025-11-01 00:13:34.570562 | TASK [Load information from galaxy.yml]
2025-11-01 00:13:34.609327 | controller | ok
2025-11-01 00:13:34.623052 | 
2025-11-01 00:13:34.623194 | LOOP [Enable FIPS mode]
2025-11-01 00:13:34.650118 | 
2025-11-01 00:13:34.650372 | LOOP [ansible-test : Include branch specific variables.]
2025-11-01 00:13:34.685250 | controller | ok: "/var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/untrusted/project_2/github.com/ansible/ansible-zuul-jobs/roles/ansible-test/vars/default.yaml"
2025-11-01 00:13:34.685407 | 
2025-11-01 00:13:34.694853 | 
2025-11-01 00:13:34.694994 | TASK [ansible-test : Setup --skip-tags for test_options]
2025-11-01 00:13:34.735849 | controller | ok
2025-11-01 00:13:34.742097 | 
2025-11-01 00:13:34.742190 | TASK [ansible-test : Enable --inventory for network-integration]
2025-11-01 00:13:34.766527 | controller | skipping: Conditional result was False
2025-11-01 00:13:34.774050 | 
2025-11-01 00:13:34.774138 | TASK [ansible-test : Enable --retry-on-error]
2025-11-01 00:13:34.788144 | controller | skipping: Conditional result was False
2025-11-01 00:13:34.795134 | 
2025-11-01 00:13:34.795246 | TASK [ansible-test : Enable --continue-on-error]
2025-11-01 00:13:34.825088 | controller | ok
2025-11-01 00:13:34.830597 | 
2025-11-01 00:13:34.830661 | TASK [ansible-test : Enable --requirements]
2025-11-01 00:13:34.844082 | controller | skipping: Conditional result was False
2025-11-01 00:13:34.851250 | 
2025-11-01 00:13:34.851320 | TASK [ansible-test : Adjust options for unit tests]
2025-11-01 00:13:34.875376 | controller | skipping: Conditional result was False
2025-11-01 00:13:34.882332 | 
2025-11-01 00:13:34.882413 | TASK [ansible-test : Install requirements with unit tests]
2025-11-01 00:13:34.937254 | controller | ok
2025-11-01 00:13:34.943135 | 
2025-11-01 00:13:34.943207 | TASK [ansible-test : Set --skip-test]
2025-11-01 00:13:34.987234 | controller | skipping: Conditional result was False
2025-11-01 00:13:34.993773 | 
2025-11-01 00:13:34.993841 | TASK [ansible-test : Reduce verbosity]
2025-11-01 00:13:35.023333 | controller | ok
2025-11-01 00:13:35.028869 | 
2025-11-01 00:13:35.028932 | TASK [ansible-test : Setup --python option]
2025-11-01 00:13:35.053857 | controller | skipping: Conditional result was False
2025-11-01 00:13:35.060554 | 
2025-11-01 00:13:35.060637 | TASK [ansible-test : Setup --docker option]
2025-11-01 00:13:35.102344 | controller | ok
2025-11-01 00:13:35.112463 | 
2025-11-01 00:13:35.112561 | TASK [ansible-test : check if MANIFEST.json exists]
2025-11-01 00:13:36.495334 | controller | ok
2025-11-01 00:13:36.510580 | 
2025-11-01 00:13:36.510775 | TASK [ansible-test : Copy the MANIFEST.json on the controller]
2025-11-01 00:13:36.541143 | controller | skipping: Conditional result was False
2025-11-01 00:13:36.557090 | 
2025-11-01 00:13:36.557251 | TASK [ansible-test : Load information from MANIFEST.json]
2025-11-01 00:13:36.575429 | controller | skipping: Conditional result was False
2025-11-01 00:13:36.592622 | 
2025-11-01 00:13:36.592812 | TASK [ansible-test : Setup location of project for integration tests]
2025-11-01 00:13:36.609751 | controller | skipping: Conditional result was False
2025-11-01 00:13:36.623931 | 
2025-11-01 00:13:36.624089 | TASK [ansible-test : Copy the galaxy.yml on the controller]
2025-11-01 00:13:38.157483 | controller | ok
2025-11-01 00:13:38.163982 | 
2025-11-01 00:13:38.164066 | TASK [ansible-test : Load information from galaxy.yml]
2025-11-01 00:13:38.206220 | controller | ok
2025-11-01 00:13:38.212415 | 
2025-11-01 00:13:38.212490 | TASK [ansible-test : Setup location of project for integration tests]
2025-11-01 00:13:38.253631 | controller | ok
2025-11-01 00:13:38.260443 | 
2025-11-01 00:13:38.260539 | TASK [ansible-test : Setup minimum test requirements]
2025-11-01 00:13:38.290760 | controller | ok
2025-11-01 00:13:38.297561 | 
2025-11-01 00:13:38.297701 | TASK [ansible-test : Ensure pip temp directory exists in /var/tmp]
2025-11-01 00:13:39.277982 | controller | ok
2025-11-01 00:13:39.290130 | 
2025-11-01 00:13:39.290306 | TASK [ansible-test : Install python requirements]
2025-11-01 00:13:40.679066 | controller | Collecting yamllint (from -r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-11-01 00:13:40.702493 | controller |   Downloading yamllint-1.35.1-py3-none-any.whl.metadata (4.2 kB)
2025-11-01 00:13:40.736880 | controller | Collecting pathspec>=0.5.3 (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-11-01 00:13:40.743034 | controller |   Downloading pathspec-0.12.1-py3-none-any.whl.metadata (21 kB)
2025-11-01 00:13:40.756797 | 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-11-01 00:13:40.765899 | controller | Downloading yamllint-1.35.1-py3-none-any.whl (66 kB)
2025-11-01 00:13:40.782278 | controller | Downloading pathspec-0.12.1-py3-none-any.whl (31 kB)
2025-11-01 00:13:40.837758 | controller | Installing collected packages: pathspec, yamllint
2025-11-01 00:13:40.932378 | controller | Successfully installed pathspec-0.12.1 yamllint-1.35.1
2025-11-01 00:13:41.660563 | controller | ok: Runtime: 0:00:01.056525
2025-11-01 00:13:41.669736 | 
2025-11-01 00:13:41.669864 | TASK [ansible-test : Fetch the integration_config.yml file from the controller]
2025-11-01 00:13:43.248625 | controller | ERROR
2025-11-01 00:13:43.248869 | controller | {
2025-11-01 00:13:43.248902 | controller |   "msg": "the remote file does not exist, not transferring, ignored"
2025-11-01 00:13:43.248921 | controller | }
2025-11-01 00:13:43.248945 | controller | ERROR: Ignoring Errors
2025-11-01 00:13:43.257836 | 
2025-11-01 00:13:43.257974 | TASK [ansible-test : Copy potential cloud provider configuration for ansible-test in the collection]
2025-11-01 00:13:43.636080 | controller | skipping: Conditional result was False
2025-11-01 00:13:43.642626 | 
2025-11-01 00:13:43.642718 | TASK [ansible-test : Enable persistent connection logging]
2025-11-01 00:13:44.970451 | controller | changed: section and option added
2025-11-01 00:13:44.984532 | 
2025-11-01 00:13:44.984708 | TASK [ansible-test : Set persistent ssh_type value]
2025-11-01 00:13:46.136189 | controller | changed: option added
2025-11-01 00:13:46.151182 | 
2025-11-01 00:13:46.151356 | TASK [ansible-test : Set ansible log path]
2025-11-01 00:13:47.266656 | controller | changed: section and option added
2025-11-01 00:13:47.273038 | 
2025-11-01 00:13:47.273116 | TASK [ansible-test : Identify the changed targets]
2025-11-01 00:13:47.629090 | controller | skipping: Conditional result was False
2025-11-01 00:13:47.645238 | 
2025-11-01 00:13:47.645410 | TASK [ansible-test : set_fact]
2025-11-01 00:13:47.693388 | controller | skipping: Conditional result was False
2025-11-01 00:13:47.703469 | 
2025-11-01 00:13:47.703613 | TASK [ansible-test : Set the targets]
2025-11-01 00:13:47.738856 | controller | ok
2025-11-01 00:13:47.745206 | 
2025-11-01 00:13:47.745302 | TASK [ansible-test : set_fact]
2025-11-01 00:13:47.759465 | controller | skipping: Conditional result was False
2025-11-01 00:13:47.767209 | 
2025-11-01 00:13:47.767327 | TASK [ansible-test : List the targets]
2025-11-01 00:13:48.160255 | controller | skipping: Conditional result was False
2025-11-01 00:13:48.177231 | 
2025-11-01 00:13:48.177452 | TASK [ansible-test : set_fact]
2025-11-01 00:13:48.207124 | controller | skipping: Conditional result was False
2025-11-01 00:13:48.223053 | 
2025-11-01 00:13:48.223243 | TASK [ansible-test : set_fact]
2025-11-01 00:13:48.252193 | controller | skipping: Conditional result was False
2025-11-01 00:13:48.262605 | 
2025-11-01 00:13:48.262748 | LOOP [ansible-test : set_fact]
2025-11-01 00:13:48.317350 | 
2025-11-01 00:13:48.317541 | TASK [ansible-test : set_fact]
2025-11-01 00:13:48.343159 | controller | skipping: Conditional result was False
2025-11-01 00:13:48.352471 | 
2025-11-01 00:13:48.352577 | TASK [ansible-test : debug]
2025-11-01 00:13:48.378336 | controller | skipping: Conditional result was False
2025-11-01 00:13:48.386660 | 
2025-11-01 00:13:48.386798 | TASK [ansible-test : debug]
2025-11-01 00:13:48.420712 | About to run: ansible-test sanity --requirements --docker -v
2025-11-01 00:13:48.428213 | 
2025-11-01 00:13:48.428306 | TASK [ansible-test : Run the test suite]
2025-11-01 00:13:49.513965 | controller | Run command: docker images quay.io/ansible/default-test-container:2.9.0 --format '{{json .}}'
2025-11-01 00:13:49.573114 | controller | Run command: docker pull quay.io/ansible/default-test-container:2.9.0
2025-11-01 00:13:51.045257 | controller | 2.9.0: Pulling from ansible/default-test-container
2025-11-01 00:13:51.412846 | controller | 171857c49d0f: Pulling fs layer
2025-11-01 00:13:51.412939 | controller | 419640447d26: Pulling fs layer
2025-11-01 00:13:51.412948 | controller | 61e52f862619: Pulling fs layer
2025-11-01 00:13:51.412955 | controller | 851de0426e26: Pulling fs layer
2025-11-01 00:13:51.412964 | controller | 37425716ea5b: Pulling fs layer
2025-11-01 00:13:51.413045 | controller | cd9b0c439616: Pulling fs layer
2025-11-01 00:13:51.413055 | controller | d4612dbd8855: Pulling fs layer
2025-11-01 00:13:51.413061 | controller | 554699364730: Pulling fs layer
2025-11-01 00:13:51.413068 | controller | 1ff15d4bdb3e: Pulling fs layer
2025-11-01 00:13:51.413074 | controller | 5f2e4724adea: Pulling fs layer
2025-11-01 00:13:51.413080 | controller | a02d9a95ccb8: Pulling fs layer
2025-11-01 00:13:51.413087 | controller | 989f4ce370cb: Pulling fs layer
2025-11-01 00:13:51.413093 | controller | 0d7f52cdf9df: Pulling fs layer
2025-11-01 00:13:51.413099 | controller | c423742351d5: Pulling fs layer
2025-11-01 00:13:51.413106 | controller | 109236341d21: Pulling fs layer
2025-11-01 00:13:51.413112 | controller | 07a2f61c96b8: Pulling fs layer
2025-11-01 00:13:51.413118 | controller | 041f122f27ae: Pulling fs layer
2025-11-01 00:13:51.413124 | controller | ca6f5098b12e: Pulling fs layer
2025-11-01 00:13:51.413130 | controller | 1eb3e7b2afd9: Pulling fs layer
2025-11-01 00:13:51.413136 | controller | 18a0b750727a: Pulling fs layer
2025-11-01 00:13:51.413143 | controller | 17f2f596716c: Pulling fs layer
2025-11-01 00:13:51.413155 | controller | f35a9998a9bd: Pulling fs layer
2025-11-01 00:13:51.413162 | controller | fdfc10566405: Pulling fs layer
2025-11-01 00:13:51.413168 | controller | 1ff1c442c5fe: Pulling fs layer
2025-11-01 00:13:51.413174 | controller | a3443c4a17ed: Pulling fs layer
2025-11-01 00:13:51.413180 | controller | 0edcf9fb2b15: Pulling fs layer
2025-11-01 00:13:51.413186 | controller | 5af43b69e845: Pulling fs layer
2025-11-01 00:13:51.413192 | controller | 1651773effb2: Pulling fs layer
2025-11-01 00:13:51.413198 | controller | 79e23c5c0fe4: Pulling fs layer
2025-11-01 00:13:51.413209 | controller | e5058b1faaa6: Pulling fs layer
2025-11-01 00:13:51.413215 | controller | 846775490569: Pulling fs layer
2025-11-01 00:13:51.413221 | controller | 041f122f27ae: Waiting
2025-11-01 00:13:51.413228 | controller | ca6f5098b12e: Waiting
2025-11-01 00:13:51.413234 | controller | 1eb3e7b2afd9: Waiting
2025-11-01 00:13:51.413240 | controller | 18a0b750727a: Waiting
2025-11-01 00:13:51.413246 | controller | 17f2f596716c: Waiting
2025-11-01 00:13:51.413252 | controller | f35a9998a9bd: Waiting
2025-11-01 00:13:51.413261 | controller | fdfc10566405: Waiting
2025-11-01 00:13:51.413298 | controller | 1ff1c442c5fe: Waiting
2025-11-01 00:13:51.413304 | controller | a3443c4a17ed: Waiting
2025-11-01 00:13:51.413310 | controller | 0edcf9fb2b15: Waiting
2025-11-01 00:13:51.413316 | controller | 5af43b69e845: Waiting
2025-11-01 00:13:51.413322 | controller | 1651773effb2: Waiting
2025-11-01 00:13:51.413328 | controller | 851de0426e26: Waiting
2025-11-01 00:13:51.413335 | controller | 37425716ea5b: Waiting
2025-11-01 00:13:51.413340 | controller | 79e23c5c0fe4: Waiting
2025-11-01 00:13:51.413346 | controller | e5058b1faaa6: Waiting
2025-11-01 00:13:51.413353 | controller | 846775490569: Waiting
2025-11-01 00:13:51.413359 | controller | cd9b0c439616: Waiting
2025-11-01 00:13:51.413369 | controller | d4612dbd8855: Waiting
2025-11-01 00:13:51.413375 | controller | 989f4ce370cb: Waiting
2025-11-01 00:13:51.413381 | controller | 0d7f52cdf9df: Waiting
2025-11-01 00:13:51.413387 | controller | c423742351d5: Waiting
2025-11-01 00:13:51.413394 | controller | 109236341d21: Waiting
2025-11-01 00:13:51.413400 | controller | 554699364730: Waiting
2025-11-01 00:13:51.413406 | controller | 1ff15d4bdb3e: Waiting
2025-11-01 00:13:51.413412 | controller | 07a2f61c96b8: Waiting
2025-11-01 00:13:51.413418 | controller | a02d9a95ccb8: Waiting
2025-11-01 00:13:51.413424 | controller | 5f2e4724adea: Waiting
2025-11-01 00:13:51.413442 | controller | 61e52f862619: Verifying Checksum
2025-11-01 00:13:51.416688 | controller | 61e52f862619: Download complete
2025-11-01 00:13:51.416720 | controller | 419640447d26: Verifying Checksum
2025-11-01 00:13:51.695666 | controller | 419640447d26: Download complete
2025-11-01 00:13:51.695760 | controller | 171857c49d0f: Verifying Checksum
2025-11-01 00:13:51.695882 | controller | 171857c49d0f: Download complete
2025-11-01 00:13:52.585149 | controller | 851de0426e26: Verifying Checksum
2025-11-01 00:13:52.612474 | controller | 851de0426e26: Download complete
2025-11-01 00:13:52.612564 | controller | cd9b0c439616: Verifying Checksum
2025-11-01 00:13:53.633952 | controller | cd9b0c439616: Download complete
2025-11-01 00:13:53.634038 | controller | d4612dbd8855: Verifying Checksum
2025-11-01 00:13:54.779956 | controller | d4612dbd8855: Download complete
2025-11-01 00:13:54.780046 | controller | 1ff15d4bdb3e: Verifying Checksum
2025-11-01 00:13:55.292492 | controller | 1ff15d4bdb3e: Download complete
2025-11-01 00:13:55.292595 | controller | 171857c49d0f: Pull complete
2025-11-01 00:13:55.313992 | controller | 419640447d26: Pull complete
2025-11-01 00:13:55.334965 | controller | 61e52f862619: Pull complete
2025-11-01 00:13:55.378650 | controller | 851de0426e26: Pull complete
2025-11-01 00:13:55.899167 | controller | 5f2e4724adea: Verifying Checksum
2025-11-01 00:13:57.614632 | controller | a02d9a95ccb8: Verifying Checksum
2025-11-01 00:13:58.699915 | controller | a02d9a95ccb8: Download complete
2025-11-01 00:13:58.700013 | controller | 989f4ce370cb: Verifying Checksum
2025-11-01 00:13:58.700094 | controller | 989f4ce370cb: Download complete
2025-11-01 00:13:59.647294 | controller | 0d7f52cdf9df: Verifying Checksum
2025-11-01 00:13:59.647437 | controller | 0d7f52cdf9df: Download complete
2025-11-01 00:14:00.510439 | controller | c423742351d5: Verifying Checksum
2025-11-01 00:14:00.510576 | controller | c423742351d5: Download complete
2025-11-01 00:14:06.939024 | controller | 554699364730: Verifying Checksum
2025-11-01 00:14:07.948049 | controller | 554699364730: Download complete
2025-11-01 00:14:07.948149 | controller | 07a2f61c96b8: Download complete
2025-11-01 00:14:08.983563 | controller | 041f122f27ae: Verifying Checksum
2025-11-01 00:14:10.222619 | controller | 041f122f27ae: Download complete
2025-11-01 00:14:10.222722 | controller | 109236341d21: Verifying Checksum
2025-11-01 00:14:11.075072 | controller | 109236341d21: Download complete
2025-11-01 00:14:11.075185 | controller | ca6f5098b12e: Verifying Checksum
2025-11-01 00:14:11.740197 | controller | ca6f5098b12e: Download complete
2025-11-01 00:14:11.740286 | controller | 1eb3e7b2afd9: Verifying Checksum
2025-11-01 00:14:11.741378 | controller | 1eb3e7b2afd9: Download complete
2025-11-01 00:14:12.653586 | controller | 17f2f596716c: Verifying Checksum
2025-11-01 00:14:12.653946 | controller | 17f2f596716c: Download complete
2025-11-01 00:14:13.039438 | controller | 18a0b750727a: Verifying Checksum
2025-11-01 00:14:13.673187 | controller | 18a0b750727a: Download complete
2025-11-01 00:14:13.673305 | controller | f35a9998a9bd: Verifying Checksum
2025-11-01 00:14:14.224909 | controller | f35a9998a9bd: Download complete
2025-11-01 00:14:14.225000 | controller | fdfc10566405: Verifying Checksum
2025-11-01 00:14:14.804403 | controller | fdfc10566405: Download complete
2025-11-01 00:14:14.804510 | controller | 1ff1c442c5fe: Download complete
2025-11-01 00:14:21.088476 | controller | a3443c4a17ed: Verifying Checksum
2025-11-01 00:14:23.313183 | controller | a3443c4a17ed: Download complete
2025-11-01 00:14:23.313253 | controller | 0edcf9fb2b15: Verifying Checksum
2025-11-01 00:14:27.345535 | controller | 0edcf9fb2b15: Download complete
2025-11-01 00:14:27.346587 | controller | 5af43b69e845: Verifying Checksum
2025-11-01 00:14:27.347015 | controller | 5af43b69e845: Download complete
2025-11-01 00:14:27.881194 | controller | 37425716ea5b: Verifying Checksum
2025-11-01 00:14:30.970033 | controller | 37425716ea5b: Download complete
2025-11-01 00:14:30.970154 | controller | 1651773effb2: Verifying Checksum
2025-11-01 00:14:30.970230 | controller | 1651773effb2: Download complete
2025-11-01 00:14:31.205882 | controller | 79e23c5c0fe4: Verifying Checksum
2025-11-01 00:14:31.206080 | controller | 79e23c5c0fe4: Download complete
2025-11-01 00:14:31.590295 | controller | e5058b1faaa6: Verifying Checksum
2025-11-01 00:14:31.590435 | controller | e5058b1faaa6: Download complete
2025-11-01 00:14:37.036039 | controller | 846775490569: Verifying Checksum
2025-11-01 00:14:37.036131 | controller | 846775490569: Download complete
2025-11-01 00:14:46.908828 | controller | 37425716ea5b: Pull complete
2025-11-01 00:14:46.936610 | controller | cd9b0c439616: Pull complete
2025-11-01 00:14:46.966664 | controller | d4612dbd8855: Pull complete
2025-11-01 00:14:53.051660 | controller | 554699364730: Pull complete
2025-11-01 00:14:53.075459 | controller | 1ff15d4bdb3e: Pull complete
2025-11-01 00:14:53.099567 | controller | 5f2e4724adea: Pull complete
2025-11-01 00:14:53.153051 | controller | a02d9a95ccb8: Pull complete
2025-11-01 00:14:53.181715 | controller | 989f4ce370cb: Pull complete
2025-11-01 00:14:53.218400 | controller | 0d7f52cdf9df: Pull complete
2025-11-01 00:14:53.242688 | controller | c423742351d5: Pull complete
2025-11-01 00:14:56.380093 | controller | 109236341d21: Pull complete
2025-11-01 00:14:56.403675 | controller | 07a2f61c96b8: Pull complete
2025-11-01 00:14:56.423604 | controller | 041f122f27ae: Pull complete
2025-11-01 00:14:56.597834 | controller | ca6f5098b12e: Pull complete
2025-11-01 00:14:56.663276 | controller | 1eb3e7b2afd9: Pull complete
2025-11-01 00:14:56.714542 | controller | 18a0b750727a: Pull complete
2025-11-01 00:14:56.742736 | controller | 17f2f596716c: Pull complete
2025-11-01 00:14:56.769191 | controller | f35a9998a9bd: Pull complete
2025-11-01 00:14:56.802496 | controller | fdfc10566405: Pull complete
2025-11-01 00:14:56.829706 | controller | 1ff1c442c5fe: Pull complete
2025-11-01 00:14:59.034590 | controller | a3443c4a17ed: Pull complete
2025-11-01 00:15:01.305734 | controller | 0edcf9fb2b15: Pull complete
2025-11-01 00:15:04.743593 | controller | 5af43b69e845: Pull complete
2025-11-01 00:15:07.687159 | controller | 1651773effb2: Pull complete
2025-11-01 00:15:11.120483 | controller | 79e23c5c0fe4: Pull complete
2025-11-01 00:15:13.600798 | controller | e5058b1faaa6: Pull complete
2025-11-01 00:15:16.874917 | controller | 846775490569: Pull complete
2025-11-01 00:15:17.058766 | controller | Digest: sha256:923f4b465456ae05243474faf9061abbefa2c2c5b88f24455fa2d5ce3d8d2ab4
2025-11-01 00:15:17.075005 | controller | Status: Downloaded newer image for quay.io/ansible/default-test-container:2.9.0
2025-11-01 00:15:17.084957 | controller | quay.io/ansible/default-test-container:2.9.0
2025-11-01 00:15:17.092490 | controller | Run command: docker images quay.io/ansible/pypi-test-container:1.0.0 --format '{{json .}}'
2025-11-01 00:15:17.136198 | controller | Run command: docker pull quay.io/ansible/pypi-test-container:1.0.0
2025-11-01 00:15:18.620156 | controller | 1.0.0: Pulling from ansible/pypi-test-container
2025-11-01 00:15:18.620513 | controller | 04a5f4cda3ee: Pulling fs layer
2025-11-01 00:15:18.620578 | controller | ff496a88c8ed: Pulling fs layer
2025-11-01 00:15:18.620630 | controller | 0ce83f459fe7: Pulling fs layer
2025-11-01 00:15:18.620684 | controller | 2e5170e1f099: Pulling fs layer
2025-11-01 00:15:18.620741 | controller | 7641eb41b08c: Pulling fs layer
2025-11-01 00:15:18.620801 | controller | ad15fa9da398: Pulling fs layer
2025-11-01 00:15:18.620871 | controller | 087d91352424: Pulling fs layer
2025-11-01 00:15:18.620937 | controller | 8b92efd6a100: Pulling fs layer
2025-11-01 00:15:18.621029 | controller | 7641eb41b08c: Waiting
2025-11-01 00:15:18.621102 | controller | ad15fa9da398: Waiting
2025-11-01 00:15:18.621204 | controller | 087d91352424: Waiting
2025-11-01 00:15:18.621272 | controller | 8b92efd6a100: Waiting
2025-11-01 00:15:18.622277 | controller | 2e5170e1f099: Waiting
2025-11-01 00:15:19.380947 | controller | 0ce83f459fe7: Verifying Checksum
2025-11-01 00:15:19.447119 | controller | 0ce83f459fe7: Download complete
2025-11-01 00:15:19.447175 | controller | ff496a88c8ed: Verifying Checksum
2025-11-01 00:15:20.666077 | controller | ff496a88c8ed: Download complete
2025-11-01 00:15:20.666141 | controller | 7641eb41b08c: Verifying Checksum
2025-11-01 00:15:20.667765 | controller | 7641eb41b08c: Download complete
2025-11-01 00:15:21.552169 | controller | ad15fa9da398: Verifying Checksum
2025-11-01 00:15:21.552247 | controller | ad15fa9da398: Download complete
2025-11-01 00:15:23.349488 | controller | 087d91352424: Verifying Checksum
2025-11-01 00:15:23.349584 | controller | 087d91352424: Download complete
2025-11-01 00:15:24.088614 | controller | 8b92efd6a100: Download complete
2025-11-01 00:15:25.667776 | controller | 2e5170e1f099: Verifying Checksum
2025-11-01 00:15:25.667999 | controller | 2e5170e1f099: Download complete
2025-11-01 00:15:25.922407 | controller | 04a5f4cda3ee: Verifying Checksum
2025-11-01 00:15:25.922557 | controller | 04a5f4cda3ee: Download complete
2025-11-01 00:15:28.463949 | controller | 04a5f4cda3ee: Pull complete
2025-11-01 00:15:28.490186 | controller | ff496a88c8ed: Pull complete
2025-11-01 00:15:28.510698 | controller | 0ce83f459fe7: Pull complete
2025-11-01 00:15:30.312008 | controller | 2e5170e1f099: Pull complete
2025-11-01 00:15:30.355954 | controller | 7641eb41b08c: Pull complete
2025-11-01 00:15:30.396469 | controller | ad15fa9da398: Pull complete
2025-11-01 00:15:31.780633 | controller | 087d91352424: Pull complete
2025-11-01 00:15:31.810622 | controller | 8b92efd6a100: Pull complete
2025-11-01 00:15:31.832979 | controller | Digest: sha256:71042ab0a14971b5608fe75706de54f367fc31db573e3b3955182037f73cadb6
2025-11-01 00:15:31.841236 | controller | Status: Downloaded newer image for quay.io/ansible/pypi-test-container:1.0.0
2025-11-01 00:15:31.853876 | controller | quay.io/ansible/pypi-test-container:1.0.0
2025-11-01 00:15:31.857886 | controller | Run command: docker run --detach quay.io/ansible/pypi-test-container:1.0.0
2025-11-01 00:15:32.471414 | controller | Run command: docker inspect 865d91d9df69e73726c1218e509b9ed92628bf791df4439af998ddb4ac74334b
2025-11-01 00:15:32.546974 | controller | Scanning collection root: /home/zuul/.ansible/collections/ansible_collections
2025-11-01 00:15:32.561920 | controller | Including collection: ansible.netcommon (288 files)
2025-11-01 00:15:32.562008 | controller | Including collection: ansible.network (23 files)
2025-11-01 00:15:32.575535 | controller | Including collection: ansible.utils (442 files)
2025-11-01 00:15:32.616734 | controller | Including collection: arista.eos (1022 files)
2025-11-01 00:15:32.668628 | controller | Including collection: cisco.ios (1172 files)
2025-11-01 00:15:32.714496 | controller | Including collection: cisco.iosxr (1043 files)
2025-11-01 00:15:32.789594 | controller | Including collection: cisco.nxos (1680 files)
2025-11-01 00:15:32.829320 | controller | Including collection: junipernetworks.junos (963 files)
2025-11-01 00:15:32.874967 | controller | Creating a payload archive containing 7359 files...
2025-11-01 00:15:34.950524 | controller | Created a 5970094 byte payload archive containing 7359 files in 2 seconds.
2025-11-01 00:15:34.956910 | controller | Assuming Docker is available on localhost.
2025-11-01 00:15:34.957205 | 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-11-01 00:15:35.452705 | controller | Run command: docker exec -i 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c dd of=/root/docker.sh bs=65536
2025-11-01 00:15:35.538186 | controller | Run command: docker exec 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c /bin/bash /root/docker.sh
2025-11-01 00:15:35.615910 | controller | Run command: docker exec -i 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c dd of=/root/test.tgz bs=65536
2025-11-01 00:15:35.715154 | controller | Run command: docker exec 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c tar oxzf /root/test.tgz -C /root
2025-11-01 00:15:37.395159 | controller | Run command: docker exec 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c /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-pc_7ri0u.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/
2025-11-01 00:15:37.848687 | controller | Injecting custom PyPI hosts entries: /etc/hosts
2025-11-01 00:15:37.848903 | controller | Injecting custom PyPI config: /root/.pip/pip.conf
2025-11-01 00:15:37.849047 | controller | Injecting custom PyPI config: /root/.pydistutils.cfg
2025-11-01 00:15:37.851226 | controller | Running sanity test 'action-plugin-docs' with Python 3.6
2025-11-01 00:15:37.852026 | controller | Read 0 sanity test ignore line(s) for Ansible 2.10 from: tests/sanity/ignore-2.10.txt
2025-11-01 00:15:37.858700 | controller | No tests applicable.
2025-11-01 00:15:37.858846 | controller | Running sanity test 'ansible-doc' with Python 3.6
2025-11-01 00:15:37.858929 | controller | No tests applicable.
2025-11-01 00:15:37.859186 | controller | Running sanity test 'changelog' with Python 3.6
2025-11-01 00:15:37.859519 | 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-11-01 00:15:38.812173 | 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-11-01 00:15:39.402683 | controller | Collecting antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2))
2025-11-01 00:15:54.423316 | 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-11-01 00:16:09.939940 | 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-11-01 00:16:25.961588 | 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-11-01 00:16:42.981463 | 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-11-01 00:17:01.988645 | 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-11-01 00:17:17.000707 | 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-11-01 00:17:17.003966 | 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-11-01 00:17:17.112731 | 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-11-01 00:17:17.112845 | controller | Removing custom PyPI config: /root/.pydistutils.cfg
2025-11-01 00:17:17.114270 | controller | Removing custom PyPI config: /root/.pip/pip.conf
2025-11-01 00:17:17.114329 | controller | Removing custom PyPI hosts entries: /etc/hosts
2025-11-01 00:17:17.173965 | controller | Run command: docker exec 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c tar czf /root/output.tgz --exclude .tmp -C /root/ansible_collections/ansible/network/tests output
2025-11-01 00:17:17.279026 | controller | Run command: docker exec -i 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c dd if=/root/output.tgz bs=65536
2025-11-01 00:17:17.350931 | controller | Run command: tar oxzf /tmp/ansible-result-5v582qd1.tgz -C /home/zuul/.ansible/collections/ansible_collections/ansible/network/tests
2025-11-01 00:17:17.368946 | controller | Run command: docker rm -f 865d91d9df69e73726c1218e509b9ed92628bf791df4439af998ddb4ac74334b
2025-11-01 00:17:17.710263 | controller | Run command: docker rm -f 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c
2025-11-01 00:17:18.384887 | controller | ERROR: Command "docker exec 72b6be3abac4125350f8afe96ee853acf30a8e125285d60a7111b875f074427c /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-pc_7ri0u.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/" returned exit status 1.
2025-11-01 00:17:18.993334 | controller | ERROR
2025-11-01 00:17:18.993599 | controller | {
2025-11-01 00:17:18.993660 | controller |   "delta": "0:03:29.180507",
2025-11-01 00:17:18.993777 | controller |   "end": "2025-11-01 00:17:18.442478",
2025-11-01 00:17:18.993817 | controller |   "msg": "non-zero return code",
2025-11-01 00:17:18.993853 | controller |   "rc": 1,
2025-11-01 00:17:18.993889 | controller |   "start": "2025-11-01 00:13:49.261971"
2025-11-01 00:17:18.993924 | controller | }
failure
2025-11-01 00:17:19.002397 | 
2025-11-01 00:17:19.002548 | PLAY RECAP
2025-11-01 00:17:19.002631 | controller | ok: 21 changed: 5 unreachable: 0 failed: 1 skipped: 20 rescued: 0 ignored: 1
2025-11-01 00:17:19.002729 | 
2025-11-01 00:17:19.190995 | RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-11-01 00:17:19.191870 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-01 00:17:19.884582 | 
2025-11-01 00:17:19.884743 | PLAY [all]
2025-11-01 00:17:19.910285 | 
2025-11-01 00:17:19.910586 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-01 00:17:22.874644 | controller | changed: non-zero return code
2025-11-01 00:17:22.887858 | 
2025-11-01 00:17:22.888031 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-01 00:17:22.913576 | controller | skipping: Conditional result was False
2025-11-01 00:17:22.922128 | 
2025-11-01 00:17:22.922233 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-01 00:17:22.964000 | 
2025-11-01 00:17:22.964165 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-01 00:17:22.994624 | 
2025-11-01 00:17:22.994785 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-01 00:17:23.018808 | controller | skipping: Conditional result was False
2025-11-01 00:17:23.025511 | 
2025-11-01 00:17:23.025623 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-01 00:17:23.056259 | 
2025-11-01 00:17:23.056421 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-01 00:17:23.080175 | controller | skipping: Conditional result was False
2025-11-01 00:17:23.087966 | 
2025-11-01 00:17:23.088061 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-01 00:17:23.111508 | controller | skipping: Conditional result was False
2025-11-01 00:17:23.118198 | 
2025-11-01 00:17:23.118392 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-01 00:17:23.142039 | controller | skipping: Conditional result was False
2025-11-01 00:17:23.172523 | 
2025-11-01 00:17:23.172628 | PLAY RECAP
2025-11-01 00:17:23.172722 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-01 00:17:23.172750 | 
2025-11-01 00:17:23.312993 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-01 00:17:23.314193 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-01 00:17:23.927368 | 
2025-11-01 00:17:23.927501 | PLAY [all:!appliance*]
2025-11-01 00:17:23.956980 | 
2025-11-01 00:17:23.957108 | TASK [unregister the node]
2025-11-01 00:17:24.320764 | controller | skipping: Conditional result was False
2025-11-01 00:17:24.334384 | 
2025-11-01 00:17:24.334608 | TASK [include_role : fetch-output]
2025-11-01 00:17:24.373294 | controller | ok
2025-11-01 00:17:24.418157 | 
2025-11-01 00:17:24.418303 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-01 00:17:24.464018 | controller | skipping: Conditional result was False
2025-11-01 00:17:24.478518 | 
2025-11-01 00:17:24.478809 | TASK [fetch-output : Set log path for single node]
2025-11-01 00:17:24.517082 | controller | ok
2025-11-01 00:17:24.529087 | 
2025-11-01 00:17:24.529241 | LOOP [fetch-output : Ensure local output dirs]
2025-11-01 00:17:24.964023 | controller -> localhost | ok: "/var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/logs"
2025-11-01 00:17:25.211547 | controller -> localhost | changed: "/var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/artifacts"
2025-11-01 00:17:25.464982 | controller -> localhost | changed: "/var/lib/zuul/builds/9ab7a3f508b1416d907450455dabe3ca/work/docs"
2025-11-01 00:17:25.480388 | 
2025-11-01 00:17:25.480536 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-01 00:17:27.692475 | controller | changed:
2025-11-01 00:17:27.692760 | controller | .d..t...... ./
2025-11-01 00:17:27.692803 | controller | cd+++++++++ controller/
2025-11-01 00:17:27.692852 | controller | changed: All items complete
2025-11-01 00:17:27.692882 | 
2025-11-01 00:17:29.733846 | controller | changed: .d..t...... ./
2025-11-01 00:17:31.824924 | controller | changed: .d..t...... ./
2025-11-01 00:17:31.848616 | 
2025-11-01 00:17:31.848817 | TASK [include_role : fetch-output-openshift]
2025-11-01 00:17:31.875189 | controller | skipping: Conditional result was False
2025-11-01 00:17:31.883491 | 
2025-11-01 00:17:31.883616 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-01 00:17:31.909940 | controller | skipping: Conditional result was False
2025-11-01 00:17:31.919140 | controller | skipping: Conditional result was False
2025-11-01 00:17:31.975109 | 
2025-11-01 00:17:31.975264 | PLAY [localhost]
2025-11-01 00:17:31.999355 | 
2025-11-01 00:17:31.999507 | TASK [Run Zuul manifest role]
2025-11-01 00:17:32.018596 | localhost | ok
2025-11-01 00:17:32.034361 | 
2025-11-01 00:17:32.034459 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-01 00:17:32.415992 | localhost | changed
2025-11-01 00:17:32.423700 | 
2025-11-01 00:17:32.423818 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-01 00:17:32.494919 | localhost | ok
2025-11-01 00:17:32.504963 | 
2025-11-01 00:17:32.505072 | TASK [Set zuul-log-path fact]
2025-11-01 00:17:32.525651 | localhost | ok
2025-11-01 00:17:32.585735 | 
2025-11-01 00:17:32.585851 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-01 00:17:32.614787 | localhost | ok
2025-11-01 00:17:32.623254 | 
2025-11-01 00:17:32.623349 | LOOP [Run upload-logs-swift role]
2025-11-01 00:17:32.647450 | localhost | Output suppressed because no_log was given
2025-11-01 00:17:32.676449 | 
2025-11-01 00:17:32.676562 | TASK [Set zuul-log-path fact]
2025-11-01 00:17:32.701012 | localhost | skipping: Conditional result was False
2025-11-01 00:17:32.708612 | 
2025-11-01 00:17:32.708763 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-01 00:17:33.101615 | localhost -> localhost | ok: Runtime: 0:00:00.012832
2025-11-01 00:17:33.117611 | 
2025-11-01 00:17:33.117799 | TASK [upload-logs-swift : Upload logs to swift]