2026-02-25 00:23:05.075496 | Job console starting... 2026-02-25 00:23:05.088969 | Updating repositories 2026-02-25 00:23:05.236987 | Preparing job workspace 2026-02-25 00:23:14.493941 | Running Ansible setup... 2026-02-25 00:23:19.814292 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-25 00:23:20.518606 | 2026-02-25 00:23:20.518885 | PLAY [localhost] 2026-02-25 00:23:20.530264 | 2026-02-25 00:23:20.530383 | TASK [Gathering Facts] 2026-02-25 00:23:21.597764 | localhost | ok 2026-02-25 00:23:21.629455 | 2026-02-25 00:23:21.629805 | TASK [Setup log path fact] 2026-02-25 00:23:21.656793 | localhost | ok 2026-02-25 00:23:21.679371 | 2026-02-25 00:23:21.679511 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-25 00:23:21.713463 | localhost | ok 2026-02-25 00:23:21.726243 | 2026-02-25 00:23:21.726376 | TASK [emit-job-header : Print job information] 2026-02-25 00:23:21.773269 | # Job Information 2026-02-25 00:23:21.773589 | Ansible Version: 2.15.12 2026-02-25 00:23:21.773665 | Job: ansible-test-sanity-docker-stable-2.11 2026-02-25 00:23:21.773778 | Pipeline: periodic 2026-02-25 00:23:21.773826 | Executor: ze04.softwarefactory-project.io 2026-02-25 00:23:21.773873 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-25 00:23:21.773924 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/9f4/ansible/9f418183a8c1429c8d64c098a755ef38/ 2026-02-25 00:23:21.773969 | Event ID: 79c881336d75451aa1b30c2394aae9ec 2026-02-25 00:23:21.780912 | 2026-02-25 00:23:21.781042 | LOOP [emit-job-header : Print node information] 2026-02-25 00:23:21.893827 | localhost | ok: 2026-02-25 00:23:21.894116 | localhost | # Node Information 2026-02-25 00:23:21.894159 | localhost | Inventory Hostname: controller 2026-02-25 00:23:21.894192 | localhost | Hostname: np0005628864 2026-02-25 00:23:21.894231 | localhost | Username: zuul 2026-02-25 00:23:21.894297 | localhost | Distro: Fedora 37 2026-02-25 00:23:21.894339 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-25 00:23:21.894370 | localhost | Region: ca-ymq-1 2026-02-25 00:23:21.894399 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-25 00:23:21.894426 | localhost | Product Name: OpenStack Nova 2026-02-25 00:23:21.894454 | localhost | Interface IP: 162.253.55.36 2026-02-25 00:23:21.908348 | 2026-02-25 00:23:21.908605 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-25 00:23:22.368987 | localhost -> localhost | changed 2026-02-25 00:23:22.377293 | 2026-02-25 00:23:22.377444 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-25 00:23:23.267494 | localhost -> localhost | changed 2026-02-25 00:23:23.290254 | 2026-02-25 00:23:23.290326 | PLAY [all:!appliance*] 2026-02-25 00:23:23.310112 | 2026-02-25 00:23:23.310261 | TASK [include_role : start-zuul-console] 2026-02-25 00:23:23.332300 | controller | ok 2026-02-25 00:23:23.349741 | 2026-02-25 00:23:23.349948 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-25 00:23:23.812830 | controller | ok 2026-02-25 00:23:23.827195 | 2026-02-25 00:23:23.827433 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-25 00:23:24.878564 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-25 00:23:24.888384 | 2026-02-25 00:23:24.888530 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-25 00:23:25.425058 | controller | skipping: Conditional result was False 2026-02-25 00:23:25.439494 | 2026-02-25 00:23:25.439740 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-25 00:23:25.468584 | controller | skipping: Conditional result was False 2026-02-25 00:23:25.484230 | 2026-02-25 00:23:25.484456 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-25 00:23:25.513967 | controller | skipping: Conditional result was False 2026-02-25 00:23:25.521952 | 2026-02-25 00:23:25.522030 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-25 00:23:25.546399 | controller | skipping: Conditional result was False 2026-02-25 00:23:25.557059 | 2026-02-25 00:23:25.557201 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-25 00:23:25.585031 | controller | skipping: Conditional result was False 2026-02-25 00:23:25.593531 | 2026-02-25 00:23:25.593721 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-25 00:23:25.618475 | controller | skipping: Conditional result was False 2026-02-25 00:23:25.638534 | 2026-02-25 00:23:25.638715 | TASK [Disable Fedora Modular] 2026-02-25 00:23:25.873976 | controller | changed 2026-02-25 00:23:25.880004 | 2026-02-25 00:23:25.880076 | TASK [Enable EPEL] 2026-02-25 00:23:25.905316 | controller | skipping: Conditional result was False 2026-02-25 00:23:25.913817 | 2026-02-25 00:23:25.913935 | TASK [Register the RHEL node] 2026-02-25 00:23:26.469037 | 2026-02-25 00:23:26.469370 | TASK [Show the subscription-manager status] 2026-02-25 00:23:27.066611 | controller | skipping: Conditional result was False 2026-02-25 00:23:27.084900 | 2026-02-25 00:23:27.085142 | TASK [Enable EPEL on RHEL] 2026-02-25 00:23:27.643293 | controller | skipping: Conditional result was False 2026-02-25 00:23:27.651667 | 2026-02-25 00:23:27.651813 | TASK [Install git and tox] 2026-02-25 00:24:48.079186 | controller | changed 2026-02-25 00:24:48.089509 | 2026-02-25 00:24:48.089741 | TASK [include_role : prepare-workspace] 2026-02-25 00:24:48.125879 | controller | ok 2026-02-25 00:24:48.161550 | 2026-02-25 00:24:48.161773 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-25 00:24:48.400187 | controller | ok 2026-02-25 00:24:48.409196 | 2026-02-25 00:24:48.409293 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-25 00:25:01.252058 | controller | Output suppressed because no_log was given 2026-02-25 00:25:01.303149 | 2026-02-25 00:25:01.303313 | TASK [include_role : prepare-workspace-openshift] 2026-02-25 00:25:01.321490 | controller | skipping: Conditional result was False 2026-02-25 00:25:01.344455 | 2026-02-25 00:25:01.344528 | PLAY [all:!appliance] 2026-02-25 00:25:01.361923 | 2026-02-25 00:25:01.362008 | TASK [Run add-build-sshkey role (RSA)] 2026-02-25 00:25:01.393570 | controller | ok 2026-02-25 00:25:01.411095 | 2026-02-25 00:25:01.411242 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-25 00:25:01.682340 | controller -> localhost | ok 2026-02-25 00:25:01.699354 | 2026-02-25 00:25:01.699507 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-25 00:25:01.740710 | controller | ok 2026-02-25 00:25:01.768645 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-25 00:25:01.777298 | 2026-02-25 00:25:01.777391 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-25 00:25:02.304600 | controller -> localhost | Generating public/private rsa key pair. 2026-02-25 00:25:02.304951 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/9f418183a8c1429c8d64c098a755ef38_id_rsa. 2026-02-25 00:25:02.304986 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/9f418183a8c1429c8d64c098a755ef38_id_rsa.pub. 2026-02-25 00:25:02.305009 | controller -> localhost | The key fingerprint is: 2026-02-25 00:25:02.305029 | controller -> localhost | SHA256:RdKf2sjl+J5kk5OvpCYxFsFEzR4dgXUew/jmYe/TVlo zuul-build-sshkey 2026-02-25 00:25:02.305049 | controller -> localhost | The key's randomart image is: 2026-02-25 00:25:02.305069 | controller -> localhost | +---[RSA 2048]----+ 2026-02-25 00:25:02.305088 | controller -> localhost | | +++.++=+ | 2026-02-25 00:25:02.305109 | controller -> localhost | | oo* oo.o | 2026-02-25 00:25:02.305128 | controller -> localhost | | o.o o. | 2026-02-25 00:25:02.305146 | controller -> localhost | | ... + = | 2026-02-25 00:25:02.305164 | controller -> localhost | | So B + o | 2026-02-25 00:25:02.305196 | controller -> localhost | | + = oo. E| 2026-02-25 00:25:02.305226 | controller -> localhost | | . o .O +o| 2026-02-25 00:25:02.305253 | controller -> localhost | | . .=.=..+| 2026-02-25 00:25:02.305274 | controller -> localhost | | o..+....| 2026-02-25 00:25:02.305295 | controller -> localhost | +----[SHA256]-----+ 2026-02-25 00:25:02.305355 | controller -> localhost | ok: Runtime: 0:00:00.155774 2026-02-25 00:25:02.313386 | 2026-02-25 00:25:02.313465 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-25 00:25:02.347695 | controller | ok 2026-02-25 00:25:02.359194 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-25 00:25:02.369974 | 2026-02-25 00:25:02.370071 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-25 00:25:02.396065 | controller | skipping: Conditional result was False 2026-02-25 00:25:02.406217 | 2026-02-25 00:25:02.406335 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-25 00:25:02.898803 | controller | changed 2026-02-25 00:25:02.906646 | 2026-02-25 00:25:02.906840 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-25 00:25:03.151572 | controller | ok 2026-02-25 00:25:03.168588 | 2026-02-25 00:25:03.168816 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-25 00:25:03.818984 | controller | changed 2026-02-25 00:25:03.826435 | 2026-02-25 00:25:03.826549 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-25 00:25:04.437121 | controller | changed 2026-02-25 00:25:04.452656 | 2026-02-25 00:25:04.453037 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-25 00:25:04.483579 | controller | skipping: Conditional result was False 2026-02-25 00:25:04.502029 | 2026-02-25 00:25:04.502238 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-25 00:25:04.951295 | controller -> localhost | changed 2026-02-25 00:25:04.966222 | 2026-02-25 00:25:04.966370 | TASK [add-build-sshkey : Add back temp key] 2026-02-25 00:25:05.257483 | controller -> localhost | Identity added: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/9f418183a8c1429c8d64c098a755ef38_id_rsa (zuul-build-sshkey) 2026-02-25 00:25:05.257817 | controller -> localhost | ok: Runtime: 0:00:00.008502 2026-02-25 00:25:05.267891 | 2026-02-25 00:25:05.268057 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-25 00:25:05.638430 | controller | ok 2026-02-25 00:25:05.654202 | 2026-02-25 00:25:05.654444 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-25 00:25:05.681541 | controller | skipping: Conditional result was False 2026-02-25 00:25:05.698758 | 2026-02-25 00:25:05.698895 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-25 00:25:05.728881 | controller | ok 2026-02-25 00:25:05.752264 | 2026-02-25 00:25:05.752370 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-25 00:25:06.034096 | controller -> localhost | ok 2026-02-25 00:25:06.041599 | 2026-02-25 00:25:06.041748 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-25 00:25:06.081544 | controller | ok 2026-02-25 00:25:06.102377 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-25 00:25:06.113672 | 2026-02-25 00:25:06.113860 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-25 00:25:06.405431 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-25 00:25:06.405760 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/9f418183a8c1429c8d64c098a755ef38_id_ecdsa. 2026-02-25 00:25:06.405793 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/9f418183a8c1429c8d64c098a755ef38_id_ecdsa.pub. 2026-02-25 00:25:06.405832 | controller -> localhost | The key fingerprint is: 2026-02-25 00:25:06.405854 | controller -> localhost | SHA256:Z6lknYt+/5aE9MpK+MmnbZHUn7cXodFI9ewZ2SUg2eE zuul-build-sshkey 2026-02-25 00:25:06.405874 | controller -> localhost | The key's randomart image is: 2026-02-25 00:25:06.405895 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-25 00:25:06.405913 | controller -> localhost | | .oooo..| 2026-02-25 00:25:06.405931 | controller -> localhost | | .o.. o=| 2026-02-25 00:25:06.405949 | controller -> localhost | | E.oo+| 2026-02-25 00:25:06.405966 | controller -> localhost | | . ooo.+o| 2026-02-25 00:25:06.405983 | controller -> localhost | | S *o +oo+| 2026-02-25 00:25:06.405999 | controller -> localhost | | o * .+.ooo| 2026-02-25 00:25:06.406015 | controller -> localhost | | + o. + .+| 2026-02-25 00:25:06.406033 | controller -> localhost | | . +.o= o..| 2026-02-25 00:25:06.406054 | controller -> localhost | | ..**oo. .| 2026-02-25 00:25:06.406080 | controller -> localhost | +----[SHA256]-----+ 2026-02-25 00:25:06.406144 | controller -> localhost | ok: Runtime: 0:00:00.012398 2026-02-25 00:25:06.414100 | 2026-02-25 00:25:06.414178 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-25 00:25:06.451158 | controller | ok 2026-02-25 00:25:06.462323 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-25 00:25:06.474526 | 2026-02-25 00:25:06.474626 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-25 00:25:06.500970 | controller | skipping: Conditional result was False 2026-02-25 00:25:06.509245 | 2026-02-25 00:25:06.509328 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-25 00:30:19.798362 | controller | changed 2026-02-25 00:30:19.806017 | 2026-02-25 00:30:19.806096 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-25 00:30:20.051214 | controller | ok 2026-02-25 00:30:20.064888 | 2026-02-25 00:30:20.065057 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-25 00:30:20.773668 | controller | changed 2026-02-25 00:30:20.787444 | 2026-02-25 00:30:20.787591 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-25 00:30:21.516901 | controller | changed 2026-02-25 00:30:21.523618 | 2026-02-25 00:30:21.523719 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-25 00:30:21.538244 | controller | skipping: Conditional result was False 2026-02-25 00:30:21.546730 | 2026-02-25 00:30:21.546856 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-25 00:30:21.795544 | controller -> localhost | changed 2026-02-25 00:30:21.817671 | 2026-02-25 00:30:21.817849 | TASK [add-build-sshkey : Add back temp key] 2026-02-25 00:30:22.140931 | controller -> localhost | Identity added: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/9f418183a8c1429c8d64c098a755ef38_id_ecdsa (zuul-build-sshkey) 2026-02-25 00:30:22.141207 | controller -> localhost | ok: Runtime: 0:00:00.014880 2026-02-25 00:30:22.149206 | 2026-02-25 00:30:22.149345 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-25 00:30:22.394308 | controller | ok 2026-02-25 00:30:22.401620 | 2026-02-25 00:30:22.401742 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-25 00:30:22.426386 | controller | skipping: Conditional result was False 2026-02-25 00:30:22.437916 | 2026-02-25 00:30:22.438023 | TASK [include_role : remove-zuul-sshkey] 2026-02-25 00:30:22.461863 | controller | skipping: Conditional result was False 2026-02-25 00:30:22.468616 | 2026-02-25 00:30:22.468731 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-25 00:30:22.703656 | controller | ok: "logs" 2026-02-25 00:30:22.704291 | controller | ok: All items complete 2026-02-25 00:30:22.704355 | 2026-02-25 00:30:22.904905 | controller | ok: "artifacts" 2026-02-25 00:30:23.106954 | controller | ok: "docs" 2026-02-25 00:30:23.122044 | 2026-02-25 00:30:23.122162 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-25 00:30:23.388592 | controller | changed: "logs" 2026-02-25 00:30:23.590297 | controller | changed: "artifacts" 2026-02-25 00:30:23.807104 | controller | changed: "docs" 2026-02-25 00:30:23.855192 | 2026-02-25 00:30:23.855336 | PLAY RECAP 2026-02-25 00:30:23.855396 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-25 00:30:23.855436 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-25 00:30:23.855463 | 2026-02-25 00:30:24.025535 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-25 00:30:24.028200 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-25 00:30:24.618086 | 2026-02-25 00:30:24.618228 | PLAY [all] 2026-02-25 00:30:24.643921 | 2026-02-25 00:30:24.644086 | TASK [Install binary dependencies] 2026-02-25 00:30:24.725774 | controller | ok 2026-02-25 00:30:24.748407 | 2026-02-25 00:30:24.748571 | TASK [bindep : Include find tasks] 2026-02-25 00:30:24.799113 | controller | ok 2026-02-25 00:30:24.807502 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-25 00:30:24.814613 | 2026-02-25 00:30:24.814723 | TASK [bindep : Look for bindep.txt] 2026-02-25 00:30:25.406256 | controller | ok 2026-02-25 00:30:25.422039 | 2026-02-25 00:30:25.422220 | TASK [bindep : Define bindep_file fact] 2026-02-25 00:30:25.442274 | controller | skipping: Conditional result was False 2026-02-25 00:30:25.459044 | 2026-02-25 00:30:25.459292 | TASK [bindep : Look for other-requirements.txt] 2026-02-25 00:30:25.701939 | controller | ok 2026-02-25 00:30:25.714383 | 2026-02-25 00:30:25.714566 | TASK [bindep : Define bindep_file fact] 2026-02-25 00:30:25.742563 | controller | skipping: Conditional result was False 2026-02-25 00:30:25.752392 | 2026-02-25 00:30:25.752526 | TASK [bindep : Look for bindep fallback file] 2026-02-25 00:30:25.789322 | controller | skipping: Conditional result was False 2026-02-25 00:30:25.806983 | 2026-02-25 00:30:25.807203 | TASK [bindep : Define bindep_file fact] 2026-02-25 00:30:25.834850 | controller | skipping: Conditional result was False 2026-02-25 00:30:25.844871 | 2026-02-25 00:30:25.845024 | TASK [bindep : Include bindep tasks] 2026-02-25 00:30:25.871497 | controller | skipping: Conditional result was False 2026-02-25 00:30:25.882182 | 2026-02-25 00:30:25.882323 | TASK [bindep : Include install tasks] 2026-02-25 00:30:25.919147 | controller | skipping: Conditional result was False 2026-02-25 00:30:25.929925 | 2026-02-25 00:30:25.930103 | LOOP [bindep : Include package tasks] 2026-02-25 00:30:26.005553 | 2026-02-25 00:30:26.005814 | TASK [Run test-setup role] 2026-02-25 00:30:26.033226 | controller | ok 2026-02-25 00:30:26.056246 | 2026-02-25 00:30:26.056388 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-25 00:30:26.288030 | controller | ok 2026-02-25 00:30:26.301501 | 2026-02-25 00:30:26.301651 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-25 00:30:26.857235 | controller | skipping: Conditional result was False 2026-02-25 00:30:26.884306 | 2026-02-25 00:30:26.884422 | PLAY RECAP 2026-02-25 00:30:26.884477 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-25 00:30:26.884506 | 2026-02-25 00:30:27.023809 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-25 00:30:27.025246 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-25 00:30:27.678568 | 2026-02-25 00:30:27.678765 | PLAY [controller] 2026-02-25 00:30:27.699217 | 2026-02-25 00:30:27.699319 | TASK [Create the /root directory] 2026-02-25 00:30:28.320818 | controller | ok 2026-02-25 00:30:28.334497 | 2026-02-25 00:30:28.334782 | TASK [Install glibc-langpack-en] 2026-02-25 00:30:32.441259 | controller | ok: Nothing to do 2026-02-25 00:30:32.456815 | 2026-02-25 00:30:32.457035 | TASK [Ensure controller directory exists] 2026-02-25 00:30:32.666736 | controller | changed 2026-02-25 00:30:32.683368 | 2026-02-25 00:30:32.683670 | TASK [Install container runtime] 2026-02-25 00:30:32.761807 | controller | ok 2026-02-25 00:30:32.806097 | 2026-02-25 00:30:32.806288 | LOOP [ensure-docker : Gather variables for each operating system] 2026-02-25 00:30:32.845863 | controller | ok: "/var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml" 2026-02-25 00:30:32.862551 | 2026-02-25 00:30:32.862733 | TASK [ensure-docker : Sanity check for distro selection] 2026-02-25 00:30:32.888074 | controller | skipping: Conditional result was False 2026-02-25 00:30:32.894734 | 2026-02-25 00:30:32.894810 | TASK [ensure-docker : Sanity check for distro install] 2026-02-25 00:30:32.920444 | controller | skipping: Conditional result was False 2026-02-25 00:30:32.932315 | 2026-02-25 00:30:32.932874 | TASK [ensure-docker : Sanity check for upstream install] 2026-02-25 00:30:32.960586 | controller | skipping: Conditional result was False 2026-02-25 00:30:32.973456 | 2026-02-25 00:30:32.973796 | TASK [ensure-docker : Sanity check for upstream install mirrors] 2026-02-25 00:30:33.000468 | controller | skipping: Conditional result was False 2026-02-25 00:30:33.008198 | 2026-02-25 00:30:33.008290 | TASK [ensure-docker : Include tasks for docker install] 2026-02-25 00:30:33.042953 | controller | ok 2026-02-25 00:30:33.055849 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml 2026-02-25 00:30:33.068772 | 2026-02-25 00:30:33.068935 | TASK [ensure-docker : Not Implemented] 2026-02-25 00:30:33.095519 | controller | skipping: Conditional result was False 2026-02-25 00:30:33.102803 | 2026-02-25 00:30:33.102880 | TASK [Set up docker mirrors] 2026-02-25 00:30:33.126645 | controller | ok 2026-02-25 00:30:33.149250 | 2026-02-25 00:30:33.149404 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info] 2026-02-25 00:30:33.185548 | controller | skipping: Conditional result was False 2026-02-25 00:30:33.193005 | 2026-02-25 00:30:33.193089 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info] 2026-02-25 00:30:33.228823 | controller | skipping: Conditional result was False 2026-02-25 00:30:33.239506 | 2026-02-25 00:30:33.239638 | TASK [use-docker-mirror : Set docker_mirror fact] 2026-02-25 00:30:33.276827 | controller | skipping: Conditional result was False 2026-02-25 00:30:33.287563 | 2026-02-25 00:30:33.287670 | TASK [use-docker-mirror : Set up docker mirrors] 2026-02-25 00:30:33.323299 | controller | skipping: Conditional result was False 2026-02-25 00:30:33.337741 | 2026-02-25 00:30:33.337828 | TASK [Add all repositories] 2026-02-25 00:30:33.359414 | controller | ok 2026-02-25 00:30:33.384968 | 2026-02-25 00:30:33.385099 | LOOP [ensure-package-repositories : Install repositories] 2026-02-25 00:30:33.417753 | controller | ok: "/var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml" 2026-02-25 00:30:33.418171 | controller | ok: All items complete 2026-02-25 00:30:33.418211 | 2026-02-25 00:30:33.490046 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml 2026-02-25 00:30:33.497173 | 2026-02-25 00:30:33.497287 | TASK [ensure-package-repositories : Create GPG key temp directory] 2026-02-25 00:30:33.826979 | controller | changed 2026-02-25 00:30:33.843758 | 2026-02-25 00:30:33.843952 | LOOP [ensure-package-repositories : Upload GPG keys] 2026-02-25 00:30:34.815883 | controller | changed: 2026-02-25 00:30:34.816173 | controller | { 2026-02-25 00:30:34.816218 | 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" 2026-02-25 00:30:34.816256 | controller | } 2026-02-25 00:30:34.834333 | 2026-02-25 00:30:34.834481 | LOOP [ensure-package-repositories : Import GPG keys] 2026-02-25 00:30:35.417209 | controller | changed: 2026-02-25 00:30:35.417484 | controller | { 2026-02-25 00:30:35.417521 | 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" 2026-02-25 00:30:35.417553 | controller | } 2026-02-25 00:30:35.417592 | controller | changed: All items complete 2026-02-25 00:30:35.417619 | 2026-02-25 00:30:35.441219 | 2026-02-25 00:30:35.441514 | TASK [ensure-package-repositories : Remove GPG temp directory] 2026-02-25 00:30:35.680779 | controller | changed 2026-02-25 00:30:35.697713 | 2026-02-25 00:30:35.697922 | LOOP [ensure-package-repositories : Add repositories] 2026-02-25 00:30:36.054254 | controller | changed: 2026-02-25 00:30:36.054511 | controller | { 2026-02-25 00:30:36.054549 | controller | "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable", 2026-02-25 00:30:36.054582 | controller | "description": "Docker CE Stable - $basearch", 2026-02-25 00:30:36.054606 | controller | "gpgcheck": true, 2026-02-25 00:30:36.054629 | controller | "name": "docker-ce-stable" 2026-02-25 00:30:36.054654 | controller | } 2026-02-25 00:30:36.091212 | 2026-02-25 00:30:36.091439 | TASK [ensure-docker : Install pre-reqs] 2026-02-25 00:30:38.590028 | controller | ok: Nothing to do 2026-02-25 00:30:38.598935 | 2026-02-25 00:30:38.599036 | TASK [ensure-docker : Remove packages] 2026-02-25 00:30:39.947487 | controller | ok: Nothing to do 2026-02-25 00:30:39.968531 | 2026-02-25 00:30:39.968725 | TASK [ensure-docker : Install upstream docker using package] 2026-02-25 00:31:26.866815 | controller | changed 2026-02-25 00:31:26.873457 | 2026-02-25 00:31:26.873547 | TASK [ensure-docker : Setup docker] 2026-02-25 00:31:26.907587 | controller | ok 2026-02-25 00:31:26.923290 | controller | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml 2026-02-25 00:31:26.935561 | 2026-02-25 00:31:26.935632 | TASK [ensure-docker : Ensure "docker" group exists] 2026-02-25 00:31:27.398580 | controller | ok 2026-02-25 00:31:27.406031 | 2026-02-25 00:31:27.406105 | TASK [ensure-docker : Add user to docker group] 2026-02-25 00:31:28.057326 | controller | changed 2026-02-25 00:31:28.070383 | 2026-02-25 00:31:28.070541 | TASK [Update docker daemon proxy configuration] 2026-02-25 00:31:28.097254 | controller | skipping: Conditional result was False 2026-02-25 00:31:28.108345 | 2026-02-25 00:31:28.108596 | TASK [Lower default MTU] 2026-02-25 00:31:28.136845 | controller | skipping: Conditional result was False 2026-02-25 00:31:28.145650 | 2026-02-25 00:31:28.145776 | TASK [ensure-docker : Get the status of the docket.socket unit] 2026-02-25 00:31:28.566577 | controller | inactive 2026-02-25 00:31:28.757439 | controller | ok: Runtime: 0:00:00.016169 2026-02-25 00:31:28.774111 | 2026-02-25 00:31:28.774432 | TASK [ensure-docker : Get the status of the docket unit] 2026-02-25 00:31:29.020898 | controller | inactive 2026-02-25 00:31:29.333135 | controller | ok: Runtime: 0:00:00.007649 2026-02-25 00:31:29.343203 | 2026-02-25 00:31:29.343311 | TASK [ensure-docker : Restart docker] 2026-02-25 00:31:29.393580 | Trigger a Docker restart 2026-02-25 00:31:29.399391 | 2026-02-25 00:31:29.399463 | TASK [ensure-docker : Reset ssh connection to pick up docker group] 2026-02-25 00:31:29.430216 | 2026-02-25 00:31:29.430398 | TASK [ensure-docker : Install docker-compose] 2026-02-25 00:31:29.457832 | controller | skipping: Conditional result was False 2026-02-25 00:31:29.465937 | 2026-02-25 00:31:29.466142 | TASK [ensure-docker : Flush handlers before role exit] 2026-02-25 00:31:29.479284 | 2026-02-25 00:31:29.479455 | TASK [ensure-docker : Stop docker.socket to avoid any conflict] 2026-02-25 00:31:30.728875 | controller | changed 2026-02-25 00:31:30.746247 | 2026-02-25 00:31:30.746481 | TASK [ensure-docker : Assure docker service is running] 2026-02-25 00:31:33.392819 | controller | changed 2026-02-25 00:31:33.402030 | 2026-02-25 00:31:33.402118 | TASK [ensure-docker : Assure docker.socket service is running] 2026-02-25 00:31:34.453015 | controller | ok 2026-02-25 00:31:34.475286 | 2026-02-25 00:31:34.475463 | TASK [ensure-docker : Correct group ownership on docker sock] 2026-02-25 00:31:35.199188 | controller | ok 2026-02-25 00:31:35.215830 | 2026-02-25 00:31:35.216120 | TASK [ensure-docker : Validate ability to talk with docker] 2026-02-25 00:31:35.777550 | controller | CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 2026-02-25 00:31:36.270244 | controller | ok: Runtime: 0:00:00.053947 2026-02-25 00:31:36.280006 | 2026-02-25 00:31:36.280137 | TASK [ensure-docker : Get version details] 2026-02-25 00:31:36.840172 | controller | Client: Docker Engine - Community 2026-02-25 00:31:36.840213 | controller | Version: 24.0.7 2026-02-25 00:31:36.840254 | controller | API version: 1.43 2026-02-25 00:31:36.840261 | controller | Go version: go1.20.10 2026-02-25 00:31:36.840272 | controller | Git commit: afdd53b 2026-02-25 00:31:36.840278 | controller | Built: Thu Oct 26 09:09:39 2023 2026-02-25 00:31:36.840283 | controller | OS/Arch: linux/amd64 2026-02-25 00:31:36.840288 | controller | Context: default 2026-02-25 00:31:36.840295 | controller | 2026-02-25 00:31:36.840300 | controller | Server: Docker Engine - Community 2026-02-25 00:31:36.840304 | controller | Engine: 2026-02-25 00:31:36.840311 | controller | Version: 24.0.7 2026-02-25 00:31:36.840350 | controller | API version: 1.43 (minimum version 1.12) 2026-02-25 00:31:36.840357 | controller | Go version: go1.20.10 2026-02-25 00:31:36.840361 | controller | Git commit: 311b9ff 2026-02-25 00:31:36.840365 | controller | Built: Thu Oct 26 09:08:11 2023 2026-02-25 00:31:36.840369 | controller | OS/Arch: linux/amd64 2026-02-25 00:31:36.840374 | controller | Experimental: false 2026-02-25 00:31:36.840378 | controller | containerd: 2026-02-25 00:31:36.840382 | controller | Version: 1.6.25 2026-02-25 00:31:36.840386 | controller | GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f 2026-02-25 00:31:36.840390 | controller | runc: 2026-02-25 00:31:36.840394 | controller | Version: 1.1.10 2026-02-25 00:31:36.840399 | controller | GitCommit: v1.1.10-0-g18a0cb0 2026-02-25 00:31:36.840404 | controller | docker-init: 2026-02-25 00:31:36.840410 | controller | Version: 0.19.0 2026-02-25 00:31:36.842277 | controller | GitCommit: de40ad0 2026-02-25 00:31:37.328900 | controller | ok: Runtime: 0:00:00.069486 2026-02-25 00:31:37.344415 | 2026-02-25 00:31:37.344608 | TASK [ensure-docker : Dump installed docker details] 2026-02-25 00:31:37.387504 | {'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': '2026-02-25 00:31:36.773037', 'end': '2026-02-25 00:31:36.842523', 'delta': '0:00:00.069486', 'msg': '', 'zuul_log_id': 'fa163e3b-3c83-34c6-1774-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} 2026-02-25 00:31:37.403467 | 2026-02-25 00:31:37.403643 | TASK [Use buildset registry] 2026-02-25 00:31:37.422349 | controller | skipping: Conditional result was False 2026-02-25 00:31:37.440889 | 2026-02-25 00:31:37.441033 | TASK [Ensure python3.8 is present] 2026-02-25 00:31:37.466802 | controller | skipping: Conditional result was False 2026-02-25 00:31:37.476366 | 2026-02-25 00:31:37.476483 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-25 00:31:37.501119 | controller | ok 2026-02-25 00:31:37.529588 | 2026-02-25 00:31:37.529769 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-25 00:31:40.454480 | controller | ok: Nothing to do 2026-02-25 00:31:40.460635 | 2026-02-25 00:31:40.460817 | TASK [our-ensure-python : Also install python3-devel] 2026-02-25 00:31:50.839325 | controller | changed 2026-02-25 00:31:50.866359 | 2026-02-25 00:31:50.866555 | TASK [Run ensure-virtualenv role] 2026-02-25 00:31:50.895990 | controller | ok 2026-02-25 00:31:50.919196 | 2026-02-25 00:31:50.919310 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-25 00:31:51.136025 | controller | /usr/bin/virtualenv 2026-02-25 00:31:51.455856 | controller | ok: Runtime: 0:00:00.005051 2026-02-25 00:31:51.462431 | 2026-02-25 00:31:51.462509 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-25 00:31:51.496373 | controller | skipping: Conditional result was False 2026-02-25 00:31:51.496723 | controller | changed: All items complete 2026-02-25 00:31:51.496755 | 2026-02-25 00:31:51.510155 | 2026-02-25 00:31:51.510274 | TASK [Find the full path of the Python interpreter] 2026-02-25 00:31:51.723419 | controller | /usr/bin/python3.9 2026-02-25 00:31:52.043136 | controller | ok 2026-02-25 00:31:52.051425 | 2026-02-25 00:31:52.051526 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-25 00:31:53.511460 | controller | created virtual environment CPython3.9.18.final.0-64 in 832ms 2026-02-25 00:31:53.548871 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-25 00:31:53.548909 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2026-02-25 00:31:53.548919 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-25 00:31:53.548932 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-25 00:31:53.602081 | controller | changed 2026-02-25 00:31:53.607756 | 2026-02-25 00:31:53.607833 | TASK [Set selinux package] 2026-02-25 00:31:53.639173 | controller | ok 2026-02-25 00:31:53.644612 | 2026-02-25 00:31:53.644724 | TASK [Set selinux package (Fedora)] 2026-02-25 00:31:53.676303 | controller | ok 2026-02-25 00:31:53.682503 | 2026-02-25 00:31:53.682577 | TASK [Install selinux into virtualenv] 2026-02-25 00:31:56.592600 | controller | Collecting selinux-please-lie-to-me 2026-02-25 00:31:56.685758 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-25 00:31:57.842093 | controller | Collecting setuptools<50.0.0 2026-02-25 00:31:57.856766 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-25 00:31:57.915087 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 14.9 MB/s eta 0:00:00 2026-02-25 00:31:58.150828 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-25 00:31:58.153617 | controller | Attempting uninstall: setuptools 2026-02-25 00:31:58.156425 | controller | Found existing installation: setuptools 62.6.0 2026-02-25 00:31:58.340405 | controller | Uninstalling setuptools-62.6.0: 2026-02-25 00:31:58.367902 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-25 00:31:59.309862 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-25 00:31:59.619046 | controller | 2026-02-25 00:31:59.837352 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-25 00:31:59.837390 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2026-02-25 00:32:00.231461 | controller | ok: Runtime: 0:00:05.785035 2026-02-25 00:32:00.245488 | 2026-02-25 00:32:00.245644 | TASK [Install pytest-forked into virtualenv] 2026-02-25 00:32:01.210122 | controller | Collecting pytest-forked 2026-02-25 00:32:01.262642 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-25 00:32:01.353363 | controller | Collecting py 2026-02-25 00:32:01.358988 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-25 00:32:01.380660 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.0 MB/s eta 0:00:00 2026-02-25 00:32:01.526180 | controller | Collecting pytest>=3.10 2026-02-25 00:32:01.531389 | controller | Downloading pytest-8.4.2-py3-none-any.whl (365 kB) 2026-02-25 00:32:01.554629 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 19.0 MB/s eta 0:00:00 2026-02-25 00:32:01.623338 | controller | Collecting tomli>=1 2026-02-25 00:32:01.627106 | controller | Downloading tomli-2.4.0-py3-none-any.whl (14 kB) 2026-02-25 00:32:01.684812 | controller | Collecting pygments>=2.7.2 2026-02-25 00:32:01.688659 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-25 00:32:01.726797 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 34.5 MB/s eta 0:00:00 2026-02-25 00:32:01.761979 | controller | Collecting pluggy<2,>=1.5 2026-02-25 00:32:01.765585 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-25 00:32:01.796478 | controller | Collecting iniconfig>=1 2026-02-25 00:32:01.800659 | controller | Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB) 2026-02-25 00:32:01.837022 | controller | Collecting exceptiongroup>=1 2026-02-25 00:32:01.840878 | controller | Downloading exceptiongroup-1.3.1-py3-none-any.whl (16 kB) 2026-02-25 00:32:01.890257 | controller | Collecting packaging>=20 2026-02-25 00:32:01.894179 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-25 00:32:01.902705 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 11.0 MB/s eta 0:00:00 2026-02-25 00:32:01.956562 | controller | Collecting typing-extensions>=4.6.0 2026-02-25 00:32:01.960114 | controller | Downloading typing_extensions-4.15.0-py3-none-any.whl (44 kB) 2026-02-25 00:32:01.968001 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 44.6/44.6 kB 7.8 MB/s eta 0:00:00 2026-02-25 00:32:02.035058 | controller | Installing collected packages: typing-extensions, tomli, pygments, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked 2026-02-25 00:32:04.089341 | controller | Successfully installed exceptiongroup-1.3.1 iniconfig-2.1.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0 tomli-2.4.0 typing-extensions-4.15.0 2026-02-25 00:32:04.093796 | controller | 2026-02-25 00:32:04.162380 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-25 00:32:04.162422 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2026-02-25 00:32:04.307981 | controller | ok: Runtime: 0:00:03.581902 2026-02-25 00:32:04.317059 | 2026-02-25 00:32:04.317165 | TASK [Update pip] 2026-02-25 00:32:05.951214 | controller | Requirement already satisfied: pip in ./venv/lib/python3.9/site-packages (22.2.2) 2026-02-25 00:32:06.364151 | controller | Collecting pip 2026-02-25 00:32:06.460251 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-25 00:32:06.583339 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 15.0 MB/s eta 0:00:00 2026-02-25 00:32:06.776862 | controller | Installing collected packages: pip 2026-02-25 00:32:06.781087 | controller | Attempting uninstall: pip 2026-02-25 00:32:06.788787 | controller | Found existing installation: pip 22.2.2 2026-02-25 00:32:07.400061 | controller | Uninstalling pip-22.2.2: 2026-02-25 00:32:07.458179 | controller | Successfully uninstalled pip-22.2.2 2026-02-25 00:32:10.043356 | controller | Successfully installed pip-26.0.1 2026-02-25 00:32:10.360948 | controller | ok: Runtime: 0:00:05.544932 2026-02-25 00:32:10.367494 | 2026-02-25 00:32:10.367570 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-25 00:32:11.051806 | controller | changed 2026-02-25 00:32:11.067051 | 2026-02-25 00:32:11.067262 | TASK [Install ansible into virtualenv] 2026-02-25 00:32:12.722664 | controller | Processing ./src/github.com/ansible/ansible 2026-02-25 00:32:12.725668 | controller | Installing build dependencies: started 2026-02-25 00:37:22.117459 | controller | ok: Runtime: 0:00:06.240700 2026-02-25 00:37:22.132464 | 2026-02-25 00:37:22.132639 | TASK [Setup download-artifact-fork role] 2026-02-25 00:37:22.178184 | controller | ok 2026-02-25 00:37:22.217893 | 2026-02-25 00:37:22.218051 | TASK [download-artifact-fork : Parse inventory response] 2026-02-25 00:37:22.285088 | controller | ok 2026-02-25 00:37:22.296303 | 2026-02-25 00:37:22.296411 | TASK [download-artifact-fork : Fetch info from Zuul API] 2026-02-25 00:37:22.333862 | controller | skipping: Conditional result was False 2026-02-25 00:37:22.344109 | 2026-02-25 00:37:22.344216 | TASK [download-artifact-fork : Parse build response] 2026-02-25 00:37:22.371732 | controller | skipping: Conditional result was False 2026-02-25 00:37:22.382218 | 2026-02-25 00:37:22.382348 | TASK [download-artifact-fork : Ensure artifacts directory exists] 2026-02-25 00:37:22.617245 | controller | changed 2026-02-25 00:37:22.633740 | 2026-02-25 00:37:22.633980 | LOOP [download-artifact-fork : Download archive by type] 2026-02-25 00:37:22.668366 | controller | skipping: Conditional result was False 2026-02-25 00:37:22.668800 | 2026-02-25 00:37:23.608058 | controller | changed: OK (20205 bytes) 2026-02-25 00:37:23.623072 | 2026-02-25 00:37:23.623253 | TASK [deploy-artifacts : define __collections] 2026-02-25 00:37:23.657243 | controller | ok 2026-02-25 00:37:23.663288 | 2026-02-25 00:37:23.663357 | LOOP [deploy-artifacts : Create list of collections] 2026-02-25 00:37:23.700611 | controller | skipping: Conditional result was False 2026-02-25 00:37:23.724190 | controller | ok: 2026-02-25 00:37:23.724405 | controller | { 2026-02-25 00:37:23.724459 | controller | "branch": "main", 2026-02-25 00:37:23.724499 | controller | "job": "build-ansible-collection", 2026-02-25 00:37:23.724538 | controller | "metadata": { 2026-02-25 00:37:23.724574 | controller | "type": "ansible_collection", 2026-02-25 00:37:23.724612 | controller | "version": "5.0.0" 2026-02-25 00:37:23.724648 | controller | }, 2026-02-25 00:37:23.724745 | controller | "name": "ansible.network", 2026-02-25 00:37:23.724804 | controller | "project": "ansible-collections/ansible.network", 2026-02-25 00:37:23.724844 | controller | "url": "https://14922f53e00d5b51a121-c18b1b7a08d97bee717b6dd5e7f6c60f.ssl.cf5.rackcdn.com/ansible/32b29d7fd055494e98c23fcead72c086/artifacts/ansible-network-5.0.0.tar.gz" 2026-02-25 00:37:23.724894 | controller | } 2026-02-25 00:37:23.742520 | 2026-02-25 00:37:23.742635 | TASK [deploy-artifacts : Install require-project collection using ansible-galaxy] 2026-02-25 00:37:24.368228 | controller | Starting galaxy collection install process 2026-02-25 00:37:24.368322 | controller | Process install dependency map 2026-02-25 00:37:26.080555 | controller | [WARNING]: Skipping Galaxy server https://galaxy.ansible.com/api/. Got an 2026-02-25 00:37:26.080953 | controller | unexpected error when getting available versions of collection 2026-02-25 00:37:26.080997 | controller | ansible.netcommon: '/api/v3/plugin/ansible/content/published/collections/index/ 2026-02-25 00:37:26.081010 | controller | ansible/netcommon/versions/' 2026-02-25 00:37:26.081026 | controller | ERROR! Unexpected Exception, this is probably a bug: '/api/v3/plugin/ansible/content/published/collections/index/ansible/netcommon/versions/' 2026-02-25 00:37:26.081160 | controller | to see the full traceback, use -vvv 2026-02-25 00:37:26.285428 | controller | ERROR 2026-02-25 00:37:26.285874 | controller | { 2026-02-25 00:37:26.285988 | controller | "delta": "0:00:02.148668", 2026-02-25 00:37:26.286060 | controller | "end": "2026-02-25 00:37:26.119605", 2026-02-25 00:37:26.286114 | controller | "msg": "non-zero return code", 2026-02-25 00:37:26.286155 | controller | "rc": 250, 2026-02-25 00:37:26.286208 | controller | "start": "2026-02-25 00:37:23.970937" 2026-02-25 00:37:26.286267 | controller | } failure 2026-02-25 00:37:26.290486 | 2026-02-25 00:37:26.290601 | PLAY RECAP 2026-02-25 00:37:26.290729 | controller | ok: 44 changed: 24 unreachable: 0 failed: 1 skipped: 17 rescued: 0 ignored: 0 2026-02-25 00:37:26.290793 | 2026-02-25 00:37:26.491435 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-25 00:37:26.493652 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-25 00:37:27.119435 | 2026-02-25 00:37:27.119657 | PLAY [all] 2026-02-25 00:37:27.144621 | 2026-02-25 00:37:27.144763 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-25 00:37:27.583746 | controller | changed: non-zero return code 2026-02-25 00:37:27.597787 | 2026-02-25 00:37:27.597947 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-25 00:37:27.612844 | controller | skipping: Conditional result was False 2026-02-25 00:37:27.622489 | 2026-02-25 00:37:27.622593 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-25 00:37:27.647438 | 2026-02-25 00:37:27.647609 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-25 00:37:27.671736 | 2026-02-25 00:37:27.671927 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-25 00:37:27.686653 | controller | skipping: Conditional result was False 2026-02-25 00:37:27.697351 | 2026-02-25 00:37:27.697444 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-25 00:37:27.722588 | 2026-02-25 00:37:27.722841 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-25 00:37:27.750506 | controller | skipping: Conditional result was False 2026-02-25 00:37:27.759951 | 2026-02-25 00:37:27.760070 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-25 00:37:27.774898 | controller | skipping: Conditional result was False 2026-02-25 00:37:27.784944 | 2026-02-25 00:37:27.785115 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-25 00:37:27.800701 | controller | skipping: Conditional result was False 2026-02-25 00:37:27.840462 | 2026-02-25 00:37:27.840582 | PLAY RECAP 2026-02-25 00:37:27.840631 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-25 00:37:27.840654 | 2026-02-25 00:37:27.953564 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-25 00:37:27.954487 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-25 00:37:28.573985 | 2026-02-25 00:37:28.574456 | PLAY [all:!appliance*] 2026-02-25 00:37:28.597319 | 2026-02-25 00:37:28.597508 | TASK [unregister the node] 2026-02-25 00:37:29.129857 | controller | skipping: Conditional result was False 2026-02-25 00:37:29.141507 | 2026-02-25 00:37:29.141732 | TASK [include_role : fetch-output] 2026-02-25 00:37:29.181763 | controller | ok 2026-02-25 00:37:29.221883 | 2026-02-25 00:37:29.222097 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-25 00:37:29.281087 | controller | skipping: Conditional result was False 2026-02-25 00:37:29.292248 | 2026-02-25 00:37:29.292415 | TASK [fetch-output : Set log path for single node] 2026-02-25 00:37:29.337467 | controller | ok 2026-02-25 00:37:29.347064 | 2026-02-25 00:37:29.347176 | LOOP [fetch-output : Ensure local output dirs] 2026-02-25 00:37:29.759869 | controller -> localhost | ok: "/var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/logs" 2026-02-25 00:37:30.019184 | controller -> localhost | changed: "/var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/artifacts" 2026-02-25 00:37:30.285120 | controller -> localhost | changed: "/var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/work/docs" 2026-02-25 00:37:30.301029 | 2026-02-25 00:37:30.301245 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-25 00:37:31.061434 | controller | changed: 2026-02-25 00:37:31.061730 | controller | .d..t...... ./ 2026-02-25 00:37:31.061774 | controller | cd+++++++++ controller/ 2026-02-25 00:37:31.061822 | controller | changed: All items complete 2026-02-25 00:37:31.061850 | 2026-02-25 00:37:31.659314 | controller | changed: .d..t...... ./ 2026-02-25 00:37:32.226610 | controller | changed: .d..t...... ./ 2026-02-25 00:37:32.250002 | 2026-02-25 00:37:32.250152 | TASK [include_role : fetch-output-openshift] 2026-02-25 00:37:32.274839 | controller | skipping: Conditional result was False 2026-02-25 00:37:32.282185 | 2026-02-25 00:37:32.282310 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-25 00:37:32.319824 | controller | skipping: Conditional result was False 2026-02-25 00:37:32.330491 | controller | skipping: Conditional result was False 2026-02-25 00:37:32.364023 | 2026-02-25 00:37:32.364176 | PLAY [localhost] 2026-02-25 00:37:32.377200 | 2026-02-25 00:37:32.377351 | TASK [Run Zuul manifest role] 2026-02-25 00:37:32.398475 | localhost | ok 2026-02-25 00:37:32.412351 | 2026-02-25 00:37:32.412518 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-25 00:37:32.861335 | localhost | changed 2026-02-25 00:37:32.866367 | 2026-02-25 00:37:32.866435 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-25 00:37:32.919839 | localhost | ok 2026-02-25 00:37:32.927970 | 2026-02-25 00:37:32.928040 | TASK [Set zuul-log-path fact] 2026-02-25 00:37:32.948469 | localhost | ok 2026-02-25 00:37:32.963412 | 2026-02-25 00:37:32.963497 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-25 00:37:33.002844 | localhost | ok 2026-02-25 00:37:33.011025 | 2026-02-25 00:37:33.011120 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-02-25 00:37:33.047624 | localhost | ok: 2026-02-25 00:37:33.047914 | localhost | { 2026-02-25 00:37:33.047951 | localhost | "auth": { 2026-02-25 00:37:33.047983 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-02-25 00:37:33.048007 | localhost | "username": "9LF91O0RK7JU" 2026-02-25 00:37:33.048030 | localhost | }, 2026-02-25 00:37:33.048052 | localhost | "profile": "rackspace", 2026-02-25 00:37:33.048073 | localhost | "project_name": "1251317", 2026-02-25 00:37:33.048094 | localhost | "region_name": "DFW" 2026-02-25 00:37:33.048115 | localhost | } 2026-02-25 00:37:33.048151 | 2026-02-25 00:37:33.063929 | 2026-02-25 00:37:33.064068 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-02-25 00:37:33.086628 | localhost | Output suppressed because no_log was given 2026-02-25 00:37:33.105287 | 2026-02-25 00:37:33.105419 | TASK [upload-logs-failover : Initialize control vars] 2026-02-25 00:37:33.146478 | localhost | ok 2026-02-25 00:37:33.184174 | 2026-02-25 00:37:33.184309 | LOOP [upload-logs-failover : Perform log upload] 2026-02-25 00:37:33.208647 | localhost | Output suppressed because no_log was given 2026-02-25 00:37:33.215426 | localhost | included: /var/lib/zuul/builds/9f418183a8c1429c8d64c098a755ef38/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-02-25 00:37:33.222515 | 2026-02-25 00:37:33.222615 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-02-25 00:37:33.302726 | localhost | Output suppressed because no_log was given 2026-02-25 00:37:33.310970 | 2026-02-25 00:37:33.311092 | TASK [Upload logs to swift] 2026-02-25 00:37:33.332662 | localhost | ok 2026-02-25 00:37:33.364694 | 2026-02-25 00:37:33.364814 | TASK [Set zuul-log-path fact] 2026-02-25 00:37:33.389352 | localhost | skipping: Conditional result was False 2026-02-25 00:37:33.395068 | 2026-02-25 00:37:33.395142 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-25 00:37:33.826492 | localhost -> localhost | ok: Runtime: 0:00:00.008422 2026-02-25 00:37:33.832419 | 2026-02-25 00:37:33.832487 | TASK [upload-logs-swift : Upload logs to swift]