2026-01-10 00:28:10.653805 | Job console starting... 2026-01-10 00:28:10.665880 | Updating repositories 2026-01-10 00:28:10.787013 | Preparing job workspace 2026-01-10 00:28:14.952047 | Running Ansible setup... 2026-01-10 00:28:19.942248 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-10 00:28:20.603182 | 2026-01-10 00:28:20.603314 | PLAY [localhost] 2026-01-10 00:28:20.612024 | 2026-01-10 00:28:20.612106 | TASK [Gathering Facts] 2026-01-10 00:28:21.658972 | localhost | ok 2026-01-10 00:28:21.682498 | 2026-01-10 00:28:21.682736 | TASK [Setup log path fact] 2026-01-10 00:28:21.700385 | localhost | ok 2026-01-10 00:28:21.713321 | 2026-01-10 00:28:21.713414 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-10 00:28:21.751311 | localhost | ok 2026-01-10 00:28:21.759369 | 2026-01-10 00:28:21.759446 | TASK [emit-job-header : Print job information] 2026-01-10 00:28:21.814120 | # Job Information 2026-01-10 00:28:21.814382 | Ansible Version: 2.15.12 2026-01-10 00:28:21.814450 | Job: ansible-test-sanity-docker-devel 2026-01-10 00:28:21.814495 | Pipeline: periodic 2026-01-10 00:28:21.814535 | Executor: ze02.softwarefactory-project.io 2026-01-10 00:28:21.814612 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-10 00:28:21.814662 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/818/ansible/818d0f76aa504ce1aba0f97b3b39738a/ 2026-01-10 00:28:21.814746 | Event ID: 763e0e28d21845a4b1dbea19b60ebb5e 2026-01-10 00:28:21.823796 | 2026-01-10 00:28:21.823936 | LOOP [emit-job-header : Print node information] 2026-01-10 00:28:21.939102 | localhost | ok: 2026-01-10 00:28:21.939385 | localhost | # Node Information 2026-01-10 00:28:21.939429 | localhost | Inventory Hostname: controller 2026-01-10 00:28:21.939456 | localhost | Hostname: np0005580302 2026-01-10 00:28:21.939481 | localhost | Username: zuul 2026-01-10 00:28:21.939511 | localhost | Distro: Fedora 37 2026-01-10 00:28:21.939537 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-01-10 00:28:21.939561 | localhost | Region: ca-ymq-1 2026-01-10 00:28:21.939585 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-10 00:28:21.939608 | localhost | Product Name: OpenStack Nova 2026-01-10 00:28:21.939631 | localhost | Interface IP: 162.253.55.12 2026-01-10 00:28:21.953246 | 2026-01-10 00:28:21.953412 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-10 00:28:22.357017 | localhost -> localhost | changed 2026-01-10 00:28:22.369013 | 2026-01-10 00:28:22.369499 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-10 00:28:23.296170 | localhost -> localhost | changed 2026-01-10 00:28:23.338578 | 2026-01-10 00:28:23.338715 | PLAY [all:!appliance*] 2026-01-10 00:28:23.364776 | 2026-01-10 00:28:23.364931 | TASK [include_role : start-zuul-console] 2026-01-10 00:28:23.389487 | controller | ok 2026-01-10 00:28:23.412946 | 2026-01-10 00:28:23.413091 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-10 00:28:23.810223 | controller | ok 2026-01-10 00:28:23.823643 | 2026-01-10 00:28:23.823795 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-10 00:28:24.904843 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-10 00:28:24.924340 | 2026-01-10 00:28:24.924485 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-10 00:28:25.468484 | controller | skipping: Conditional result was False 2026-01-10 00:28:25.482658 | 2026-01-10 00:28:25.482842 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-10 00:28:25.531026 | controller | skipping: Conditional result was False 2026-01-10 00:28:25.547357 | 2026-01-10 00:28:25.547513 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-10 00:28:25.575105 | controller | skipping: Conditional result was False 2026-01-10 00:28:25.585700 | 2026-01-10 00:28:25.585804 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-10 00:28:25.611833 | controller | skipping: Conditional result was False 2026-01-10 00:28:25.621435 | 2026-01-10 00:28:25.621545 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-10 00:28:25.646882 | controller | skipping: Conditional result was False 2026-01-10 00:28:25.656872 | 2026-01-10 00:28:25.656988 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-10 00:28:25.683164 | controller | skipping: Conditional result was False 2026-01-10 00:28:25.695234 | 2026-01-10 00:28:25.695337 | TASK [Disable Fedora Modular] 2026-01-10 00:28:26.043073 | controller | changed 2026-01-10 00:28:26.048934 | 2026-01-10 00:28:26.049013 | TASK [Enable EPEL] 2026-01-10 00:28:26.074074 | controller | skipping: Conditional result was False 2026-01-10 00:28:26.080431 | 2026-01-10 00:28:26.080534 | TASK [Register the RHEL node] 2026-01-10 00:28:26.632272 | 2026-01-10 00:28:26.632555 | TASK [Show the subscription-manager status] 2026-01-10 00:28:27.218439 | controller | skipping: Conditional result was False 2026-01-10 00:28:27.248779 | 2026-01-10 00:28:27.248988 | TASK [Enable EPEL on RHEL] 2026-01-10 00:28:27.807288 | controller | skipping: Conditional result was False 2026-01-10 00:28:27.823825 | 2026-01-10 00:28:27.824018 | TASK [Install git and tox] 2026-01-10 00:29:49.874289 | controller | changed 2026-01-10 00:29:49.888521 | 2026-01-10 00:29:49.888653 | TASK [include_role : prepare-workspace] 2026-01-10 00:29:49.927457 | controller | ok 2026-01-10 00:29:49.965269 | 2026-01-10 00:29:49.965384 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-10 00:29:50.241216 | controller | ok 2026-01-10 00:29:50.247490 | 2026-01-10 00:29:50.247552 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-10 00:30:02.361883 | controller | Output suppressed because no_log was given 2026-01-10 00:30:02.384727 | 2026-01-10 00:30:02.384896 | TASK [include_role : prepare-workspace-openshift] 2026-01-10 00:30:02.404883 | controller | skipping: Conditional result was False 2026-01-10 00:30:02.477383 | 2026-01-10 00:30:02.477492 | PLAY [all:!appliance] 2026-01-10 00:30:02.497134 | 2026-01-10 00:30:02.497256 | TASK [Run add-build-sshkey role (RSA)] 2026-01-10 00:30:02.527814 | controller | ok 2026-01-10 00:30:02.544349 | 2026-01-10 00:30:02.544480 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-10 00:30:02.834854 | controller -> localhost | ok 2026-01-10 00:30:02.845070 | 2026-01-10 00:30:02.845244 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-10 00:30:02.868233 | controller | ok 2026-01-10 00:30:02.884588 | controller | included: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-10 00:30:02.891008 | 2026-01-10 00:30:02.891102 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-10 00:30:03.293396 | controller -> localhost | Generating public/private rsa key pair. 2026-01-10 00:30:03.293746 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/818d0f76aa504ce1aba0f97b3b39738a_id_rsa. 2026-01-10 00:30:03.293814 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/818d0f76aa504ce1aba0f97b3b39738a_id_rsa.pub. 2026-01-10 00:30:03.293860 | controller -> localhost | The key fingerprint is: 2026-01-10 00:30:03.293903 | controller -> localhost | SHA256:kQW0RH6Ak96WqYcQFyZPnI0q1J64oHC5YFlH2ogOJjc zuul-build-sshkey 2026-01-10 00:30:03.293944 | controller -> localhost | The key's randomart image is: 2026-01-10 00:30:03.293985 | controller -> localhost | +---[RSA 2048]----+ 2026-01-10 00:30:03.294025 | controller -> localhost | | .oo+X*.. | 2026-01-10 00:30:03.294066 | controller -> localhost | | o.**Oo.= | 2026-01-10 00:30:03.294106 | controller -> localhost | |o+E*.B.o=o. | 2026-01-10 00:30:03.294145 | controller -> localhost | |O+=.= . =o | 2026-01-10 00:30:03.294184 | controller -> localhost | |+= + . +S | 2026-01-10 00:30:03.294242 | controller -> localhost | |. o o . | 2026-01-10 00:30:03.294302 | controller -> localhost | | . | 2026-01-10 00:30:03.294359 | controller -> localhost | | | 2026-01-10 00:30:03.294400 | controller -> localhost | | | 2026-01-10 00:30:03.294445 | controller -> localhost | +----[SHA256]-----+ 2026-01-10 00:30:03.294534 | controller -> localhost | ok: Runtime: 0:00:00.032647 2026-01-10 00:30:03.310460 | 2026-01-10 00:30:03.310640 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-10 00:30:03.340185 | controller | ok 2026-01-10 00:30:03.360262 | controller | included: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-10 00:30:03.376993 | 2026-01-10 00:30:03.377142 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-10 00:30:03.394167 | controller | skipping: Conditional result was False 2026-01-10 00:30:03.404564 | 2026-01-10 00:30:03.404695 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-10 00:30:03.883654 | controller | changed 2026-01-10 00:30:03.889651 | 2026-01-10 00:30:03.889739 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-10 00:30:04.119816 | controller | ok 2026-01-10 00:30:04.137322 | 2026-01-10 00:30:04.137485 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-10 00:30:04.791172 | controller | changed 2026-01-10 00:30:04.804801 | 2026-01-10 00:30:04.804935 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-10 00:30:05.457251 | controller | changed 2026-01-10 00:30:05.473981 | 2026-01-10 00:30:05.474168 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-10 00:30:05.492735 | controller | skipping: Conditional result was False 2026-01-10 00:30:05.510573 | 2026-01-10 00:30:05.510828 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-10 00:30:06.000861 | controller -> localhost | changed 2026-01-10 00:30:06.016748 | 2026-01-10 00:30:06.016955 | TASK [add-build-sshkey : Add back temp key] 2026-01-10 00:30:06.362089 | controller -> localhost | Identity added: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/818d0f76aa504ce1aba0f97b3b39738a_id_rsa (zuul-build-sshkey) 2026-01-10 00:30:06.362555 | controller -> localhost | ok: Runtime: 0:00:00.013872 2026-01-10 00:30:06.376801 | 2026-01-10 00:30:06.376935 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-10 00:30:06.734881 | controller | ok 2026-01-10 00:30:06.747495 | 2026-01-10 00:30:06.747628 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-10 00:30:06.785950 | controller | skipping: Conditional result was False 2026-01-10 00:30:06.814004 | 2026-01-10 00:30:06.814147 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-10 00:30:06.854499 | controller | ok 2026-01-10 00:30:06.887847 | 2026-01-10 00:30:06.887976 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-10 00:30:07.179501 | controller -> localhost | ok 2026-01-10 00:30:07.193579 | 2026-01-10 00:30:07.193754 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-10 00:30:07.232363 | controller | ok 2026-01-10 00:30:07.257392 | controller | included: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-10 00:30:07.266410 | 2026-01-10 00:30:07.266494 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-10 00:30:07.619180 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-10 00:30:07.619640 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/818d0f76aa504ce1aba0f97b3b39738a_id_ecdsa. 2026-01-10 00:30:07.619751 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/818d0f76aa504ce1aba0f97b3b39738a_id_ecdsa.pub. 2026-01-10 00:30:07.619817 | controller -> localhost | The key fingerprint is: 2026-01-10 00:30:07.619861 | controller -> localhost | SHA256:KTpfrJRi2yOvMfd35eRsGViywaIOPTo8YucsR+Nt12Y zuul-build-sshkey 2026-01-10 00:30:07.619913 | controller -> localhost | The key's randomart image is: 2026-01-10 00:30:07.619967 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-10 00:30:07.620015 | controller -> localhost | | | 2026-01-10 00:30:07.620061 | controller -> localhost | | | 2026-01-10 00:30:07.620105 | controller -> localhost | | . | 2026-01-10 00:30:07.620157 | controller -> localhost | | .. + . | 2026-01-10 00:30:07.620199 | controller -> localhost | | ..S. . * | 2026-01-10 00:30:07.620237 | controller -> localhost | | .+++ o + | 2026-01-10 00:30:07.620287 | controller -> localhost | | B++*o. . * o | 2026-01-10 00:30:07.620342 | controller -> localhost | | .=%X++ o E * | 2026-01-10 00:30:07.620393 | controller -> localhost | | .oXB=.o + . | 2026-01-10 00:30:07.620446 | controller -> localhost | +----[SHA256]-----+ 2026-01-10 00:30:07.620585 | controller -> localhost | ok: Runtime: 0:00:00.014726 2026-01-10 00:30:07.639861 | 2026-01-10 00:30:07.640002 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-10 00:30:07.683155 | controller | ok 2026-01-10 00:30:07.701639 | controller | included: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-10 00:30:07.715321 | 2026-01-10 00:30:07.715417 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-10 00:30:07.740986 | controller | skipping: Conditional result was False 2026-01-10 00:30:07.752590 | 2026-01-10 00:30:07.752748 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-10 00:30:08.028534 | controller | changed 2026-01-10 00:30:08.043144 | 2026-01-10 00:30:08.043295 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-10 00:30:08.300025 | controller | ok 2026-01-10 00:30:08.313547 | 2026-01-10 00:30:08.313829 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-10 00:30:08.989737 | controller | changed 2026-01-10 00:30:09.005569 | 2026-01-10 00:30:09.005758 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-10 00:30:09.646819 | controller | changed 2026-01-10 00:30:09.658464 | 2026-01-10 00:30:09.658632 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-10 00:30:09.684497 | controller | skipping: Conditional result was False 2026-01-10 00:30:09.696810 | 2026-01-10 00:30:09.696999 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-10 00:30:09.959948 | controller -> localhost | changed 2026-01-10 00:30:10.030858 | 2026-01-10 00:30:10.031011 | TASK [add-build-sshkey : Add back temp key] 2026-01-10 00:30:10.340766 | controller -> localhost | Identity added: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/818d0f76aa504ce1aba0f97b3b39738a_id_ecdsa (zuul-build-sshkey) 2026-01-10 00:30:10.341104 | controller -> localhost | ok: Runtime: 0:00:00.013048 2026-01-10 00:30:10.352467 | 2026-01-10 00:30:10.352593 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-10 00:30:10.575244 | controller | ok 2026-01-10 00:30:10.580972 | 2026-01-10 00:30:10.581042 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-10 00:30:10.615283 | controller | skipping: Conditional result was False 2026-01-10 00:30:10.627707 | 2026-01-10 00:30:10.627782 | TASK [include_role : remove-zuul-sshkey] 2026-01-10 00:30:10.652356 | controller | skipping: Conditional result was False 2026-01-10 00:30:10.660960 | 2026-01-10 00:30:10.661034 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-10 00:30:10.906037 | controller | ok: "logs" 2026-01-10 00:30:10.906276 | controller | ok: All items complete 2026-01-10 00:30:10.906303 | 2026-01-10 00:30:11.115423 | controller | ok: "artifacts" 2026-01-10 00:30:11.318196 | controller | ok: "docs" 2026-01-10 00:30:11.344229 | 2026-01-10 00:30:11.344481 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-10 00:30:11.586415 | controller | changed: "logs" 2026-01-10 00:30:11.796055 | controller | changed: "artifacts" 2026-01-10 00:30:12.013312 | controller | changed: "docs" 2026-01-10 00:30:12.084333 | 2026-01-10 00:30:12.084461 | PLAY RECAP 2026-01-10 00:30:12.084525 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-10 00:30:12.084564 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-10 00:30:12.084591 | 2026-01-10 00:30:12.212878 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-10 00:30:12.214085 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-10 00:30:12.784628 | 2026-01-10 00:30:12.784800 | PLAY [all] 2026-01-10 00:30:12.807732 | 2026-01-10 00:30:12.807830 | TASK [Install binary dependencies] 2026-01-10 00:30:12.857358 | controller | ok 2026-01-10 00:30:12.876881 | 2026-01-10 00:30:12.876969 | TASK [bindep : Include find tasks] 2026-01-10 00:30:12.906837 | controller | ok 2026-01-10 00:30:12.915909 | controller | included: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-10 00:30:12.923306 | 2026-01-10 00:30:12.923374 | TASK [bindep : Look for bindep.txt] 2026-01-10 00:30:13.299612 | controller | ok 2026-01-10 00:30:13.316114 | 2026-01-10 00:30:13.316281 | TASK [bindep : Define bindep_file fact] 2026-01-10 00:30:13.353585 | controller | skipping: Conditional result was False 2026-01-10 00:30:13.372517 | 2026-01-10 00:30:13.372709 | TASK [bindep : Look for other-requirements.txt] 2026-01-10 00:30:13.589255 | controller | ok 2026-01-10 00:30:13.597891 | 2026-01-10 00:30:13.597998 | TASK [bindep : Define bindep_file fact] 2026-01-10 00:30:13.623914 | controller | skipping: Conditional result was False 2026-01-10 00:30:13.633624 | 2026-01-10 00:30:13.633765 | TASK [bindep : Look for bindep fallback file] 2026-01-10 00:30:13.663200 | controller | skipping: Conditional result was False 2026-01-10 00:30:13.675881 | 2026-01-10 00:30:13.676026 | TASK [bindep : Define bindep_file fact] 2026-01-10 00:30:13.703744 | controller | skipping: Conditional result was False 2026-01-10 00:30:13.712348 | 2026-01-10 00:30:13.712428 | TASK [bindep : Include bindep tasks] 2026-01-10 00:30:13.736510 | controller | skipping: Conditional result was False 2026-01-10 00:30:13.743120 | 2026-01-10 00:30:13.743203 | TASK [bindep : Include install tasks] 2026-01-10 00:30:13.767357 | controller | skipping: Conditional result was False 2026-01-10 00:30:13.774406 | 2026-01-10 00:30:13.774528 | LOOP [bindep : Include package tasks] 2026-01-10 00:30:13.835800 | 2026-01-10 00:30:13.836026 | TASK [Run test-setup role] 2026-01-10 00:30:13.862137 | controller | ok 2026-01-10 00:30:13.886487 | 2026-01-10 00:30:13.886631 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-10 00:30:14.127480 | controller | ok 2026-01-10 00:30:14.141947 | 2026-01-10 00:30:14.142086 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-10 00:30:14.693837 | controller | skipping: Conditional result was False 2026-01-10 00:30:14.749043 | 2026-01-10 00:30:14.749145 | PLAY RECAP 2026-01-10 00:30:14.749203 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-10 00:30:14.749236 | 2026-01-10 00:30:14.850139 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-10 00:30:14.851947 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-10 00:30:15.460565 | 2026-01-10 00:30:15.460757 | PLAY [controller] 2026-01-10 00:30:15.488647 | 2026-01-10 00:30:15.488774 | TASK [Create the /root directory] 2026-01-10 00:30:15.893988 | controller | ok 2026-01-10 00:30:15.907496 | 2026-01-10 00:30:15.907734 | TASK [Install glibc-langpack-en] 2026-01-10 00:30:19.876118 | controller | ok: Nothing to do 2026-01-10 00:30:19.888603 | 2026-01-10 00:30:19.888809 | TASK [Ensure controller directory exists] 2026-01-10 00:30:20.126036 | controller | changed 2026-01-10 00:30:20.138820 | 2026-01-10 00:30:20.138983 | TASK [Install container runtime] 2026-01-10 00:30:20.194730 | controller | ok 2026-01-10 00:30:20.249008 | 2026-01-10 00:30:20.249143 | LOOP [ensure-podman : Find distribution installation] 2026-01-10 00:30:20.282832 | controller | ok: "/var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-10 00:30:20.295036 | controller | included: /var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-10 00:30:20.303912 | 2026-01-10 00:30:20.303997 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-10 00:31:24.983222 | controller | changed 2026-01-10 00:31:24.990780 | 2026-01-10 00:31:24.990857 | TASK [ensure-podman : Fetch podman version] 2026-01-10 00:31:25.562346 | controller | Client: Podman Engine 2026-01-10 00:31:25.562513 | controller | Version: 4.6.2 2026-01-10 00:31:25.562563 | controller | API Version: 4.6.2 2026-01-10 00:31:25.562608 | controller | Go Version: go1.19.12 2026-01-10 00:31:25.562664 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-10 00:31:25.562716 | controller | OS/Arch: linux/amd64 2026-01-10 00:31:26.021583 | controller | ok: Runtime: 0:00:00.191050 2026-01-10 00:31:26.035014 | 2026-01-10 00:31:26.035161 | TASK [ensure-podman : Print podman version installed] 2026-01-10 00:31:26.074505 | Podman version: Client: Podman Engine 2026-01-10 00:31:26.074814 | Version: 4.6.2 2026-01-10 00:31:26.074882 | API Version: 4.6.2 2026-01-10 00:31:26.074931 | Go Version: go1.19.12 2026-01-10 00:31:26.074974 | Built: Mon Aug 28 19:38:31 2023 2026-01-10 00:31:26.075017 | OS/Arch: linux/amd64 2026-01-10 00:31:26.087575 | 2026-01-10 00:31:26.087746 | TASK [ensure-podman : Validate podman engine] 2026-01-10 00:31:26.633776 | controller | skipping: Conditional result was False 2026-01-10 00:31:26.647721 | 2026-01-10 00:31:26.647905 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-10 00:31:26.675279 | controller | skipping: Conditional result was False 2026-01-10 00:31:26.691379 | 2026-01-10 00:31:26.691496 | TASK [Ensure python3.8 is present] 2026-01-10 00:31:26.705720 | controller | skipping: Conditional result was False 2026-01-10 00:31:26.711544 | 2026-01-10 00:31:26.711605 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-10 00:31:26.732659 | controller | ok 2026-01-10 00:31:26.755631 | 2026-01-10 00:31:26.755792 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-10 00:31:28.162701 | controller | ok: Nothing to do 2026-01-10 00:31:28.175586 | 2026-01-10 00:31:28.175763 | TASK [our-ensure-python : Also install python3-devel] 2026-01-10 00:31:38.182232 | controller | changed 2026-01-10 00:31:38.207868 | 2026-01-10 00:31:38.208055 | TASK [Run ensure-virtualenv role] 2026-01-10 00:31:38.238693 | controller | ok 2026-01-10 00:31:38.272064 | 2026-01-10 00:31:38.272163 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-10 00:31:38.549904 | controller | /usr/bin/virtualenv 2026-01-10 00:31:38.833419 | controller | ok: Runtime: 0:00:00.005578 2026-01-10 00:31:38.846908 | 2026-01-10 00:31:38.847079 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-10 00:31:38.886941 | controller | skipping: Conditional result was False 2026-01-10 00:31:38.887402 | controller | ok: All items complete 2026-01-10 00:31:38.887464 | 2026-01-10 00:31:38.921336 | 2026-01-10 00:31:38.921587 | TASK [Find the full path of the Python interpreter] 2026-01-10 00:31:39.149710 | controller | /usr/bin/python3 2026-01-10 00:31:39.467327 | controller | ok 2026-01-10 00:31:39.481247 | 2026-01-10 00:31:39.481451 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-10 00:31:40.477128 | controller | created virtual environment CPython3.11.0.final.0-64 in 524ms 2026-01-10 00:31:40.493545 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-10 00:31:40.493585 | 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-01-10 00:31:40.493595 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-10 00:31:40.493631 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-10 00:31:40.543544 | controller | changed 2026-01-10 00:31:40.552189 | 2026-01-10 00:31:40.552300 | TASK [Set selinux package] 2026-01-10 00:31:40.586300 | controller | ok 2026-01-10 00:31:40.593942 | 2026-01-10 00:31:40.594044 | TASK [Set selinux package (Fedora)] 2026-01-10 00:31:40.647328 | controller | ok 2026-01-10 00:31:40.652342 | 2026-01-10 00:31:40.652403 | TASK [Install selinux into virtualenv] 2026-01-10 00:31:54.147144 | controller | Collecting selinux-please-lie-to-me 2026-01-10 00:32:06.408415 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-10 00:32:06.712685 | controller | Collecting setuptools<50.0.0 2026-01-10 00:32:06.719521 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-10 00:32:06.754749 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.6 MB/s eta 0:00:00 2026-01-10 00:32:06.837329 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-10 00:32:06.837494 | controller | Attempting uninstall: setuptools 2026-01-10 00:32:06.839871 | controller | Found existing installation: setuptools 62.6.0 2026-01-10 00:32:06.898773 | controller | Uninstalling setuptools-62.6.0: 2026-01-10 00:32:06.906371 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-10 00:32:07.258230 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-10 00:32:18.784278 | controller | 2026-01-10 00:32:18.886731 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-10 00:32:18.886777 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-10 00:32:19.222087 | controller | ok: Runtime: 0:00:38.018400 2026-01-10 00:32:19.230348 | 2026-01-10 00:32:19.230483 | TASK [Install pytest-forked into virtualenv] 2026-01-10 00:32:31.034423 | controller | Collecting pytest-forked 2026-01-10 00:32:40.215163 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-10 00:32:40.260813 | controller | Collecting py 2026-01-10 00:32:40.265148 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-10 00:32:40.290291 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.6 MB/s eta 0:00:00 2026-01-10 00:32:40.402479 | controller | Collecting pytest>=3.10 2026-01-10 00:32:40.406201 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-10 00:32:40.420707 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 32.7 MB/s eta 0:00:00 2026-01-10 00:32:40.462757 | controller | Collecting iniconfig>=1.0.1 2026-01-10 00:32:40.467217 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-10 00:32:40.511890 | controller | Collecting packaging>=22 2026-01-10 00:32:40.515140 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-10 00:32:40.522762 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.4 MB/s eta 0:00:00 2026-01-10 00:32:40.559677 | controller | Collecting pluggy<2,>=1.5 2026-01-10 00:32:40.563381 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-10 00:32:40.614622 | controller | Collecting pygments>=2.7.2 2026-01-10 00:32:40.621503 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-10 00:32:40.639185 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 82.0 MB/s eta 0:00:00 2026-01-10 00:32:40.711834 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-10 00:32:41.804898 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-01-10 00:32:41.813451 | controller | 2026-01-10 00:32:41.881641 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-10 00:32:41.881674 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-10 00:32:42.273214 | controller | ok: Runtime: 0:00:22.440176 2026-01-10 00:32:42.281635 | 2026-01-10 00:32:42.281747 | TASK [Update pip] 2026-01-10 00:32:42.807928 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-10 00:32:52.583643 | controller | Collecting pip 2026-01-10 00:33:04.900704 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-10 00:33:05.002990 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 18.3 MB/s eta 0:00:00 2026-01-10 00:33:05.068215 | controller | Installing collected packages: pip 2026-01-10 00:33:05.068362 | controller | Attempting uninstall: pip 2026-01-10 00:33:05.070608 | controller | Found existing installation: pip 22.2.2 2026-01-10 00:33:05.207829 | controller | Uninstalling pip-22.2.2: 2026-01-10 00:33:05.222747 | controller | Successfully uninstalled pip-22.2.2 2026-01-10 00:33:06.051351 | controller | Successfully installed pip-25.3 2026-01-10 00:33:06.335544 | controller | ok: Runtime: 0:00:23.626300 2026-01-10 00:33:06.349414 | 2026-01-10 00:33:06.349581 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-10 00:33:06.584535 | controller | changed 2026-01-10 00:33:06.598591 | 2026-01-10 00:33:06.598794 | TASK [Install ansible into virtualenv] 2026-01-10 00:33:07.136154 | controller | Processing ./src/github.com/ansible/ansible 2026-01-10 00:33:07.139301 | controller | Installing build dependencies: started 2026-01-10 00:33:29.762455 | controller | Installing build dependencies: finished with status 'done' 2026-01-10 00:33:29.763668 | controller | Getting requirements to build wheel: started 2026-01-10 00:33:30.521100 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-10 00:33:30.521979 | controller | Preparing metadata (pyproject.toml): started 2026-01-10 00:33:31.013874 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-10 00:33:31.016699 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-01-10 00:33:31.019257 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-10 00:33:31.189106 | controller | ERROR 2026-01-10 00:33:31.189336 | controller | { 2026-01-10 00:33:31.189397 | controller | "delta": "0:00:24.222760", 2026-01-10 00:33:31.189438 | controller | "end": "2026-01-10 00:33:31.080098", 2026-01-10 00:33:31.189476 | controller | "msg": "non-zero return code", 2026-01-10 00:33:31.189529 | controller | "rc": 1, 2026-01-10 00:33:31.189567 | controller | "start": "2026-01-10 00:33:06.857338" 2026-01-10 00:33:31.189612 | controller | } failure 2026-01-10 00:33:31.193069 | 2026-01-10 00:33:31.193171 | PLAY RECAP 2026-01-10 00:33:31.193259 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-10 00:33:31.193314 | 2026-01-10 00:33:31.323943 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-10 00:33:31.324916 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-10 00:33:31.926341 | 2026-01-10 00:33:31.926459 | PLAY [all] 2026-01-10 00:33:31.949442 | 2026-01-10 00:33:31.949577 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-10 00:33:32.234702 | controller | changed: non-zero return code 2026-01-10 00:33:32.240716 | 2026-01-10 00:33:32.240795 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-10 00:33:32.265098 | controller | skipping: Conditional result was False 2026-01-10 00:33:32.271408 | 2026-01-10 00:33:32.271479 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-10 00:33:32.306230 | 2026-01-10 00:33:32.306634 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-10 00:33:32.341770 | 2026-01-10 00:33:32.341986 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-10 00:33:32.367415 | controller | skipping: Conditional result was False 2026-01-10 00:33:32.379643 | 2026-01-10 00:33:32.379836 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-10 00:33:32.414836 | 2026-01-10 00:33:32.415056 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-10 00:33:32.440422 | controller | skipping: Conditional result was False 2026-01-10 00:33:32.449819 | 2026-01-10 00:33:32.449960 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-10 00:33:32.474949 | controller | skipping: Conditional result was False 2026-01-10 00:33:32.484522 | 2026-01-10 00:33:32.484660 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-10 00:33:32.510465 | controller | skipping: Conditional result was False 2026-01-10 00:33:32.550920 | 2026-01-10 00:33:32.551150 | PLAY RECAP 2026-01-10 00:33:32.551300 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-10 00:33:32.551348 | 2026-01-10 00:33:32.678113 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-10 00:33:32.679332 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-10 00:33:33.240182 | 2026-01-10 00:33:33.240293 | PLAY [all:!appliance*] 2026-01-10 00:33:33.262403 | 2026-01-10 00:33:33.262524 | TASK [unregister the node] 2026-01-10 00:33:33.793936 | controller | skipping: Conditional result was False 2026-01-10 00:33:33.801810 | 2026-01-10 00:33:33.801918 | TASK [include_role : fetch-output] 2026-01-10 00:33:33.834035 | controller | ok 2026-01-10 00:33:33.860304 | 2026-01-10 00:33:33.860410 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-10 00:33:33.905507 | controller | skipping: Conditional result was False 2026-01-10 00:33:33.919045 | 2026-01-10 00:33:33.919217 | TASK [fetch-output : Set log path for single node] 2026-01-10 00:33:33.967616 | controller | ok 2026-01-10 00:33:33.980089 | 2026-01-10 00:33:33.980233 | LOOP [fetch-output : Ensure local output dirs] 2026-01-10 00:33:34.390253 | controller -> localhost | ok: "/var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/logs" 2026-01-10 00:33:34.655280 | controller -> localhost | changed: "/var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/artifacts" 2026-01-10 00:33:34.888587 | controller -> localhost | changed: "/var/lib/zuul/builds/818d0f76aa504ce1aba0f97b3b39738a/work/docs" 2026-01-10 00:33:34.912643 | 2026-01-10 00:33:34.912897 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-10 00:33:35.632732 | controller | changed: 2026-01-10 00:33:35.633042 | controller | .d..t...... ./ 2026-01-10 00:33:35.633102 | controller | cd+++++++++ controller/ 2026-01-10 00:33:35.633167 | controller | changed: All items complete 2026-01-10 00:33:35.633209 | 2026-01-10 00:33:36.171777 | controller | changed: .d..t...... ./ 2026-01-10 00:33:36.698288 | controller | changed: .d..t...... ./ 2026-01-10 00:33:36.727053 | 2026-01-10 00:33:36.727259 | TASK [include_role : fetch-output-openshift] 2026-01-10 00:33:36.744777 | controller | skipping: Conditional result was False 2026-01-10 00:33:36.754658 | 2026-01-10 00:33:36.754847 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-10 00:33:36.780067 | controller | skipping: Conditional result was False 2026-01-10 00:33:36.790685 | controller | skipping: Conditional result was False 2026-01-10 00:33:36.829368 | 2026-01-10 00:33:36.829529 | PLAY [localhost] 2026-01-10 00:33:36.846125 | 2026-01-10 00:33:36.846213 | TASK [Run Zuul manifest role] 2026-01-10 00:33:36.865707 | localhost | ok 2026-01-10 00:33:36.879368 | 2026-01-10 00:33:36.879431 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-10 00:33:37.256340 | localhost | changed 2026-01-10 00:33:37.263311 | 2026-01-10 00:33:37.263408 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-10 00:33:37.296415 | localhost | ok 2026-01-10 00:33:37.308578 | 2026-01-10 00:33:37.308710 | TASK [Set zuul-log-path fact] 2026-01-10 00:33:37.328120 | localhost | ok 2026-01-10 00:33:37.349049 | 2026-01-10 00:33:37.349221 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-10 00:33:37.388767 | localhost | ok 2026-01-10 00:33:37.396509 | 2026-01-10 00:33:37.396566 | LOOP [Run upload-logs-swift role] 2026-01-10 00:33:37.434848 | localhost | Output suppressed because no_log was given 2026-01-10 00:33:37.459629 | 2026-01-10 00:33:37.459722 | TASK [Set zuul-log-path fact] 2026-01-10 00:33:37.503870 | localhost | skipping: Conditional result was False 2026-01-10 00:33:37.508725 | 2026-01-10 00:33:37.508792 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-10 00:33:37.903338 | localhost -> localhost | ok: Runtime: 0:00:00.007998 2026-01-10 00:33:37.953269 | 2026-01-10 00:33:37.953409 | TASK [upload-logs-swift : Upload logs to swift]