2025-10-27 00:13:33.502896 | Job console starting...
2025-10-27 00:13:33.512183 | Updating repositories
2025-10-27 00:13:33.656983 | Preparing job workspace
2025-10-27 00:13:41.897661 | Running Ansible setup...
2025-10-27 00:13:46.595932 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-27 00:13:47.339048 | 
2025-10-27 00:13:47.339185 | PLAY [localhost]
2025-10-27 00:13:47.348476 | 
2025-10-27 00:13:47.348568 | TASK [Gathering Facts]
2025-10-27 00:13:48.453156 | localhost | ok
2025-10-27 00:13:48.474025 | 
2025-10-27 00:13:48.474305 | TASK [Setup log path fact]
2025-10-27 00:13:48.498182 | localhost | ok
2025-10-27 00:13:48.511100 | 
2025-10-27 00:13:48.511201 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-27 00:13:48.540944 | localhost | ok
2025-10-27 00:13:48.549555 | 
2025-10-27 00:13:48.549708 | TASK [emit-job-header : Print job information]
2025-10-27 00:13:48.589667 | # Job Information
2025-10-27 00:13:48.589896 | Ansible Version: 2.15.12
2025-10-27 00:13:48.589940 | Job: ansible-test-sanity-docker-stable-2.10
2025-10-27 00:13:48.589969 | Pipeline: periodic
2025-10-27 00:13:48.589996 | Executor: ze04.softwarefactory-project.io
2025-10-27 00:13:48.590022 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-27 00:13:48.590052 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/0aa/ansible/0aa32a410eb74bdb827a3f4965d44f48/
2025-10-27 00:13:48.590077 | Event ID: 750469794ad743fdb26497abfe8a4902
2025-10-27 00:13:48.594074 | 
2025-10-27 00:13:48.594165 | LOOP [emit-job-header : Print node information]
2025-10-27 00:13:48.701559 | localhost | ok:
2025-10-27 00:13:48.701810 | localhost | # Node Information
2025-10-27 00:13:48.701839 | localhost | Inventory Hostname: controller
2025-10-27 00:13:48.701868 | localhost | Hostname: np0005502828
2025-10-27 00:13:48.701888 | localhost | Username: zuul
2025-10-27 00:13:48.701913 | localhost | Distro: Fedora 37
2025-10-27 00:13:48.701932 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-10-27 00:13:48.701950 | localhost | Region: ca-ymq-1
2025-10-27 00:13:48.701967 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-27 00:13:48.701983 | localhost | Product Name: OpenStack Nova
2025-10-27 00:13:48.702000 | localhost | Interface IP: 162.253.55.206
2025-10-27 00:13:48.729723 | 
2025-10-27 00:13:48.729924 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-27 00:13:49.139803 | localhost -> localhost | changed
2025-10-27 00:13:49.153283 | 
2025-10-27 00:13:49.153451 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-27 00:13:50.129349 | localhost -> localhost | changed
2025-10-27 00:13:50.174606 | 
2025-10-27 00:13:50.174784 | PLAY [all:!appliance*]
2025-10-27 00:13:50.206254 | 
2025-10-27 00:13:50.206410 | TASK [include_role : start-zuul-console]
2025-10-27 00:13:50.230459 | controller | ok
2025-10-27 00:13:50.257272 | 
2025-10-27 00:13:50.257444 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-27 00:13:50.665104 | controller | ok
2025-10-27 00:13:50.691160 | 
2025-10-27 00:13:50.691349 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-27 00:14:13.204875 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-27 00:14:13.217229 | 
2025-10-27 00:14:13.217357 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-27 00:14:13.767322 | controller | skipping: Conditional result was False
2025-10-27 00:14:13.782622 | 
2025-10-27 00:14:13.782867 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-27 00:14:13.811146 | controller | skipping: Conditional result was False
2025-10-27 00:14:13.827946 | 
2025-10-27 00:14:13.828181 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-27 00:14:13.855436 | controller | skipping: Conditional result was False
2025-10-27 00:14:13.865525 | 
2025-10-27 00:14:13.865706 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-27 00:14:13.893861 | controller | skipping: Conditional result was False
2025-10-27 00:14:13.904052 | 
2025-10-27 00:14:13.904248 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-27 00:14:13.931352 | controller | skipping: Conditional result was False
2025-10-27 00:14:13.948333 | 
2025-10-27 00:14:13.948551 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-27 00:14:13.973886 | controller | skipping: Conditional result was False
2025-10-27 00:14:13.992010 | 
2025-10-27 00:14:13.992160 | TASK [Disable Fedora Modular]
2025-10-27 00:14:14.354225 | controller | changed
2025-10-27 00:14:14.366248 | 
2025-10-27 00:14:14.366462 | TASK [Enable EPEL]
2025-10-27 00:14:14.404316 | controller | skipping: Conditional result was False
2025-10-27 00:14:14.413801 | 
2025-10-27 00:14:14.413894 | TASK [Register the RHEL node]
2025-10-27 00:14:14.527820 | 
2025-10-27 00:14:14.528069 | TASK [Show the subscription-manager status]
2025-10-27 00:14:14.615045 | controller | skipping: Conditional result was False
2025-10-27 00:14:14.625473 | 
2025-10-27 00:14:14.625570 | TASK [Enable EPEL on RHEL]
2025-10-27 00:14:15.179528 | controller | skipping: Conditional result was False
2025-10-27 00:14:15.189226 | 
2025-10-27 00:14:15.189334 | TASK [Install git and tox]
2025-10-27 00:15:17.478407 | controller | changed
2025-10-27 00:15:17.485135 | 
2025-10-27 00:15:17.485261 | TASK [include_role : prepare-workspace]
2025-10-27 00:15:17.590319 | controller | ok
2025-10-27 00:15:17.611575 | 
2025-10-27 00:15:17.611714 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-27 00:15:17.838261 | controller | ok
2025-10-27 00:15:17.846100 | 
2025-10-27 00:15:17.846215 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-27 00:15:30.778158 | controller | Output suppressed because no_log was given
2025-10-27 00:15:30.802942 | 
2025-10-27 00:15:30.803089 | TASK [include_role : prepare-workspace-openshift]
2025-10-27 00:15:30.828392 | controller | skipping: Conditional result was False
2025-10-27 00:15:30.893028 | 
2025-10-27 00:15:30.893201 | PLAY [all:!appliance]
2025-10-27 00:15:30.929453 | 
2025-10-27 00:15:30.929617 | TASK [Run add-build-sshkey role (RSA)]
2025-10-27 00:15:30.963510 | controller | ok
2025-10-27 00:15:30.988816 | 
2025-10-27 00:15:30.988985 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-27 00:15:31.230348 | controller -> localhost | ok
2025-10-27 00:15:31.237836 | 
2025-10-27 00:15:31.237916 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-27 00:15:31.289876 | controller | ok
2025-10-27 00:15:31.330702 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-27 00:15:31.365484 | 
2025-10-27 00:15:31.365653 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-27 00:15:32.003771 | controller -> localhost | Generating public/private rsa key pair.
2025-10-27 00:15:32.004048 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/0aa32a410eb74bdb827a3f4965d44f48_id_rsa.
2025-10-27 00:15:32.004082 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/0aa32a410eb74bdb827a3f4965d44f48_id_rsa.pub.
2025-10-27 00:15:32.004105 | controller -> localhost | The key fingerprint is:
2025-10-27 00:15:32.004126 | controller -> localhost | SHA256:8Yo+lWfM22Fhc3ZrCqxBVCzPDnq7jwSi4fMT1YcI7Zk zuul-build-sshkey
2025-10-27 00:15:32.004146 | controller -> localhost | The key's randomart image is:
2025-10-27 00:15:32.004167 | controller -> localhost | +---[RSA 2048]----+
2025-10-27 00:15:32.004186 | controller -> localhost | |      .   o.     |
2025-10-27 00:15:32.004207 | controller -> localhost | |     . . o .     |
2025-10-27 00:15:32.004227 | controller -> localhost | |      o B =      |
2025-10-27 00:15:32.004246 | controller -> localhost | |       E B ++ o .|
2025-10-27 00:15:32.004266 | controller -> localhost | |   . ...S+*. = ..|
2025-10-27 00:15:32.004294 | controller -> localhost | |  . o..o++=+o  o |
2025-10-27 00:15:32.004320 | controller -> localhost | |   +  o.o+++..o  |
2025-10-27 00:15:32.004343 | controller -> localhost | |    oo. .oo ..   |
2025-10-27 00:15:32.004377 | controller -> localhost | |     .o. oo.     |
2025-10-27 00:15:32.004419 | controller -> localhost | +----[SHA256]-----+
2025-10-27 00:15:32.004479 | controller -> localhost | ok: Runtime: 0:00:00.146937
2025-10-27 00:15:32.013364 | 
2025-10-27 00:15:32.013464 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-27 00:15:32.064485 | controller | ok
2025-10-27 00:15:32.083584 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-27 00:15:32.094775 | 
2025-10-27 00:15:32.094893 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-27 00:15:32.122318 | controller | skipping: Conditional result was False
2025-10-27 00:15:32.130928 | 
2025-10-27 00:15:32.131045 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-27 00:15:32.625866 | controller | changed
2025-10-27 00:15:32.635853 | 
2025-10-27 00:15:32.636019 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-27 00:15:32.911594 | controller | ok
2025-10-27 00:15:32.922740 | 
2025-10-27 00:15:32.922905 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-27 00:15:33.598773 | controller | changed
2025-10-27 00:15:33.604724 | 
2025-10-27 00:15:33.604799 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-27 00:15:34.255975 | controller | changed
2025-10-27 00:15:34.264603 | 
2025-10-27 00:15:34.264797 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-27 00:15:34.292256 | controller | skipping: Conditional result was False
2025-10-27 00:15:34.303350 | 
2025-10-27 00:15:34.303460 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-27 00:15:34.811043 | controller -> localhost | changed
2025-10-27 00:15:34.833908 | 
2025-10-27 00:15:34.834034 | TASK [add-build-sshkey : Add back temp key]
2025-10-27 00:15:35.238863 | controller -> localhost | Identity added: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/0aa32a410eb74bdb827a3f4965d44f48_id_rsa (zuul-build-sshkey)
2025-10-27 00:15:35.239115 | controller -> localhost | ok: Runtime: 0:00:00.022463
2025-10-27 00:15:35.248992 | 
2025-10-27 00:15:35.249118 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-27 00:15:35.546808 | controller | ok
2025-10-27 00:15:35.556192 | 
2025-10-27 00:15:35.556330 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-27 00:15:35.583950 | controller | skipping: Conditional result was False
2025-10-27 00:15:35.595808 | 
2025-10-27 00:15:35.595915 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-27 00:15:35.628047 | controller | ok
2025-10-27 00:15:35.648192 | 
2025-10-27 00:15:35.648329 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-27 00:15:35.902950 | controller -> localhost | ok
2025-10-27 00:15:35.910165 | 
2025-10-27 00:15:35.910262 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-27 00:15:35.941745 | controller | ok
2025-10-27 00:15:35.968444 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-27 00:15:35.993956 | 
2025-10-27 00:15:35.994153 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-27 00:15:36.343879 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-27 00:15:36.344120 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/0aa32a410eb74bdb827a3f4965d44f48_id_ecdsa.
2025-10-27 00:15:36.344148 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/0aa32a410eb74bdb827a3f4965d44f48_id_ecdsa.pub.
2025-10-27 00:15:36.344184 | controller -> localhost | The key fingerprint is:
2025-10-27 00:15:36.344205 | controller -> localhost | SHA256:5jI9Vsk8Et1snb7XszxZpclfzetI1xlWLAjrqaT2j8I zuul-build-sshkey
2025-10-27 00:15:36.344224 | controller -> localhost | The key's randomart image is:
2025-10-27 00:15:36.344243 | controller -> localhost | +---[ECDSA 521]---+
2025-10-27 00:15:36.344261 | controller -> localhost | |          .      |
2025-10-27 00:15:36.344278 | controller -> localhost | |         . = o o |
2025-10-27 00:15:36.344297 | controller -> localhost | |        . o = + o|
2025-10-27 00:15:36.344314 | controller -> localhost | |         = + . .o|
2025-10-27 00:15:36.344331 | controller -> localhost | |        S O  ..*o|
2025-10-27 00:15:36.344348 | controller -> localhost | |       * + .  =.X|
2025-10-27 00:15:36.344365 | controller -> localhost | |     .= *    ..=O|
2025-10-27 00:15:36.344382 | controller -> localhost | |     .E= o  . +=+|
2025-10-27 00:15:36.344399 | controller -> localhost | |       .o..  ..+.|
2025-10-27 00:15:36.344417 | controller -> localhost | +----[SHA256]-----+
2025-10-27 00:15:36.344470 | controller -> localhost | ok: Runtime: 0:00:00.010216
2025-10-27 00:15:36.352853 | 
2025-10-27 00:15:36.352948 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-27 00:15:36.384190 | controller | ok
2025-10-27 00:15:36.392354 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-27 00:15:36.401458 | 
2025-10-27 00:15:36.401560 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-27 00:15:36.426502 | controller | skipping: Conditional result was False
2025-10-27 00:15:36.434715 | 
2025-10-27 00:15:36.434825 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-27 00:15:36.757883 | controller | changed
2025-10-27 00:15:36.771581 | 
2025-10-27 00:15:36.771776 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-27 00:15:37.002214 | controller | ok
2025-10-27 00:15:37.009343 | 
2025-10-27 00:15:37.009489 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-27 00:15:37.671282 | controller | changed
2025-10-27 00:15:37.683161 | 
2025-10-27 00:15:37.683315 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-27 00:15:38.367467 | controller | changed
2025-10-27 00:15:38.391576 | 
2025-10-27 00:15:38.391748 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-27 00:15:38.418155 | controller | skipping: Conditional result was False
2025-10-27 00:15:38.427725 | 
2025-10-27 00:15:38.427891 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-27 00:15:38.721741 | controller -> localhost | changed
2025-10-27 00:15:38.738777 | 
2025-10-27 00:15:38.738931 | TASK [add-build-sshkey : Add back temp key]
2025-10-27 00:15:39.019040 | controller -> localhost | Identity added: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/0aa32a410eb74bdb827a3f4965d44f48_id_ecdsa (zuul-build-sshkey)
2025-10-27 00:15:39.019299 | controller -> localhost | ok: Runtime: 0:00:00.009144
2025-10-27 00:15:39.026821 | 
2025-10-27 00:15:39.026927 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-27 00:15:39.252134 | controller | ok
2025-10-27 00:15:39.261416 | 
2025-10-27 00:15:39.261570 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-27 00:15:39.291179 | controller | skipping: Conditional result was False
2025-10-27 00:15:39.304642 | 
2025-10-27 00:15:39.304928 | TASK [include_role : remove-zuul-sshkey]
2025-10-27 00:15:39.335817 | controller | skipping: Conditional result was False
2025-10-27 00:15:39.344511 | 
2025-10-27 00:15:39.344616 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-27 00:15:39.570360 | controller | ok: "logs"
2025-10-27 00:15:39.570674 | controller | ok: All items complete
2025-10-27 00:15:39.570732 | 
2025-10-27 00:15:39.764485 | controller | ok: "artifacts"
2025-10-27 00:15:39.967893 | controller | ok: "docs"
2025-10-27 00:15:39.979916 | 
2025-10-27 00:15:39.980036 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-27 00:15:40.255281 | controller | changed: "logs"
2025-10-27 00:15:40.466258 | controller | changed: "artifacts"
2025-10-27 00:15:40.683296 | controller | changed: "docs"
2025-10-27 00:15:40.720515 | 
2025-10-27 00:15:40.720644 | PLAY RECAP
2025-10-27 00:15:40.720747 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-27 00:15:40.720782 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-27 00:15:40.720800 | 
2025-10-27 00:15:40.872192 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-27 00:15:40.874142 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-27 00:15:41.592461 | 
2025-10-27 00:15:41.592631 | PLAY [all]
2025-10-27 00:15:41.617930 | 
2025-10-27 00:15:41.618064 | TASK [Install binary dependencies]
2025-10-27 00:15:41.691037 | controller | ok
2025-10-27 00:15:41.715706 | 
2025-10-27 00:15:41.715901 | TASK [bindep : Include find tasks]
2025-10-27 00:15:41.747434 | controller | ok
2025-10-27 00:15:41.756635 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-27 00:15:41.763779 | 
2025-10-27 00:15:41.763846 | TASK [bindep : Look for bindep.txt]
2025-10-27 00:15:42.168951 | controller | ok
2025-10-27 00:15:42.175297 | 
2025-10-27 00:15:42.175374 | TASK [bindep : Define bindep_file fact]
2025-10-27 00:15:42.200987 | controller | skipping: Conditional result was False
2025-10-27 00:15:42.208662 | 
2025-10-27 00:15:42.208829 | TASK [bindep : Look for other-requirements.txt]
2025-10-27 00:15:42.437066 | controller | ok
2025-10-27 00:15:42.456634 | 
2025-10-27 00:15:42.457003 | TASK [bindep : Define bindep_file fact]
2025-10-27 00:15:42.498906 | controller | skipping: Conditional result was False
2025-10-27 00:15:42.508786 | 
2025-10-27 00:15:42.508899 | TASK [bindep : Look for bindep fallback file]
2025-10-27 00:15:42.554298 | controller | skipping: Conditional result was False
2025-10-27 00:15:42.565269 | 
2025-10-27 00:15:42.565376 | TASK [bindep : Define bindep_file fact]
2025-10-27 00:15:42.591203 | controller | skipping: Conditional result was False
2025-10-27 00:15:42.603353 | 
2025-10-27 00:15:42.603597 | TASK [bindep : Include bindep tasks]
2025-10-27 00:15:42.641435 | controller | skipping: Conditional result was False
2025-10-27 00:15:42.654864 | 
2025-10-27 00:15:42.655241 | TASK [bindep : Include install tasks]
2025-10-27 00:15:42.702404 | controller | skipping: Conditional result was False
2025-10-27 00:15:42.710854 | 
2025-10-27 00:15:42.711023 | LOOP [bindep : Include package tasks]
2025-10-27 00:15:42.780390 | 
2025-10-27 00:15:42.780619 | TASK [Run test-setup role]
2025-10-27 00:15:42.811205 | controller | ok
2025-10-27 00:15:42.839912 | 
2025-10-27 00:15:42.840089 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-27 00:15:43.158431 | controller | ok
2025-10-27 00:15:43.178199 | 
2025-10-27 00:15:43.178413 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-27 00:15:43.723598 | controller | skipping: Conditional result was False
2025-10-27 00:15:43.763127 | 
2025-10-27 00:15:43.763251 | PLAY RECAP
2025-10-27 00:15:43.763309 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-27 00:15:43.763337 | 
2025-10-27 00:15:43.895699 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-27 00:15:43.896737 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-27 00:15:44.548773 | 
2025-10-27 00:15:44.548966 | PLAY [controller]
2025-10-27 00:15:44.570938 | 
2025-10-27 00:15:44.571050 | TASK [Create the /root directory]
2025-10-27 00:15:44.983147 | controller | ok
2025-10-27 00:15:44.992906 | 
2025-10-27 00:15:44.993021 | TASK [Install glibc-langpack-en]
2025-10-27 00:15:50.437708 | controller | ok: Nothing to do
2025-10-27 00:15:50.446491 | 
2025-10-27 00:15:50.446590 | TASK [Ensure controller directory exists]
2025-10-27 00:15:50.675458 | controller | changed
2025-10-27 00:15:50.682044 | 
2025-10-27 00:15:50.682226 | TASK [Install container runtime]
2025-10-27 00:15:50.726299 | controller | ok
2025-10-27 00:15:50.770960 | 
2025-10-27 00:15:50.771145 | LOOP [ensure-docker : Gather variables for each operating system]
2025-10-27 00:15:50.806613 | controller | ok: "/var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml"
2025-10-27 00:15:50.814727 | 
2025-10-27 00:15:50.814841 | TASK [ensure-docker : Sanity check for distro selection]
2025-10-27 00:15:50.830097 | controller | skipping: Conditional result was False
2025-10-27 00:15:50.840272 | 
2025-10-27 00:15:50.840402 | TASK [ensure-docker : Sanity check for distro install]
2025-10-27 00:15:50.867524 | controller | skipping: Conditional result was False
2025-10-27 00:15:50.879058 | 
2025-10-27 00:15:50.879213 | TASK [ensure-docker : Sanity check for upstream install]
2025-10-27 00:15:50.905284 | controller | skipping: Conditional result was False
2025-10-27 00:15:50.917726 | 
2025-10-27 00:15:50.917990 | TASK [ensure-docker : Sanity check for upstream install mirrors]
2025-10-27 00:15:50.946241 | controller | skipping: Conditional result was False
2025-10-27 00:15:50.961509 | 
2025-10-27 00:15:50.961783 | TASK [ensure-docker : Include tasks for docker install]
2025-10-27 00:15:50.996401 | controller | ok
2025-10-27 00:15:51.007174 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml
2025-10-27 00:15:51.018521 | 
2025-10-27 00:15:51.018710 | TASK [ensure-docker : Not Implemented]
2025-10-27 00:15:51.044549 | controller | skipping: Conditional result was False
2025-10-27 00:15:51.054520 | 
2025-10-27 00:15:51.054752 | TASK [Set up docker mirrors]
2025-10-27 00:15:51.077221 | controller | ok
2025-10-27 00:15:51.100450 | 
2025-10-27 00:15:51.100601 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info]
2025-10-27 00:15:51.136017 | controller | skipping: Conditional result was False
2025-10-27 00:15:51.143484 | 
2025-10-27 00:15:51.143578 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info]
2025-10-27 00:15:51.169379 | controller | skipping: Conditional result was False
2025-10-27 00:15:51.177813 | 
2025-10-27 00:15:51.177933 | TASK [use-docker-mirror : Set docker_mirror fact]
2025-10-27 00:15:51.203805 | controller | skipping: Conditional result was False
2025-10-27 00:15:51.216341 | 
2025-10-27 00:15:51.216500 | TASK [use-docker-mirror : Set up docker mirrors]
2025-10-27 00:15:51.242209 | controller | skipping: Conditional result was False
2025-10-27 00:15:51.258869 | 
2025-10-27 00:15:51.259000 | TASK [Add all repositories]
2025-10-27 00:15:51.282282 | controller | ok
2025-10-27 00:15:51.359737 | 
2025-10-27 00:15:51.359899 | LOOP [ensure-package-repositories : Install repositories]
2025-10-27 00:15:51.388861 | controller | ok: "/var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml"
2025-10-27 00:15:51.389304 | controller | ok: All items complete
2025-10-27 00:15:51.389339 | 
2025-10-27 00:15:51.404427 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml
2025-10-27 00:15:51.411082 | 
2025-10-27 00:15:51.411151 | TASK [ensure-package-repositories : Create GPG key temp directory]
2025-10-27 00:15:51.727451 | controller | changed
2025-10-27 00:15:51.744229 | 
2025-10-27 00:15:51.744485 | LOOP [ensure-package-repositories : Upload GPG keys]
2025-10-27 00:15:52.712527 | controller | changed:
2025-10-27 00:15:52.713065 | controller | {
2025-10-27 00:15:52.713109 | 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-10-27 00:15:52.713140 | controller | }
2025-10-27 00:15:52.734813 | 
2025-10-27 00:15:52.735021 | LOOP [ensure-package-repositories : Import GPG keys]
2025-10-27 00:15:54.110209 | controller | changed:
2025-10-27 00:15:54.110508 | controller | {
2025-10-27 00:15:54.110567 | 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-10-27 00:15:54.110616 | controller | }
2025-10-27 00:15:54.110714 | controller | changed: All items complete
2025-10-27 00:15:54.110789 | 
2025-10-27 00:15:54.132248 | 
2025-10-27 00:15:54.132438 | TASK [ensure-package-repositories : Remove GPG temp directory]
2025-10-27 00:15:54.404327 | controller | changed
2025-10-27 00:15:54.410933 | 
2025-10-27 00:15:54.411008 | LOOP [ensure-package-repositories : Add repositories]
2025-10-27 00:15:54.806397 | controller | changed:
2025-10-27 00:15:54.806829 | controller | {
2025-10-27 00:15:54.806896 | controller |   "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable",
2025-10-27 00:15:54.806940 | controller |   "description": "Docker CE Stable - $basearch",
2025-10-27 00:15:54.806978 | controller |   "gpgcheck": true,
2025-10-27 00:15:54.807015 | controller |   "name": "docker-ce-stable"
2025-10-27 00:15:54.807052 | controller | }
2025-10-27 00:15:54.850331 | 
2025-10-27 00:15:54.850513 | TASK [ensure-docker : Install pre-reqs]
2025-10-27 00:16:00.261180 | controller | ok: Nothing to do
2025-10-27 00:16:00.271302 | 
2025-10-27 00:16:00.271471 | TASK [ensure-docker : Remove packages]
2025-10-27 00:16:02.039722 | controller | ok: Nothing to do
2025-10-27 00:16:02.048180 | 
2025-10-27 00:16:02.048265 | TASK [ensure-docker : Install upstream docker using package]
2025-10-27 00:16:56.904211 | controller | changed
2025-10-27 00:16:56.910450 | 
2025-10-27 00:16:56.910521 | TASK [ensure-docker : Setup docker]
2025-10-27 00:16:56.946135 | controller | ok
2025-10-27 00:16:56.962645 | controller | included: /var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml
2025-10-27 00:16:56.981384 | 
2025-10-27 00:16:56.981523 | TASK [ensure-docker : Ensure "docker" group exists]
2025-10-27 00:16:57.382418 | controller | ok
2025-10-27 00:16:57.389996 | 
2025-10-27 00:16:57.390086 | TASK [ensure-docker : Add user to docker group]
2025-10-27 00:16:57.922379 | controller | changed
2025-10-27 00:16:57.932467 | 
2025-10-27 00:16:57.932599 | TASK [Update docker daemon proxy configuration]
2025-10-27 00:16:57.958274 | controller | skipping: Conditional result was False
2025-10-27 00:16:57.970627 | 
2025-10-27 00:16:57.970763 | TASK [Lower default MTU]
2025-10-27 00:16:57.997034 | controller | skipping: Conditional result was False
2025-10-27 00:16:58.058031 | 
2025-10-27 00:16:58.058194 | TASK [ensure-docker : Get the status of the docket.socket unit]
2025-10-27 00:16:58.493114 | controller | inactive
2025-10-27 00:16:58.594075 | controller | ok: Runtime: 0:00:00.013517
2025-10-27 00:16:58.601625 | 
2025-10-27 00:16:58.601787 | TASK [ensure-docker : Get the status of the docket unit]
2025-10-27 00:16:58.862553 | controller | inactive
2025-10-27 00:16:59.140002 | controller | ok: Runtime: 0:00:00.014333
2025-10-27 00:16:59.148982 | 
2025-10-27 00:16:59.149054 | TASK [ensure-docker : Restart docker]
2025-10-27 00:16:59.192186 | Trigger a Docker restart
2025-10-27 00:16:59.199159 | 
2025-10-27 00:16:59.199244 | TASK [ensure-docker : Reset ssh connection to pick up docker group]
2025-10-27 00:16:59.232739 | 
2025-10-27 00:16:59.232896 | TASK [ensure-docker : Install docker-compose]
2025-10-27 00:16:59.250729 | controller | skipping: Conditional result was False
2025-10-27 00:16:59.258472 | 
2025-10-27 00:16:59.258595 | TASK [ensure-docker : Flush handlers before role exit]
2025-10-27 00:16:59.270860 | 
2025-10-27 00:16:59.270963 | TASK [ensure-docker : Stop docker.socket to avoid any conflict]
2025-10-27 00:17:00.481265 | controller | changed
2025-10-27 00:17:00.492794 | 
2025-10-27 00:17:00.493115 | TASK [ensure-docker : Assure docker service is running]
2025-10-27 00:17:02.637773 | controller | changed
2025-10-27 00:17:02.650107 | 
2025-10-27 00:17:02.650292 | TASK [ensure-docker : Assure docker.socket service is running]
2025-10-27 00:17:03.399667 | controller | ok
2025-10-27 00:17:03.411945 | 
2025-10-27 00:17:03.412092 | TASK [ensure-docker : Correct group ownership on docker sock]
2025-10-27 00:17:04.092766 | controller | ok
2025-10-27 00:17:04.102616 | 
2025-10-27 00:17:04.102826 | TASK [ensure-docker : Validate ability to talk with docker]
2025-10-27 00:17:04.733457 | controller | CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES
2025-10-27 00:17:05.162921 | controller | ok: Runtime: 0:00:00.052806
2025-10-27 00:17:05.171712 | 
2025-10-27 00:17:05.171850 | TASK [ensure-docker : Get version details]
2025-10-27 00:17:05.575349 | controller | Client: Docker Engine - Community
2025-10-27 00:17:05.575470 | controller |  Version:           24.0.7
2025-10-27 00:17:05.575505 | controller |  API version:       1.43
2025-10-27 00:17:05.575536 | controller |  Go version:        go1.20.10
2025-10-27 00:17:05.575573 | controller |  Git commit:        afdd53b
2025-10-27 00:17:05.575609 | controller |  Built:             Thu Oct 26 09:09:39 2023
2025-10-27 00:17:05.575645 | controller |  OS/Arch:           linux/amd64
2025-10-27 00:17:05.575682 | controller |  Context:           default
2025-10-27 00:17:05.575697 | controller |
2025-10-27 00:17:05.575730 | controller | Server: Docker Engine - Community
2025-10-27 00:17:05.575767 | controller |  Engine:
2025-10-27 00:17:05.575857 | controller |   Version:          24.0.7
2025-10-27 00:17:05.575888 | controller |   API version:      1.43 (minimum version 1.12)
2025-10-27 00:17:05.575918 | controller |   Go version:       go1.20.10
2025-10-27 00:17:05.575947 | controller |   Git commit:       311b9ff
2025-10-27 00:17:05.575981 | controller |   Built:            Thu Oct 26 09:08:11 2023
2025-10-27 00:17:05.576015 | controller |   OS/Arch:          linux/amd64
2025-10-27 00:17:05.576059 | controller |   Experimental:     false
2025-10-27 00:17:05.576078 | controller |  containerd:
2025-10-27 00:17:05.576147 | controller |   Version:          1.6.25
2025-10-27 00:17:05.576230 | controller |   GitCommit:        d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f
2025-10-27 00:17:05.576251 | controller |  runc:
2025-10-27 00:17:05.576308 | controller |   Version:          1.1.10
2025-10-27 00:17:05.576338 | controller |   GitCommit:        v1.1.10-0-g18a0cb0
2025-10-27 00:17:05.576358 | controller |  docker-init:
2025-10-27 00:17:05.576470 | controller |   Version:          0.19.0
2025-10-27 00:17:05.576503 | controller |   GitCommit:        de40ad0
2025-10-27 00:17:05.717776 | controller | ok: Runtime: 0:00:00.052561
2025-10-27 00:17:05.725072 | 
2025-10-27 00:17:05.725194 | TASK [ensure-docker : Dump installed docker details]
2025-10-27 00:17:05.750085 | {'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-10-27 00:17:05.525646', 'end': '2025-10-27 00:17:05.578207', 'delta': '0:00:00.052561', 'msg': '', 'zuul_log_id': 'fa163e3b-3c83-8a6a-07a7-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-10-27 00:17:05.770354 | 
2025-10-27 00:17:05.770514 | TASK [Use buildset registry]
2025-10-27 00:17:05.786038 | controller | skipping: Conditional result was False
2025-10-27 00:17:05.800264 | 
2025-10-27 00:17:05.800423 | TASK [Ensure python3.8 is present]
2025-10-27 00:17:05.820152 | controller | skipping: Conditional result was False
2025-10-27 00:17:05.829855 | 
2025-10-27 00:17:05.829950 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-27 00:17:05.851044 | controller | ok
2025-10-27 00:17:05.870920 | 
2025-10-27 00:17:05.871030 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-27 00:17:07.979826 | controller | ok: Nothing to do
2025-10-27 00:17:07.990133 | 
2025-10-27 00:17:07.990376 | TASK [our-ensure-python : Also install python3-devel]
2025-10-27 00:17:20.469883 | controller | changed
2025-10-27 00:17:20.489888 | 
2025-10-27 00:17:20.490065 | TASK [Run ensure-virtualenv role]
2025-10-27 00:17:20.517185 | controller | ok
2025-10-27 00:17:20.557525 | 
2025-10-27 00:17:20.557723 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-27 00:17:20.836012 | controller | /usr/bin/virtualenv
2025-10-27 00:17:21.114514 | controller | ok: Runtime: 0:00:00.004667
2025-10-27 00:17:21.123876 | 
2025-10-27 00:17:21.124070 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-27 00:17:21.151464 | controller | skipping: Conditional result was False
2025-10-27 00:17:21.152058 | controller | changed: All items complete
2025-10-27 00:17:21.152124 | 
2025-10-27 00:17:21.185575 | 
2025-10-27 00:17:21.185820 | TASK [Find the full path of the Python interpreter]
2025-10-27 00:17:21.424350 | controller | /usr/bin/python3.8
2025-10-27 00:17:21.734529 | controller | ok
2025-10-27 00:17:21.746612 | 
2025-10-27 00:17:21.746813 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-27 00:17:23.434838 | controller | created virtual environment CPython3.8.18.final.0-64 in 824ms
2025-10-27 00:17:23.478411 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-27 00:17:23.478451 | 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-10-27 00:17:23.478463 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-27 00:17:23.478478 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-27 00:17:23.792669 | controller | changed
2025-10-27 00:17:23.800905 | 
2025-10-27 00:17:23.801049 | TASK [Set selinux package]
2025-10-27 00:17:23.826345 | controller | ok
2025-10-27 00:17:23.834260 | 
2025-10-27 00:17:23.834437 | TASK [Set selinux package (Fedora)]
2025-10-27 00:17:23.890025 | controller | ok
2025-10-27 00:17:23.898085 | 
2025-10-27 00:17:23.898230 | TASK [Install selinux into virtualenv]
2025-10-27 00:17:36.528732 | controller | Collecting selinux-please-lie-to-me
2025-10-27 00:17:48.844370 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-27 00:17:49.334687 | controller | Collecting setuptools<50.0.0
2025-10-27 00:17:49.343611 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-27 00:17:49.396230 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.3 MB/s eta 0:00:00
2025-10-27 00:17:49.474096 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-27 00:17:49.474380 | controller |   Attempting uninstall: setuptools
2025-10-27 00:17:49.475122 | controller |     Found existing installation: setuptools 62.6.0
2025-10-27 00:17:49.549215 | controller |     Uninstalling setuptools-62.6.0:
2025-10-27 00:17:49.559739 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-27 00:17:50.000746 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-27 00:18:03.625490 | controller |
2025-10-27 00:18:03.738933 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-10-27 00:18:03.738977 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-10-27 00:18:03.963901 | controller | ok: Runtime: 0:00:39.632480
2025-10-27 00:18:03.976938 | 
2025-10-27 00:18:03.977115 | TASK [Install pytest-forked into virtualenv]
2025-10-27 00:18:20.001288 | controller | Collecting pytest-forked
2025-10-27 00:18:32.232012 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-27 00:18:32.278082 | controller | Collecting py
2025-10-27 00:18:32.281525 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-27 00:18:32.305907 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.1 MB/s eta 0:00:00
2025-10-27 00:18:32.472989 | controller | Collecting pytest>=3.10
2025-10-27 00:18:32.497425 | controller |   Downloading pytest-8.3.5-py3-none-any.whl (343 kB)
2025-10-27 00:18:32.573922 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 343.6/343.6 kB 4.8 MB/s eta 0:00:00
2025-10-27 00:18:32.666550 | controller | Collecting packaging
2025-10-27 00:18:32.670670 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-27 00:18:32.680618 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.9 MB/s eta 0:00:00
2025-10-27 00:18:32.714948 | controller | Collecting exceptiongroup>=1.0.0rc8
2025-10-27 00:18:32.720057 | controller |   Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB)
2025-10-27 00:18:32.746535 | controller | Collecting iniconfig
2025-10-27 00:18:32.750813 | controller |   Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB)
2025-10-27 00:18:32.791344 | controller | Collecting pluggy<2,>=1.5
2025-10-27 00:18:32.796614 | controller |   Downloading pluggy-1.5.0-py3-none-any.whl (20 kB)
2025-10-27 00:18:32.848121 | controller | Collecting tomli>=1
2025-10-27 00:18:32.851953 | controller |   Downloading tomli-2.3.0-py3-none-any.whl (14 kB)
2025-10-27 00:18:32.928293 | controller | Collecting typing-extensions>=4.6.0
2025-10-27 00:18:32.933337 | controller |   Downloading typing_extensions-4.13.2-py3-none-any.whl (45 kB)
2025-10-27 00:18:32.941940 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 6.6 MB/s eta 0:00:00
2025-10-27 00:18:33.014250 | controller | Installing collected packages: typing-extensions, tomli, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked
2025-10-27 00:18:33.419365 | 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-10-27 00:18:33.423951 | controller |
2025-10-27 00:18:33.491239 | controller | [notice] A new release of pip available: 22.2.2 -> 25.0.1
2025-10-27 00:18:33.491293 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip
2025-10-27 00:18:33.563777 | controller | ok: Runtime: 0:00:29.268724
2025-10-27 00:18:33.570711 | 
2025-10-27 00:18:33.570806 | TASK [Update pip]
2025-10-27 00:18:34.105479 | controller | Requirement already satisfied: pip in ./venv/lib/python3.8/site-packages (22.2.2)
2025-10-27 00:18:44.646019 | controller | Collecting pip
2025-10-27 00:18:56.811867 | controller |   Downloading pip-25.0.1-py3-none-any.whl (1.8 MB)
2025-10-27 00:18:56.879414 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 28.8 MB/s eta 0:00:00
2025-10-27 00:18:56.935538 | controller | Installing collected packages: pip
2025-10-27 00:18:56.935786 | controller |   Attempting uninstall: pip
2025-10-27 00:18:56.936485 | controller |     Found existing installation: pip 22.2.2
2025-10-27 00:18:57.107808 | controller |     Uninstalling pip-22.2.2:
2025-10-27 00:18:57.123541 | controller |       Successfully uninstalled pip-22.2.2
2025-10-27 00:18:57.899429 | controller | Successfully installed pip-25.0.1
2025-10-27 00:18:58.119492 | controller | ok: Runtime: 0:00:24.174228
2025-10-27 00:18:58.134456 | 
2025-10-27 00:18:58.134656 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-27 00:18:58.365425 | controller | changed
2025-10-27 00:18:58.380592 | 
2025-10-27 00:18:58.380834 | TASK [Install ansible into virtualenv]
2025-10-27 00:18:58.920931 | controller | Processing ./src/github.com/ansible/ansible
2025-10-27 00:18:58.921816 | controller |   Preparing metadata (setup.py): started
2025-10-27 00:18:59.362283 | controller |   Preparing metadata (setup.py): finished with status 'done'
2025-10-27 00:19:09.102491 | controller | Collecting jinja2 (from ansible-base==2.10.17.post0)
2025-10-27 00:19:19.309719 | controller |   Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB)
2025-10-27 00:19:19.428157 | controller | Collecting PyYAML (from ansible-base==2.10.17.post0)
2025-10-27 00:19:19.433979 | 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-10-27 00:19:19.687933 | controller | Collecting cryptography (from ansible-base==2.10.17.post0)
2025-10-27 00:19:19.700269 | controller |   Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB)
2025-10-27 00:19:19.721868 | controller | Requirement already satisfied: packaging in ./venv/lib/python3.8/site-packages (from ansible-base==2.10.17.post0) (25.0)
2025-10-27 00:19:19.861415 | controller | Collecting cffi>=1.14 (from cryptography->ansible-base==2.10.17.post0)
2025-10-27 00:19:19.932175 | controller |   Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (1.5 kB)
2025-10-27 00:19:19.941517 | 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-10-27 00:19:20.014621 | controller | Collecting MarkupSafe>=2.0 (from jinja2->ansible-base==2.10.17.post0)
2025-10-27 00:19:20.019994 | controller |   Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB)
2025-10-27 00:19:20.042382 | controller | Collecting pycparser (from cffi>=1.14->cryptography->ansible-base==2.10.17.post0)
2025-10-27 00:19:20.047314 | controller |   Downloading pycparser-2.23-py3-none-any.whl.metadata (993 bytes)
2025-10-27 00:19:20.068869 | controller | Downloading cryptography-46.0.3-cp38-abi3-manylinux_2_34_x86_64.whl (4.5 MB)
2025-10-27 00:19:20.137612 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.5/4.5 MB 70.3 MB/s eta 0:00:00
2025-10-27 00:19:20.143461 | controller | Downloading jinja2-3.1.6-py3-none-any.whl (134 kB)
2025-10-27 00:19:20.157272 | 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-10-27 00:19:20.212254 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 806.0/806.0 kB 11.2 MB/s eta 0:00:00
2025-10-27 00:19:20.219215 | controller | Downloading cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB)
2025-10-27 00:19:20.261481 | controller | Downloading MarkupSafe-2.1.5-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (26 kB)
2025-10-27 00:19:20.277493 | controller | Downloading pycparser-2.23-py3-none-any.whl (118 kB)
2025-10-27 00:19:20.303063 | controller | Building wheels for collected packages: ansible-base
2025-10-27 00:19:20.303896 | controller |   Building wheel for ansible-base (setup.py): started
2025-10-27 00:19:21.438655 | controller |   Building wheel for ansible-base (setup.py): finished with status 'done'
2025-10-27 00:19:21.443424 | controller |   Created wheel for ansible-base: filename=ansible_base-2.10.17.post0-py3-none-any.whl size=1881569 sha256=bb848153c131e1b3fee6b9288818cff266527b28495f0dab642713f3a8dc9c48
2025-10-27 00:19:21.443969 | controller |   Stored in directory: /var/tmp/ansible-test-pip/pip-ephem-wheel-cache-fhzfnbr0/wheels/a5/4b/fa/b6deaae105422b0b3b92831e0369d44bf7fca5bb3413d79be7
2025-10-27 00:19:21.452866 | controller | Successfully built ansible-base
2025-10-27 00:19:21.488817 | controller | Installing collected packages: PyYAML, pycparser, MarkupSafe, jinja2, cffi, cryptography, ansible-base
2025-10-27 00:19:22.938619 | 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-10-27 00:19:23.451511 | controller | ok: Runtime: 0:00:24.413275
2025-10-27 00:19:23.458840 | 
2025-10-27 00:19:23.458952 | TASK [Setup download-artifact-fork role]
2025-10-27 00:19:23.481006 | controller | ok
2025-10-27 00:19:23.502017 | 
2025-10-27 00:19:23.502157 | TASK [download-artifact-fork : Parse inventory response]
2025-10-27 00:19:23.533886 | controller | ok
2025-10-27 00:19:23.540613 | 
2025-10-27 00:19:23.540721 | TASK [download-artifact-fork : Fetch info from Zuul API]
2025-10-27 00:19:23.565176 | controller | skipping: Conditional result was False
2025-10-27 00:19:23.573763 | 
2025-10-27 00:19:23.573846 | TASK [download-artifact-fork : Parse build response]
2025-10-27 00:19:23.599469 | controller | skipping: Conditional result was False
2025-10-27 00:19:23.606602 | 
2025-10-27 00:19:23.606674 | TASK [download-artifact-fork : Ensure artifacts directory exists]
2025-10-27 00:19:24.078658 | controller | changed
2025-10-27 00:19:24.084860 | 
2025-10-27 00:19:24.084929 | LOOP [download-artifact-fork : Download archive by type]
2025-10-27 00:19:24.124618 | controller | skipping: Conditional result was False
2025-10-27 00:19:24.125114 | 
2025-10-27 00:19:25.279899 | controller | changed: OK (20189 bytes)
2025-10-27 00:19:25.306242 | 
2025-10-27 00:19:25.306418 | TASK [deploy-artifacts : define __collections]
2025-10-27 00:19:25.341099 | controller | ok
2025-10-27 00:19:25.348812 | 
2025-10-27 00:19:25.348908 | LOOP [deploy-artifacts : Create list of collections]
2025-10-27 00:19:25.379916 | controller | skipping: Conditional result was False
2025-10-27 00:19:25.398890 | controller | ok:
2025-10-27 00:19:25.399143 | controller | {
2025-10-27 00:19:25.399215 | controller |   "branch": "main",
2025-10-27 00:19:25.399261 | controller |   "job": "build-ansible-collection",
2025-10-27 00:19:25.399302 | controller |   "metadata": {
2025-10-27 00:19:25.399340 | controller |     "type": "ansible_collection",
2025-10-27 00:19:25.399378 | controller |     "version": "5.0.0"
2025-10-27 00:19:25.399415 | controller |   },
2025-10-27 00:19:25.399452 | controller |   "name": "ansible.network",
2025-10-27 00:19:25.399488 | controller |   "project": "ansible-collections/ansible.network",
2025-10-27 00:19:25.399525 | controller |   "url": "https://6f27dba4a6cd11ea02c0-9fef0acf01129b3386356f551f8206d1.ssl.cf5.rackcdn.com/ansible/3b6c715cf02e40e29797dc3f4e68a9c5/artifacts/ansible-network-5.0.0.tar.gz"
2025-10-27 00:19:25.399577 | controller | }
2025-10-27 00:19:25.472714 | 
2025-10-27 00:19:25.472895 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy]
2025-10-27 00:19:26.051404 | controller | Starting galaxy collection install process
2025-10-27 00:19:26.051660 | controller | Process install dependency map
2025-10-27 00:25:15.088516 | controller | Starting collection install process
2025-10-27 00:25:15.088672 | controller | Installing 'ansible.network:5.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/network'
2025-10-27 00:25:15.101368 | controller | ansible.network (5.0.0) was installed successfully
2025-10-27 00:25:15.101469 | controller | Installing 'ansible.netcommon:8.1.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2025-10-27 00:25:15.101670 | 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-4063ueepsmnj/tmpwpdkh4p9
2025-10-27 00:25:58.166249 | controller | ansible.netcommon (8.1.0) was installed successfully
2025-10-27 00:25:58.166464 | controller | Installing 'ansible.utils:6.0.0' to '/home/zuul/.ansible/collections/ansible_collections/ansible/utils'
2025-10-27 00:25:58.166735 | 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-4063ueepsmnj/tmpwpdkh4p9
2025-10-27 00:26:39.581066 | controller | ansible.utils (6.0.0) was installed successfully
2025-10-27 00:26:39.581131 | controller | Installing 'arista.eos:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/arista/eos'
2025-10-27 00:26:39.581153 | 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-4063ueepsmnj/tmpwpdkh4p9
2025-10-27 00:27:23.066376 | controller | arista.eos (12.0.0) was installed successfully
2025-10-27 00:27:23.066471 | controller | Installing 'cisco.ios:11.1.1' to '/home/zuul/.ansible/collections/ansible_collections/cisco/ios'
2025-10-27 00:27:23.066488 | 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-4063ueepsmnj/tmpwpdkh4p9
2025-10-27 00:28:07.663694 | controller | cisco.ios (11.1.1) was installed successfully
2025-10-27 00:28:07.663821 | controller | Installing 'cisco.iosxr:12.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/iosxr'
2025-10-27 00:28:07.663969 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/cisco-iosxr-12.0.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-4063ueepsmnj/tmpwpdkh4p9
2025-10-27 00:28:50.588297 | controller | cisco.iosxr (12.0.0) was installed successfully
2025-10-27 00:28:50.588362 | controller | Installing 'cisco.nxos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/cisco/nxos'
2025-10-27 00:28:50.588378 | 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-4063ueepsmnj/tmpwpdkh4p9
2025-10-27 00:29:34.158869 | controller | cisco.nxos (11.0.0) was installed successfully
2025-10-27 00:29:34.158959 | controller | Installing 'junipernetworks.junos:11.0.0' to '/home/zuul/.ansible/collections/ansible_collections/junipernetworks/junos'
2025-10-27 00:29:34.158978 | 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-4063ueepsmnj/tmpwpdkh4p9
2025-10-27 00:30:31.010515 | controller | junipernetworks.junos (11.0.0) was installed successfully
2025-10-27 00:30:31.341136 | controller | ok: Runtime: 0:11:05.357043
2025-10-27 00:30:31.356471 | 
2025-10-27 00:30:31.356603 | TASK [podman may need iptables kernel modules]
2025-10-27 00:30:31.893297 | controller | ok: Runtime: 0:00:00.003734
2025-10-27 00:30:31.930796 | 
2025-10-27 00:30:31.931014 | PLAY RECAP
2025-10-27 00:30:31.931102 | controller | ok: 46 changed: 26 unreachable: 0 failed: 0 skipped: 17 rescued: 0 ignored: 0
2025-10-27 00:30:31.931148 | 
2025-10-27 00:30:32.099364 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-27 00:30:32.100441 | RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-10-27 00:30:32.786572 | 
2025-10-27 00:30:32.786737 | PLAY [controller]
2025-10-27 00:30:32.812050 | 
2025-10-27 00:30:32.812193 | TASK [Copy the galaxy.yml on the controller]
2025-10-27 00:30:33.804171 | controller | changed
2025-10-27 00:30:33.820023 | 
2025-10-27 00:30:33.820236 | TASK [Load information from galaxy.yml]
2025-10-27 00:30:33.872164 | controller | ok
2025-10-27 00:30:33.888134 | 
2025-10-27 00:30:33.888555 | LOOP [Enable FIPS mode]
2025-10-27 00:30:33.927053 | 
2025-10-27 00:30:33.927914 | LOOP [ansible-test : Include branch specific variables.]
2025-10-27 00:30:33.985173 | controller | ok: "/var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/untrusted/project_2/github.com/ansible/ansible-zuul-jobs/roles/ansible-test/vars/default.yaml"
2025-10-27 00:30:33.985415 | 
2025-10-27 00:30:33.998060 | 
2025-10-27 00:30:33.998238 | TASK [ansible-test : Setup --skip-tags for test_options]
2025-10-27 00:30:34.043507 | controller | ok
2025-10-27 00:30:34.051320 | 
2025-10-27 00:30:34.051435 | TASK [ansible-test : Enable --inventory for network-integration]
2025-10-27 00:30:34.077910 | controller | skipping: Conditional result was False
2025-10-27 00:30:34.087333 | 
2025-10-27 00:30:34.087431 | TASK [ansible-test : Enable --retry-on-error]
2025-10-27 00:30:34.114296 | controller | skipping: Conditional result was False
2025-10-27 00:30:34.125131 | 
2025-10-27 00:30:34.125248 | TASK [ansible-test : Enable --continue-on-error]
2025-10-27 00:30:34.159807 | controller | ok
2025-10-27 00:30:34.167309 | 
2025-10-27 00:30:34.167385 | TASK [ansible-test : Enable --requirements]
2025-10-27 00:30:34.183431 | controller | skipping: Conditional result was False
2025-10-27 00:30:34.193519 | 
2025-10-27 00:30:34.193603 | TASK [ansible-test : Adjust options for unit tests]
2025-10-27 00:30:34.217777 | controller | skipping: Conditional result was False
2025-10-27 00:30:34.225891 | 
2025-10-27 00:30:34.225979 | TASK [ansible-test : Install requirements with unit tests]
2025-10-27 00:30:34.255823 | controller | ok
2025-10-27 00:30:34.261320 | 
2025-10-27 00:30:34.261383 | TASK [ansible-test : Set --skip-test]
2025-10-27 00:30:34.306148 | controller | skipping: Conditional result was False
2025-10-27 00:30:34.313138 | 
2025-10-27 00:30:34.313210 | TASK [ansible-test : Reduce verbosity]
2025-10-27 00:30:34.350232 | controller | ok
2025-10-27 00:30:34.395475 | 
2025-10-27 00:30:34.395649 | TASK [ansible-test : Setup --python option]
2025-10-27 00:30:34.430734 | controller | skipping: Conditional result was False
2025-10-27 00:30:34.437970 | 
2025-10-27 00:30:34.438042 | TASK [ansible-test : Setup --docker option]
2025-10-27 00:30:34.480546 | controller | ok
2025-10-27 00:30:34.487758 | 
2025-10-27 00:30:34.487829 | TASK [ansible-test : check if MANIFEST.json exists]
2025-10-27 00:30:35.056373 | controller | ok
2025-10-27 00:30:35.070113 | 
2025-10-27 00:30:35.070268 | TASK [ansible-test : Copy the MANIFEST.json on the controller]
2025-10-27 00:30:35.097819 | controller | skipping: Conditional result was False
2025-10-27 00:30:35.113731 | 
2025-10-27 00:30:35.113911 | TASK [ansible-test : Load information from MANIFEST.json]
2025-10-27 00:30:35.141812 | controller | skipping: Conditional result was False
2025-10-27 00:30:35.157480 | 
2025-10-27 00:30:35.157706 | TASK [ansible-test : Setup location of project for integration tests]
2025-10-27 00:30:35.184647 | controller | skipping: Conditional result was False
2025-10-27 00:30:35.197512 | 
2025-10-27 00:30:35.197649 | TASK [ansible-test : Copy the galaxy.yml on the controller]
2025-10-27 00:30:35.925058 | controller | ok
2025-10-27 00:30:35.930772 | 
2025-10-27 00:30:35.930847 | TASK [ansible-test : Load information from galaxy.yml]
2025-10-27 00:30:35.973077 | controller | ok
2025-10-27 00:30:35.978995 | 
2025-10-27 00:30:35.979064 | TASK [ansible-test : Setup location of project for integration tests]
2025-10-27 00:30:36.025496 | controller | ok
2025-10-27 00:30:36.033486 | 
2025-10-27 00:30:36.033575 | TASK [ansible-test : Setup minimum test requirements]
2025-10-27 00:30:36.068530 | controller | ok
2025-10-27 00:30:36.076630 | 
2025-10-27 00:30:36.076737 | TASK [ansible-test : Ensure pip temp directory exists in /var/tmp]
2025-10-27 00:30:36.850606 | controller | ok
2025-10-27 00:30:36.866579 | 
2025-10-27 00:30:36.866832 | TASK [ansible-test : Install python requirements]
2025-10-27 00:30:50.871477 | controller | Collecting yamllint (from -r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-10-27 00:31:03.115677 | controller |   Downloading yamllint-1.35.1-py3-none-any.whl.metadata (4.2 kB)
2025-10-27 00:31:03.145609 | controller | Collecting pathspec>=0.5.3 (from yamllint->-r /home/zuul/.ansible/collections/ansible_collections/ansible/network/test-requirements.txt (line 1))
2025-10-27 00:31:03.229024 | controller |   Downloading pathspec-0.12.1-py3-none-any.whl.metadata (21 kB)
2025-10-27 00:31:03.238253 | 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-10-27 00:31:03.247517 | controller | Downloading yamllint-1.35.1-py3-none-any.whl (66 kB)
2025-10-27 00:31:03.258914 | controller | Downloading pathspec-0.12.1-py3-none-any.whl (31 kB)
2025-10-27 00:31:03.300508 | controller | Installing collected packages: pathspec, yamllint
2025-10-27 00:31:03.362354 | controller | Successfully installed pathspec-0.12.1 yamllint-1.35.1
2025-10-27 00:31:03.471265 | controller | ok: Runtime: 0:00:25.914126
2025-10-27 00:31:03.477719 | 
2025-10-27 00:31:03.477782 | TASK [ansible-test : Copy potential cloud provider configuration for ansible-test in the collection]
2025-10-27 00:31:04.008995 | controller | skipping: Conditional result was False
2025-10-27 00:31:04.025066 | 
2025-10-27 00:31:04.025285 | TASK [ansible-test : Enable persistent connection logging]
2025-10-27 00:31:04.766665 | controller | changed: section and option added
2025-10-27 00:31:04.776869 | 
2025-10-27 00:31:04.777015 | TASK [ansible-test : Set persistent ssh_type value]
2025-10-27 00:31:05.372181 | controller | changed: option added
2025-10-27 00:31:05.385966 | 
2025-10-27 00:31:05.386139 | TASK [ansible-test : Set ansible log path]
2025-10-27 00:31:05.777205 | controller | changed: section and option added
2025-10-27 00:31:05.793747 | 
2025-10-27 00:31:05.793955 | TASK [ansible-test : Identify the changed targets]
2025-10-27 00:31:06.384508 | controller | skipping: Conditional result was False
2025-10-27 00:31:06.395073 | 
2025-10-27 00:31:06.395207 | TASK [ansible-test : set_fact]
2025-10-27 00:31:06.451469 | controller | skipping: Conditional result was False
2025-10-27 00:31:06.460314 | 
2025-10-27 00:31:06.460408 | TASK [ansible-test : Set the targets]
2025-10-27 00:31:06.494258 | controller | ok
2025-10-27 00:31:06.502932 | 
2025-10-27 00:31:06.503039 | TASK [ansible-test : set_fact]
2025-10-27 00:31:06.529057 | controller | skipping: Conditional result was False
2025-10-27 00:31:06.538022 | 
2025-10-27 00:31:06.538123 | TASK [ansible-test : List the targets]
2025-10-27 00:31:07.081877 | controller | skipping: Conditional result was False
2025-10-27 00:31:07.092105 | 
2025-10-27 00:31:07.092254 | TASK [ansible-test : set_fact]
2025-10-27 00:31:07.118009 | controller | skipping: Conditional result was False
2025-10-27 00:31:07.128153 | 
2025-10-27 00:31:07.128279 | TASK [ansible-test : set_fact]
2025-10-27 00:31:07.153662 | controller | skipping: Conditional result was False
2025-10-27 00:31:07.162976 | 
2025-10-27 00:31:07.163130 | LOOP [ansible-test : set_fact]
2025-10-27 00:31:07.232782 | 
2025-10-27 00:31:07.233067 | TASK [ansible-test : set_fact]
2025-10-27 00:31:07.259762 | controller | skipping: Conditional result was False
2025-10-27 00:31:07.274164 | 
2025-10-27 00:31:07.274323 | TASK [ansible-test : debug]
2025-10-27 00:31:07.291128 | controller | skipping: Conditional result was False
2025-10-27 00:31:07.310031 | 
2025-10-27 00:31:07.310237 | TASK [ansible-test : debug]
2025-10-27 00:31:07.354502 | About to run: ansible-test sanity --requirements --docker -v
2025-10-27 00:31:07.360732 | 
2025-10-27 00:31:07.360824 | TASK [ansible-test : Run the test suite]
2025-10-27 00:31:08.304983 | controller | Run command: docker images quay.io/ansible/default-test-container:2.9.0 --format '{{json .}}'
2025-10-27 00:31:08.354475 | controller | Run command: docker pull quay.io/ansible/default-test-container:2.9.0
2025-10-27 00:31:10.033663 | controller | 2.9.0: Pulling from ansible/default-test-container
2025-10-27 00:31:10.033921 | controller | 171857c49d0f: Pulling fs layer
2025-10-27 00:31:10.037454 | controller | 419640447d26: Pulling fs layer
2025-10-27 00:31:10.037472 | controller | 61e52f862619: Pulling fs layer
2025-10-27 00:31:10.037479 | controller | 851de0426e26: Pulling fs layer
2025-10-27 00:31:10.037490 | controller | 37425716ea5b: Pulling fs layer
2025-10-27 00:31:10.037510 | controller | cd9b0c439616: Pulling fs layer
2025-10-27 00:31:10.037517 | controller | d4612dbd8855: Pulling fs layer
2025-10-27 00:31:10.037522 | controller | 554699364730: Pulling fs layer
2025-10-27 00:31:10.037528 | controller | 1ff15d4bdb3e: Pulling fs layer
2025-10-27 00:31:10.037534 | controller | 5f2e4724adea: Pulling fs layer
2025-10-27 00:31:10.037539 | controller | a02d9a95ccb8: Pulling fs layer
2025-10-27 00:31:10.037545 | controller | 989f4ce370cb: Pulling fs layer
2025-10-27 00:31:10.037551 | controller | 0d7f52cdf9df: Pulling fs layer
2025-10-27 00:31:10.037556 | controller | c423742351d5: Pulling fs layer
2025-10-27 00:31:10.037562 | controller | 109236341d21: Pulling fs layer
2025-10-27 00:31:10.037568 | controller | 07a2f61c96b8: Pulling fs layer
2025-10-27 00:31:10.037574 | controller | 041f122f27ae: Pulling fs layer
2025-10-27 00:31:10.037579 | controller | ca6f5098b12e: Pulling fs layer
2025-10-27 00:31:10.037584 | controller | 1eb3e7b2afd9: Pulling fs layer
2025-10-27 00:31:10.037590 | controller | 18a0b750727a: Pulling fs layer
2025-10-27 00:31:10.037595 | controller | 17f2f596716c: Pulling fs layer
2025-10-27 00:31:10.037603 | controller | f35a9998a9bd: Pulling fs layer
2025-10-27 00:31:10.037609 | controller | fdfc10566405: Pulling fs layer
2025-10-27 00:31:10.037614 | controller | 1ff1c442c5fe: Pulling fs layer
2025-10-27 00:31:10.037620 | controller | a3443c4a17ed: Pulling fs layer
2025-10-27 00:31:10.037625 | controller | 0edcf9fb2b15: Pulling fs layer
2025-10-27 00:31:10.037631 | controller | 5af43b69e845: Pulling fs layer
2025-10-27 00:31:10.037637 | controller | 1651773effb2: Pulling fs layer
2025-10-27 00:31:10.037643 | controller | 79e23c5c0fe4: Pulling fs layer
2025-10-27 00:31:10.037657 | controller | e5058b1faaa6: Pulling fs layer
2025-10-27 00:31:10.037664 | controller | 846775490569: Pulling fs layer
2025-10-27 00:31:10.037674 | controller | 851de0426e26: Waiting
2025-10-27 00:31:10.037909 | controller | 37425716ea5b: Waiting
2025-10-27 00:31:10.037934 | controller | cd9b0c439616: Waiting
2025-10-27 00:31:10.037944 | controller | d4612dbd8855: Waiting
2025-10-27 00:31:10.038036 | controller | 554699364730: Waiting
2025-10-27 00:31:10.038050 | controller | 1ff15d4bdb3e: Waiting
2025-10-27 00:31:10.038060 | controller | 5f2e4724adea: Waiting
2025-10-27 00:31:10.038065 | controller | a02d9a95ccb8: Waiting
2025-10-27 00:31:10.038070 | controller | 989f4ce370cb: Waiting
2025-10-27 00:31:10.038076 | controller | 0d7f52cdf9df: Waiting
2025-10-27 00:31:10.038081 | controller | c423742351d5: Waiting
2025-10-27 00:31:10.038277 | controller | 109236341d21: Waiting
2025-10-27 00:31:10.038284 | controller | 07a2f61c96b8: Waiting
2025-10-27 00:31:10.038290 | controller | 041f122f27ae: Waiting
2025-10-27 00:31:10.041243 | controller | ca6f5098b12e: Waiting
2025-10-27 00:31:10.041252 | controller | 1eb3e7b2afd9: Waiting
2025-10-27 00:31:10.041257 | controller | 18a0b750727a: Waiting
2025-10-27 00:31:10.041271 | controller | 17f2f596716c: Waiting
2025-10-27 00:31:10.041280 | controller | f35a9998a9bd: Waiting
2025-10-27 00:31:10.041285 | controller | fdfc10566405: Waiting
2025-10-27 00:31:10.041290 | controller | 1ff1c442c5fe: Waiting
2025-10-27 00:31:10.041295 | controller | a3443c4a17ed: Waiting
2025-10-27 00:31:10.041301 | controller | 0edcf9fb2b15: Waiting
2025-10-27 00:31:10.041309 | controller | 5af43b69e845: Waiting
2025-10-27 00:31:10.941422 | controller | 1651773effb2: Waiting
2025-10-27 00:31:10.941529 | controller | 79e23c5c0fe4: Waiting
2025-10-27 00:31:10.941537 | controller | e5058b1faaa6: Waiting
2025-10-27 00:31:10.941544 | controller | 846775490569: Waiting
2025-10-27 00:31:10.941558 | controller | 419640447d26: Verifying Checksum
2025-10-27 00:31:11.039051 | controller | 419640447d26: Download complete
2025-10-27 00:31:11.039092 | controller | 61e52f862619: Verifying Checksum
2025-10-27 00:31:12.111345 | controller | 61e52f862619: Download complete
2025-10-27 00:31:12.111401 | controller | 851de0426e26: Verifying Checksum
2025-10-27 00:31:12.735047 | controller | 851de0426e26: Download complete
2025-10-27 00:31:12.735115 | controller | 171857c49d0f: Verifying Checksum
2025-10-27 00:31:12.913052 | controller | 171857c49d0f: Download complete
2025-10-27 00:31:12.913097 | controller | cd9b0c439616: Verifying Checksum
2025-10-27 00:31:14.097909 | controller | cd9b0c439616: Download complete
2025-10-27 00:31:14.097948 | controller | d4612dbd8855: Verifying Checksum
2025-10-27 00:31:15.639928 | controller | d4612dbd8855: Download complete
2025-10-27 00:31:15.639989 | controller | 1ff15d4bdb3e: Verifying Checksum
2025-10-27 00:31:15.640046 | controller | 1ff15d4bdb3e: Download complete
2025-10-27 00:31:15.786194 | controller | 171857c49d0f: Pull complete
2025-10-27 00:31:15.823006 | controller | 419640447d26: Pull complete
2025-10-27 00:31:15.858315 | controller | 61e52f862619: Pull complete
2025-10-27 00:31:15.938110 | controller | 851de0426e26: Pull complete
2025-10-27 00:31:16.365581 | controller | 554699364730: Verifying Checksum
2025-10-27 00:31:16.879702 | controller | 554699364730: Download complete
2025-10-27 00:31:16.879762 | controller | 5f2e4724adea: Download complete
2025-10-27 00:31:17.801823 | controller | a02d9a95ccb8: Verifying Checksum
2025-10-27 00:31:17.802089 | controller | a02d9a95ccb8: Download complete
2025-10-27 00:31:18.069357 | controller | 989f4ce370cb: Verifying Checksum
2025-10-27 00:31:18.069444 | controller | 989f4ce370cb: Download complete
2025-10-27 00:31:19.003308 | controller | 0d7f52cdf9df: Verifying Checksum
2025-10-27 00:31:19.003397 | controller | 0d7f52cdf9df: Download complete
2025-10-27 00:31:19.084314 | controller | c423742351d5: Verifying Checksum
2025-10-27 00:31:19.084450 | controller | c423742351d5: Download complete
2025-10-27 00:31:19.836436 | controller | 37425716ea5b: Verifying Checksum
2025-10-27 00:31:19.837900 | controller | 37425716ea5b: Download complete
2025-10-27 00:31:20.732601 | controller | 07a2f61c96b8: Verifying Checksum
2025-10-27 00:31:20.732694 | controller | 07a2f61c96b8: Download complete
2025-10-27 00:31:21.067955 | controller | 041f122f27ae: Verifying Checksum
2025-10-27 00:31:21.068237 | controller | 041f122f27ae: Download complete
2025-10-27 00:31:22.461102 | controller | 1eb3e7b2afd9: Verifying Checksum
2025-10-27 00:31:22.461185 | controller | 1eb3e7b2afd9: Download complete
2025-10-27 00:31:22.655070 | controller | ca6f5098b12e: Verifying Checksum
2025-10-27 00:31:22.655146 | controller | ca6f5098b12e: Download complete
2025-10-27 00:31:22.930988 | controller | 109236341d21: Verifying Checksum
2025-10-27 00:31:22.931058 | controller | 109236341d21: Download complete
2025-10-27 00:31:23.736273 | controller | 17f2f596716c: Verifying Checksum
2025-10-27 00:31:23.736342 | controller | 17f2f596716c: Download complete
2025-10-27 00:31:23.997049 | controller | 18a0b750727a: Verifying Checksum
2025-10-27 00:31:23.997132 | controller | 18a0b750727a: Download complete
2025-10-27 00:31:24.080313 | controller | f35a9998a9bd: Verifying Checksum
2025-10-27 00:31:24.080372 | controller | f35a9998a9bd: Download complete
2025-10-27 00:31:25.071532 | controller | fdfc10566405: Verifying Checksum
2025-10-27 00:31:25.072064 | controller | fdfc10566405: Download complete
2025-10-27 00:31:25.134732 | controller | 1ff1c442c5fe: Verifying Checksum
2025-10-27 00:31:25.134784 | controller | 1ff1c442c5fe: Download complete
2025-10-27 00:31:25.998217 | controller | a3443c4a17ed: Verifying Checksum
2025-10-27 00:31:25.998439 | controller | a3443c4a17ed: Download complete
2025-10-27 00:31:26.861106 | controller | 5af43b69e845: Verifying Checksum
2025-10-27 00:31:26.861229 | controller | 5af43b69e845: Download complete
2025-10-27 00:31:26.923345 | controller | 0edcf9fb2b15: Verifying Checksum
2025-10-27 00:31:26.923417 | controller | 0edcf9fb2b15: Download complete
2025-10-27 00:31:28.216828 | controller | 1651773effb2: Verifying Checksum
2025-10-27 00:31:28.216893 | controller | 1651773effb2: Download complete
2025-10-27 00:31:28.578772 | controller | e5058b1faaa6: Verifying Checksum
2025-10-27 00:31:28.578839 | controller | e5058b1faaa6: Download complete
2025-10-27 00:31:28.898972 | controller | 79e23c5c0fe4: Verifying Checksum
2025-10-27 00:31:28.899265 | controller | 79e23c5c0fe4: Download complete
2025-10-27 00:31:31.314477 | controller | 846775490569: Verifying Checksum
2025-10-27 00:31:31.314806 | controller | 846775490569: Download complete
2025-10-27 00:31:34.335029 | controller | 37425716ea5b: Pull complete
2025-10-27 00:31:34.356469 | controller | cd9b0c439616: Pull complete
2025-10-27 00:31:34.480536 | controller | d4612dbd8855: Pull complete
2025-10-27 00:31:37.900600 | controller | 554699364730: Pull complete
2025-10-27 00:31:37.942500 | controller | 1ff15d4bdb3e: Pull complete
2025-10-27 00:31:37.967658 | controller | 5f2e4724adea: Pull complete
2025-10-27 00:31:38.010934 | controller | a02d9a95ccb8: Pull complete
2025-10-27 00:31:38.032330 | controller | 989f4ce370cb: Pull complete
2025-10-27 00:31:38.050727 | controller | 0d7f52cdf9df: Pull complete
2025-10-27 00:31:38.072606 | controller | c423742351d5: Pull complete
2025-10-27 00:31:39.364546 | controller | 109236341d21: Pull complete
2025-10-27 00:31:39.387370 | controller | 07a2f61c96b8: Pull complete
2025-10-27 00:31:39.414163 | controller | 041f122f27ae: Pull complete
2025-10-27 00:31:39.517996 | controller | ca6f5098b12e: Pull complete
2025-10-27 00:31:39.556579 | controller | 1eb3e7b2afd9: Pull complete
2025-10-27 00:31:39.595897 | controller | 18a0b750727a: Pull complete
2025-10-27 00:31:39.614884 | controller | 17f2f596716c: Pull complete
2025-10-27 00:31:39.634794 | controller | f35a9998a9bd: Pull complete
2025-10-27 00:31:39.656846 | controller | fdfc10566405: Pull complete
2025-10-27 00:31:39.678662 | controller | 1ff1c442c5fe: Pull complete
2025-10-27 00:31:40.664706 | controller | a3443c4a17ed: Pull complete
2025-10-27 00:31:41.750034 | controller | 0edcf9fb2b15: Pull complete
2025-10-27 00:31:43.351625 | controller | 5af43b69e845: Pull complete
2025-10-27 00:31:44.857774 | controller | 1651773effb2: Pull complete
2025-10-27 00:31:46.358502 | controller | 79e23c5c0fe4: Pull complete
2025-10-27 00:31:47.590831 | controller | e5058b1faaa6: Pull complete
2025-10-27 00:31:49.145608 | controller | 846775490569: Pull complete
2025-10-27 00:31:49.176631 | controller | Digest: sha256:923f4b465456ae05243474faf9061abbefa2c2c5b88f24455fa2d5ce3d8d2ab4
2025-10-27 00:31:49.183034 | controller | Status: Downloaded newer image for quay.io/ansible/default-test-container:2.9.0
2025-10-27 00:31:49.189967 | controller | quay.io/ansible/default-test-container:2.9.0
2025-10-27 00:31:49.192249 | controller | Run command: docker images quay.io/ansible/pypi-test-container:1.0.0 --format '{{json .}}'
2025-10-27 00:31:49.210987 | controller | Run command: docker pull quay.io/ansible/pypi-test-container:1.0.0
2025-10-27 00:31:50.936770 | controller | 1.0.0: Pulling from ansible/pypi-test-container
2025-10-27 00:31:50.937302 | controller | 04a5f4cda3ee: Pulling fs layer
2025-10-27 00:31:50.937444 | controller | ff496a88c8ed: Pulling fs layer
2025-10-27 00:31:50.937830 | controller | 0ce83f459fe7: Pulling fs layer
2025-10-27 00:31:50.939009 | controller | 2e5170e1f099: Pulling fs layer
2025-10-27 00:31:50.939266 | controller | 7641eb41b08c: Pulling fs layer
2025-10-27 00:31:50.939399 | controller | ad15fa9da398: Pulling fs layer
2025-10-27 00:31:50.939521 | controller | 087d91352424: Pulling fs layer
2025-10-27 00:31:50.939747 | controller | 8b92efd6a100: Pulling fs layer
2025-10-27 00:31:50.939810 | controller | 2e5170e1f099: Waiting
2025-10-27 00:31:50.939889 | controller | 7641eb41b08c: Waiting
2025-10-27 00:31:50.939953 | controller | ad15fa9da398: Waiting
2025-10-27 00:31:50.940007 | controller | 087d91352424: Waiting
2025-10-27 00:31:50.940061 | controller | 8b92efd6a100: Waiting
2025-10-27 00:31:51.939711 | controller | ff496a88c8ed: Verifying Checksum
2025-10-27 00:31:51.939802 | controller | ff496a88c8ed: Download complete
2025-10-27 00:31:52.122846 | controller | 0ce83f459fe7: Verifying Checksum
2025-10-27 00:31:52.122936 | controller | 0ce83f459fe7: Download complete
2025-10-27 00:31:52.597106 | controller | 04a5f4cda3ee: Verifying Checksum
2025-10-27 00:31:52.597213 | controller | 04a5f4cda3ee: Download complete
2025-10-27 00:31:53.356018 | controller | 7641eb41b08c: Download complete
2025-10-27 00:31:53.650522 | controller | 2e5170e1f099: Verifying Checksum
2025-10-27 00:31:53.650583 | controller | 2e5170e1f099: Download complete
2025-10-27 00:31:53.703455 | controller | ad15fa9da398: Verifying Checksum
2025-10-27 00:31:53.703553 | controller | ad15fa9da398: Download complete
2025-10-27 00:31:54.448893 | controller | 087d91352424: Verifying Checksum
2025-10-27 00:31:54.449024 | controller | 087d91352424: Download complete
2025-10-27 00:31:54.828729 | controller | 8b92efd6a100: Verifying Checksum
2025-10-27 00:31:54.828870 | controller | 8b92efd6a100: Download complete
2025-10-27 00:31:55.213851 | controller | 04a5f4cda3ee: Pull complete
2025-10-27 00:31:55.302670 | controller | ff496a88c8ed: Pull complete
2025-10-27 00:31:55.402317 | controller | 0ce83f459fe7: Pull complete
2025-10-27 00:31:56.617525 | controller | 2e5170e1f099: Pull complete
2025-10-27 00:31:56.676528 | controller | 7641eb41b08c: Pull complete
2025-10-27 00:31:56.717851 | controller | ad15fa9da398: Pull complete
2025-10-27 00:31:57.336000 | controller | 087d91352424: Pull complete
2025-10-27 00:31:57.383541 | controller | 8b92efd6a100: Pull complete
2025-10-27 00:31:57.411500 | controller | Digest: sha256:71042ab0a14971b5608fe75706de54f367fc31db573e3b3955182037f73cadb6
2025-10-27 00:31:57.422200 | controller | Status: Downloaded newer image for quay.io/ansible/pypi-test-container:1.0.0
2025-10-27 00:31:57.433044 | controller | quay.io/ansible/pypi-test-container:1.0.0
2025-10-27 00:31:57.435259 | controller | Run command: docker run --detach quay.io/ansible/pypi-test-container:1.0.0
2025-10-27 00:32:01.471981 | controller | Run command: docker inspect 9c0d12d988eddf897573767b47ce7c845b379d87197cb3a66c36f081a196722a
2025-10-27 00:32:01.506199 | controller | Scanning collection root: /home/zuul/.ansible/collections/ansible_collections
2025-10-27 00:32:01.514708 | controller | Including collection: ansible.netcommon (288 files)
2025-10-27 00:32:01.522137 | controller | Including collection: ansible.network (23 files)
2025-10-27 00:32:01.522160 | controller | Including collection: ansible.utils (442 files)
2025-10-27 00:32:01.547139 | controller | Including collection: arista.eos (1022 files)
2025-10-27 00:32:01.576008 | controller | Including collection: cisco.ios (1172 files)
2025-10-27 00:32:01.602781 | controller | Including collection: cisco.iosxr (1037 files)
2025-10-27 00:32:01.648787 | controller | Including collection: cisco.nxos (1680 files)
2025-10-27 00:32:01.674745 | controller | Including collection: junipernetworks.junos (963 files)
2025-10-27 00:32:01.697609 | controller | Creating a payload archive containing 7353 files...
2025-10-27 00:32:03.190367 | controller | Created a 5961495 byte payload archive containing 7353 files in 1 seconds.
2025-10-27 00:32:03.191390 | controller | Assuming Docker is available on localhost.
2025-10-27 00:32:03.191715 | 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-10-27 00:32:03.779824 | controller | Run command: docker exec -i ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 dd of=/root/docker.sh bs=65536
2025-10-27 00:32:03.831397 | controller | Run command: docker exec ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 /bin/bash /root/docker.sh
2025-10-27 00:32:03.886652 | controller | Run command: docker exec -i ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 dd of=/root/test.tgz bs=65536
2025-10-27 00:32:03.948888 | controller | Run command: docker exec ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 tar oxzf /root/test.tgz -C /root
2025-10-27 00:32:04.578659 | controller | Run command: docker exec ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 /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-29d706rb.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/
2025-10-27 00:32:04.830822 | controller | Injecting custom PyPI hosts entries: /etc/hosts
2025-10-27 00:32:04.831205 | controller | Injecting custom PyPI config: /root/.pip/pip.conf
2025-10-27 00:32:04.831226 | controller | Injecting custom PyPI config: /root/.pydistutils.cfg
2025-10-27 00:32:04.831241 | controller | Running sanity test 'action-plugin-docs' with Python 3.6
2025-10-27 00:32:04.831589 | controller | Read 0 sanity test ignore line(s) for Ansible 2.10 from: tests/sanity/ignore-2.10.txt
2025-10-27 00:32:04.836157 | controller | No tests applicable.
2025-10-27 00:32:04.836299 | controller | Running sanity test 'ansible-doc' with Python 3.6
2025-10-27 00:32:04.836315 | controller | No tests applicable.
2025-10-27 00:32:04.836434 | controller | Running sanity test 'changelog' with Python 3.6
2025-10-27 00:32:04.836758 | 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-10-27 00:32:05.419291 | 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-10-27 00:32:05.804038 | controller | Collecting antsibull-changelog==0.9.0 (from -r /root/ansible/test/lib/ansible_test/_data/requirements/sanity.changelog.txt (line 2))
2025-10-27 00:32:05.833897 | 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-10-27 00:32:05.834966 | 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-10-27 00:32:05.873699 | 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-10-27 00:32:05.873902 | controller | Removing custom PyPI config: /root/.pydistutils.cfg
2025-10-27 00:32:05.874091 | controller | Removing custom PyPI config: /root/.pip/pip.conf
2025-10-27 00:32:05.891013 | controller | Removing custom PyPI hosts entries: /etc/hosts
2025-10-27 00:32:05.891052 | controller | Run command: docker exec ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 tar czf /root/output.tgz --exclude .tmp -C /root/ansible_collections/ansible/network/tests output
2025-10-27 00:32:05.943361 | controller | Run command: docker exec -i ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 dd if=/root/output.tgz bs=65536
2025-10-27 00:32:05.988954 | controller | Run command: tar oxzf /tmp/ansible-result-3laakp8m.tgz -C /home/zuul/.ansible/collections/ansible_collections/ansible/network/tests
2025-10-27 00:32:06.000714 | controller | Run command: docker rm -f 9c0d12d988eddf897573767b47ce7c845b379d87197cb3a66c36f081a196722a
2025-10-27 00:32:06.997286 | controller | Run command: docker rm -f ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7
2025-10-27 00:32:07.420016 | controller | ERROR: Command "docker exec ba82098f1e4e07e44d3c71cd3830cbfc7714e18c14d44606df2b072766847af7 /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-29d706rb.json --truncate 0 --redact --color no --requirements --pypi-endpoint http://172.17.0.2:3141/root/pypi/+simple/" returned exit status 1.
2025-10-27 00:32:07.941390 | controller | ERROR
2025-10-27 00:32:07.941906 | controller | {
2025-10-27 00:32:07.942013 | controller |   "delta": "0:00:59.467508",
2025-10-27 00:32:07.942079 | controller |   "end": "2025-10-27 00:32:07.441814",
2025-10-27 00:32:07.942354 | controller |   "msg": "non-zero return code",
2025-10-27 00:32:07.942425 | controller |   "rc": 1,
2025-10-27 00:32:07.942482 | controller |   "start": "2025-10-27 00:31:07.974306"
2025-10-27 00:32:07.942540 | controller | }
failure
2025-10-27 00:32:07.951415 | 
2025-10-27 00:32:07.951538 | PLAY RECAP
2025-10-27 00:32:07.951654 | controller | ok: 20 changed: 5 unreachable: 0 failed: 1 skipped: 20 rescued: 0 ignored: 0
2025-10-27 00:32:07.951747 | 
2025-10-27 00:32:08.175204 | RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/run.yaml@master]
2025-10-27 00:32:08.177470 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-27 00:32:08.801922 | 
2025-10-27 00:32:08.802076 | PLAY [all]
2025-10-27 00:32:08.824763 | 
2025-10-27 00:32:08.824894 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-27 00:32:09.264048 | controller | changed: non-zero return code
2025-10-27 00:32:09.276864 | 
2025-10-27 00:32:09.277020 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-27 00:32:09.304359 | controller | skipping: Conditional result was False
2025-10-27 00:32:09.317877 | 
2025-10-27 00:32:09.318052 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-27 00:32:09.361777 | 
2025-10-27 00:32:09.362101 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-27 00:32:09.404994 | 
2025-10-27 00:32:09.405323 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-27 00:32:09.422932 | controller | skipping: Conditional result was False
2025-10-27 00:32:09.440383 | 
2025-10-27 00:32:09.440620 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-27 00:32:09.477989 | 
2025-10-27 00:32:09.478439 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-27 00:32:09.514609 | controller | skipping: Conditional result was False
2025-10-27 00:32:09.529195 | 
2025-10-27 00:32:09.529398 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-27 00:32:09.556711 | controller | skipping: Conditional result was False
2025-10-27 00:32:09.568319 | 
2025-10-27 00:32:09.568504 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-27 00:32:09.595216 | controller | skipping: Conditional result was False
2025-10-27 00:32:09.636822 | 
2025-10-27 00:32:09.636955 | PLAY RECAP
2025-10-27 00:32:09.637003 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-27 00:32:09.637031 | 
2025-10-27 00:32:09.766320 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-27 00:32:09.768794 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-27 00:32:10.420755 | 
2025-10-27 00:32:10.421054 | PLAY [all:!appliance*]
2025-10-27 00:32:10.446515 | 
2025-10-27 00:32:10.446658 | TASK [unregister the node]
2025-10-27 00:32:10.984276 | controller | skipping: Conditional result was False
2025-10-27 00:32:10.998928 | 
2025-10-27 00:32:10.999109 | TASK [include_role : fetch-output]
2025-10-27 00:32:11.061821 | controller | ok
2025-10-27 00:32:11.099995 | 
2025-10-27 00:32:11.100192 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-27 00:32:11.156851 | controller | skipping: Conditional result was False
2025-10-27 00:32:11.163532 | 
2025-10-27 00:32:11.163635 | TASK [fetch-output : Set log path for single node]
2025-10-27 00:32:11.193527 | controller | ok
2025-10-27 00:32:11.199258 | 
2025-10-27 00:32:11.199323 | LOOP [fetch-output : Ensure local output dirs]
2025-10-27 00:32:11.631628 | controller -> localhost | ok: "/var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/logs"
2025-10-27 00:32:11.883445 | controller -> localhost | changed: "/var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/artifacts"
2025-10-27 00:32:12.152781 | controller -> localhost | changed: "/var/lib/zuul/builds/0aa32a410eb74bdb827a3f4965d44f48/work/docs"
2025-10-27 00:32:12.174620 | 
2025-10-27 00:32:12.174868 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-27 00:32:12.977410 | controller | changed:
2025-10-27 00:32:12.977945 | controller | .d..t...... ./
2025-10-27 00:32:12.977998 | controller | cd+++++++++ controller/
2025-10-27 00:32:12.978046 | controller | changed: All items complete
2025-10-27 00:32:12.978172 | 
2025-10-27 00:32:13.559329 | controller | changed: .d..t...... ./
2025-10-27 00:32:14.065980 | controller | changed: .d..t...... ./
2025-10-27 00:32:14.092793 | 
2025-10-27 00:32:14.092959 | TASK [include_role : fetch-output-openshift]
2025-10-27 00:32:14.109501 | controller | skipping: Conditional result was False
2025-10-27 00:32:14.120417 | 
2025-10-27 00:32:14.120537 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-27 00:32:14.154528 | controller | skipping: Conditional result was False
2025-10-27 00:32:14.165059 | controller | skipping: Conditional result was False
2025-10-27 00:32:14.209415 | 
2025-10-27 00:32:14.209552 | PLAY [localhost]
2025-10-27 00:32:14.222237 | 
2025-10-27 00:32:14.222333 | TASK [Run Zuul manifest role]
2025-10-27 00:32:14.242368 | localhost | ok
2025-10-27 00:32:14.255610 | 
2025-10-27 00:32:14.255736 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-27 00:32:14.682275 | localhost | changed
2025-10-27 00:32:14.687029 | 
2025-10-27 00:32:14.687106 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-27 00:32:14.726290 | localhost | ok
2025-10-27 00:32:14.734468 | 
2025-10-27 00:32:14.734528 | TASK [Set zuul-log-path fact]
2025-10-27 00:32:14.754180 | localhost | ok
2025-10-27 00:32:14.768053 | 
2025-10-27 00:32:14.768126 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-27 00:32:14.807515 | localhost | ok
2025-10-27 00:32:14.815608 | 
2025-10-27 00:32:14.815708 | LOOP [Run upload-logs-swift role]
2025-10-27 00:32:14.872367 | localhost | Output suppressed because no_log was given
2025-10-27 00:32:14.898882 | 
2025-10-27 00:32:14.899018 | TASK [Set zuul-log-path fact]
2025-10-27 00:32:14.945157 | localhost | skipping: Conditional result was False
2025-10-27 00:32:14.958853 | 
2025-10-27 00:32:14.959085 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-27 00:32:15.417851 | localhost -> localhost | ok: Runtime: 0:00:00.004905
2025-10-27 00:32:15.428627 | 
2025-10-27 00:32:15.428828 | TASK [upload-logs-swift : Upload logs to swift]