2026-02-22 00:06:48.949909 | Job console starting... 2026-02-22 00:06:48.973482 | Updating repositories 2026-02-22 00:06:49.135014 | Preparing job workspace 2026-02-22 00:07:01.770226 | Running Ansible setup... 2026-02-22 00:07:08.475006 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-22 00:07:09.358165 | 2026-02-22 00:07:09.358293 | PLAY [localhost] 2026-02-22 00:07:09.366768 | 2026-02-22 00:07:09.366838 | TASK [Gathering Facts] 2026-02-22 00:07:10.459684 | localhost | ok 2026-02-22 00:07:10.479074 | 2026-02-22 00:07:10.479183 | TASK [Setup log path fact] 2026-02-22 00:07:10.500886 | localhost | ok 2026-02-22 00:07:10.519601 | 2026-02-22 00:07:10.519712 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-22 00:07:10.550503 | localhost | ok 2026-02-22 00:07:10.558191 | 2026-02-22 00:07:10.558258 | TASK [emit-job-header : Print job information] 2026-02-22 00:07:10.607810 | # Job Information 2026-02-22 00:07:10.607980 | Ansible Version: 2.15.12 2026-02-22 00:07:10.608025 | Job: ansible-test-sanity-docker-devel 2026-02-22 00:07:10.608055 | Pipeline: periodic 2026-02-22 00:07:10.608082 | Executor: ze03.softwarefactory-project.io 2026-02-22 00:07:10.608108 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-22 00:07:10.608139 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/4c9/ansible/4c989de5d40347638d36784f57291544/ 2026-02-22 00:07:10.608167 | Event ID: a7fc77fcb26d4cceb2ed771a560774dd 2026-02-22 00:07:10.613518 | 2026-02-22 00:07:10.613610 | LOOP [emit-job-header : Print node information] 2026-02-22 00:07:10.736170 | localhost | ok: 2026-02-22 00:07:10.736438 | localhost | # Node Information 2026-02-22 00:07:10.736485 | localhost | Inventory Hostname: controller 2026-02-22 00:07:10.736518 | localhost | Hostname: np0005625929 2026-02-22 00:07:10.736548 | localhost | Username: zuul 2026-02-22 00:07:10.736601 | localhost | Distro: Fedora 37 2026-02-22 00:07:10.736633 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-22 00:07:10.736663 | localhost | Region: ca-ymq-1 2026-02-22 00:07:10.736692 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-22 00:07:10.736743 | localhost | Product Name: OpenStack Nova 2026-02-22 00:07:10.736780 | localhost | Interface IP: 162.253.55.200 2026-02-22 00:07:10.747939 | 2026-02-22 00:07:10.748028 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-22 00:07:11.210091 | localhost -> localhost | changed 2026-02-22 00:07:11.223026 | 2026-02-22 00:07:11.223141 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-22 00:07:12.752425 | localhost -> localhost | changed 2026-02-22 00:07:12.786626 | 2026-02-22 00:07:12.786745 | PLAY [all:!appliance*] 2026-02-22 00:07:12.812481 | 2026-02-22 00:07:12.812591 | TASK [include_role : start-zuul-console] 2026-02-22 00:07:12.833039 | controller | ok 2026-02-22 00:07:12.847226 | 2026-02-22 00:07:12.847319 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-22 00:07:13.226454 | controller | ok 2026-02-22 00:07:13.248791 | 2026-02-22 00:07:13.248948 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-22 00:07:14.272024 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-22 00:07:14.282828 | 2026-02-22 00:07:14.282996 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-22 00:07:14.832393 | controller | skipping: Conditional result was False 2026-02-22 00:07:14.854179 | 2026-02-22 00:07:14.854418 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-22 00:07:14.880077 | controller | skipping: Conditional result was False 2026-02-22 00:07:14.892217 | 2026-02-22 00:07:14.892308 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-22 00:07:14.908584 | controller | skipping: Conditional result was False 2026-02-22 00:07:14.921868 | 2026-02-22 00:07:14.921971 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-22 00:07:14.940305 | controller | skipping: Conditional result was False 2026-02-22 00:07:14.947348 | 2026-02-22 00:07:14.947419 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-22 00:07:14.961902 | controller | skipping: Conditional result was False 2026-02-22 00:07:14.971468 | 2026-02-22 00:07:14.971552 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-22 00:07:14.996515 | controller | skipping: Conditional result was False 2026-02-22 00:07:15.008927 | 2026-02-22 00:07:15.008995 | TASK [Disable Fedora Modular] 2026-02-22 00:07:15.294617 | controller | changed 2026-02-22 00:07:15.319491 | 2026-02-22 00:07:15.319694 | TASK [Enable EPEL] 2026-02-22 00:07:15.348305 | controller | skipping: Conditional result was False 2026-02-22 00:07:15.366110 | 2026-02-22 00:07:15.366256 | TASK [Register the RHEL node] 2026-02-22 00:07:15.927128 | 2026-02-22 00:07:15.927339 | TASK [Show the subscription-manager status] 2026-02-22 00:07:16.498189 | controller | skipping: Conditional result was False 2026-02-22 00:07:16.511721 | 2026-02-22 00:07:16.511910 | TASK [Enable EPEL on RHEL] 2026-02-22 00:07:17.051884 | controller | skipping: Conditional result was False 2026-02-22 00:07:17.065864 | 2026-02-22 00:07:17.066073 | TASK [Install git and tox] 2026-02-22 00:08:46.409044 | controller | changed 2026-02-22 00:08:46.419296 | 2026-02-22 00:08:46.419436 | TASK [include_role : prepare-workspace] 2026-02-22 00:08:46.456744 | controller | ok 2026-02-22 00:08:46.489352 | 2026-02-22 00:08:46.489472 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-22 00:08:46.738974 | controller | ok 2026-02-22 00:08:46.754186 | 2026-02-22 00:08:46.754387 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-22 00:09:00.314598 | controller | Output suppressed because no_log was given 2026-02-22 00:09:00.355397 | 2026-02-22 00:09:00.355694 | TASK [include_role : prepare-workspace-openshift] 2026-02-22 00:09:00.380989 | controller | skipping: Conditional result was False 2026-02-22 00:09:00.409083 | 2026-02-22 00:09:00.409200 | PLAY [all:!appliance] 2026-02-22 00:09:00.430492 | 2026-02-22 00:09:00.430574 | TASK [Run add-build-sshkey role (RSA)] 2026-02-22 00:09:00.452870 | controller | ok 2026-02-22 00:09:00.471354 | 2026-02-22 00:09:00.471446 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-22 00:09:00.745516 | controller -> localhost | ok 2026-02-22 00:09:00.753159 | 2026-02-22 00:09:00.753255 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-22 00:09:00.786630 | controller | ok 2026-02-22 00:09:00.802385 | controller | included: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-22 00:09:00.809435 | 2026-02-22 00:09:00.809522 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-22 00:09:01.309301 | controller -> localhost | Generating public/private rsa key pair. 2026-02-22 00:09:01.309532 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/4c989de5d40347638d36784f57291544_id_rsa. 2026-02-22 00:09:01.309575 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/4c989de5d40347638d36784f57291544_id_rsa.pub. 2026-02-22 00:09:01.309608 | controller -> localhost | The key fingerprint is: 2026-02-22 00:09:01.309638 | controller -> localhost | SHA256:bOv6kS2ui4LpbU+fMxtmHMg5Zn9uAnyDrRpryTF9DPs zuul-build-sshkey 2026-02-22 00:09:01.309673 | controller -> localhost | The key's randomart image is: 2026-02-22 00:09:01.309706 | controller -> localhost | +---[RSA 2048]----+ 2026-02-22 00:09:01.309766 | controller -> localhost | | | 2026-02-22 00:09:01.309797 | controller -> localhost | | | 2026-02-22 00:09:01.309824 | controller -> localhost | | | 2026-02-22 00:09:01.309851 | controller -> localhost | | ..o. | 2026-02-22 00:09:01.309878 | controller -> localhost | | oB*.S | 2026-02-22 00:09:01.309918 | controller -> localhost | | oo*+B.+ | 2026-02-22 00:09:01.309950 | controller -> localhost | | o..+.***.. | 2026-02-22 00:09:01.309980 | controller -> localhost | |o o=+o+E=+ | 2026-02-22 00:09:01.310006 | controller -> localhost | |..o=+.+OX. | 2026-02-22 00:09:01.310036 | controller -> localhost | +----[SHA256]-----+ 2026-02-22 00:09:01.310137 | controller -> localhost | ok: Runtime: 0:00:00.106153 2026-02-22 00:09:01.321183 | 2026-02-22 00:09:01.321304 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-22 00:09:01.352414 | controller | ok 2026-02-22 00:09:01.365032 | controller | included: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-22 00:09:01.376046 | 2026-02-22 00:09:01.376169 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-22 00:09:01.400777 | controller | skipping: Conditional result was False 2026-02-22 00:09:01.408097 | 2026-02-22 00:09:01.408213 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-22 00:09:01.872188 | controller | changed 2026-02-22 00:09:01.881388 | 2026-02-22 00:09:01.881514 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-22 00:09:02.116098 | controller | ok 2026-02-22 00:09:02.129287 | 2026-02-22 00:09:02.129469 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-22 00:09:02.749331 | controller | changed 2026-02-22 00:09:02.757901 | 2026-02-22 00:09:02.757995 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-22 00:09:03.494257 | controller | changed 2026-02-22 00:09:03.504450 | 2026-02-22 00:09:03.504567 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-22 00:09:03.520256 | controller | skipping: Conditional result was False 2026-02-22 00:09:03.528784 | 2026-02-22 00:09:03.528890 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-22 00:09:03.937538 | controller -> localhost | changed 2026-02-22 00:09:03.949504 | 2026-02-22 00:09:03.949618 | TASK [add-build-sshkey : Add back temp key] 2026-02-22 00:09:04.292342 | controller -> localhost | Identity added: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/4c989de5d40347638d36784f57291544_id_rsa (zuul-build-sshkey) 2026-02-22 00:09:04.292599 | controller -> localhost | ok: Runtime: 0:00:00.009373 2026-02-22 00:09:04.304122 | 2026-02-22 00:09:04.304247 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-22 00:09:04.703937 | controller | ok 2026-02-22 00:09:04.716397 | 2026-02-22 00:09:04.716545 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-22 00:09:04.764217 | controller | skipping: Conditional result was False 2026-02-22 00:09:04.791572 | 2026-02-22 00:09:04.791782 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-22 00:09:04.831581 | controller | ok 2026-02-22 00:09:04.864430 | 2026-02-22 00:09:04.864567 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-22 00:09:05.154783 | controller -> localhost | ok 2026-02-22 00:09:05.161349 | 2026-02-22 00:09:05.161417 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-22 00:09:05.191022 | controller | ok 2026-02-22 00:09:05.202179 | controller | included: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-22 00:09:05.208942 | 2026-02-22 00:09:05.209015 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-22 00:09:05.559663 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-22 00:09:05.560004 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/4c989de5d40347638d36784f57291544_id_ecdsa. 2026-02-22 00:09:05.560067 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/4c989de5d40347638d36784f57291544_id_ecdsa.pub. 2026-02-22 00:09:05.560133 | controller -> localhost | The key fingerprint is: 2026-02-22 00:09:05.560177 | controller -> localhost | SHA256:dL/MgMLdrnJ6+OYK+8tFBYxpE7wqygR3qjyJN/LDC7s zuul-build-sshkey 2026-02-22 00:09:05.560218 | controller -> localhost | The key's randomart image is: 2026-02-22 00:09:05.560258 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-22 00:09:05.560297 | controller -> localhost | | ..=. | 2026-02-22 00:09:05.560335 | controller -> localhost | | * .. | 2026-02-22 00:09:05.560372 | controller -> localhost | | . o. o | 2026-02-22 00:09:05.560409 | controller -> localhost | |. . ...o = . | 2026-02-22 00:09:05.560445 | controller -> localhost | |.. o .o S o . | 2026-02-22 00:09:05.560480 | controller -> localhost | | .o . o . + . | 2026-02-22 00:09:05.560516 | controller -> localhost | |*+... .. . + | 2026-02-22 00:09:05.560552 | controller -> localhost | |=B= +o.+. | 2026-02-22 00:09:05.560588 | controller -> localhost | |E=++..*@+ | 2026-02-22 00:09:05.560625 | controller -> localhost | +----[SHA256]-----+ 2026-02-22 00:09:05.560764 | controller -> localhost | ok: Runtime: 0:00:00.010110 2026-02-22 00:09:05.575583 | 2026-02-22 00:09:05.575807 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-22 00:09:05.620089 | controller | ok 2026-02-22 00:09:05.630291 | controller | included: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-22 00:09:05.643013 | 2026-02-22 00:09:05.643149 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-22 00:09:05.669234 | controller | skipping: Conditional result was False 2026-02-22 00:09:05.679192 | 2026-02-22 00:09:05.679326 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-22 00:09:05.971674 | controller | changed 2026-02-22 00:09:05.984812 | 2026-02-22 00:09:05.984967 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-22 00:09:06.234258 | controller | ok 2026-02-22 00:09:06.251787 | 2026-02-22 00:09:06.252020 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-22 00:09:06.954287 | controller | changed 2026-02-22 00:09:06.967285 | 2026-02-22 00:09:06.967433 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-22 00:09:07.677265 | controller | changed 2026-02-22 00:09:07.690671 | 2026-02-22 00:09:07.690866 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-22 00:09:07.728636 | controller | skipping: Conditional result was False 2026-02-22 00:09:07.743118 | 2026-02-22 00:09:07.743305 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-22 00:09:08.016811 | controller -> localhost | changed 2026-02-22 00:09:08.061044 | 2026-02-22 00:09:08.061153 | TASK [add-build-sshkey : Add back temp key] 2026-02-22 00:09:08.391038 | controller -> localhost | Identity added: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/4c989de5d40347638d36784f57291544_id_ecdsa (zuul-build-sshkey) 2026-02-22 00:09:08.391244 | controller -> localhost | ok: Runtime: 0:00:00.017413 2026-02-22 00:09:08.397821 | 2026-02-22 00:09:08.397899 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-22 00:09:08.608463 | controller | ok 2026-02-22 00:09:08.621704 | 2026-02-22 00:09:08.622032 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-22 00:09:08.669983 | controller | skipping: Conditional result was False 2026-02-22 00:09:08.700239 | 2026-02-22 00:09:08.700414 | TASK [include_role : remove-zuul-sshkey] 2026-02-22 00:09:08.727267 | controller | skipping: Conditional result was False 2026-02-22 00:09:08.736758 | 2026-02-22 00:09:08.736876 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-22 00:09:08.992180 | controller | ok: "logs" 2026-02-22 00:09:08.992664 | controller | ok: All items complete 2026-02-22 00:09:08.992784 | 2026-02-22 00:09:09.197132 | controller | ok: "artifacts" 2026-02-22 00:09:09.392393 | controller | ok: "docs" 2026-02-22 00:09:09.409933 | 2026-02-22 00:09:09.410162 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-22 00:09:09.668277 | controller | changed: "logs" 2026-02-22 00:09:09.902818 | controller | changed: "artifacts" 2026-02-22 00:09:10.115598 | controller | changed: "docs" 2026-02-22 00:09:10.163918 | 2026-02-22 00:09:10.164026 | PLAY RECAP 2026-02-22 00:09:10.164068 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-22 00:09:10.164093 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-22 00:09:10.164111 | 2026-02-22 00:09:10.294711 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-22 00:09:10.295772 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-22 00:09:10.978116 | 2026-02-22 00:09:10.978242 | PLAY [all] 2026-02-22 00:09:11.002517 | 2026-02-22 00:09:11.002648 | TASK [Install binary dependencies] 2026-02-22 00:09:11.063497 | controller | ok 2026-02-22 00:09:11.082991 | 2026-02-22 00:09:11.083077 | TASK [bindep : Include find tasks] 2026-02-22 00:09:11.115207 | controller | ok 2026-02-22 00:09:11.127469 | controller | included: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-22 00:09:11.136635 | 2026-02-22 00:09:11.136719 | TASK [bindep : Look for bindep.txt] 2026-02-22 00:09:11.485211 | controller | ok 2026-02-22 00:09:11.491468 | 2026-02-22 00:09:11.491634 | TASK [bindep : Define bindep_file fact] 2026-02-22 00:09:11.519695 | controller | skipping: Conditional result was False 2026-02-22 00:09:11.528841 | 2026-02-22 00:09:11.528986 | TASK [bindep : Look for other-requirements.txt] 2026-02-22 00:09:11.752445 | controller | ok 2026-02-22 00:09:11.764789 | 2026-02-22 00:09:11.764957 | TASK [bindep : Define bindep_file fact] 2026-02-22 00:09:11.792515 | controller | skipping: Conditional result was False 2026-02-22 00:09:11.805880 | 2026-02-22 00:09:11.806051 | TASK [bindep : Look for bindep fallback file] 2026-02-22 00:09:11.843504 | controller | skipping: Conditional result was False 2026-02-22 00:09:11.858893 | 2026-02-22 00:09:11.859045 | TASK [bindep : Define bindep_file fact] 2026-02-22 00:09:11.886445 | controller | skipping: Conditional result was False 2026-02-22 00:09:11.900664 | 2026-02-22 00:09:11.900841 | TASK [bindep : Include bindep tasks] 2026-02-22 00:09:11.928406 | controller | skipping: Conditional result was False 2026-02-22 00:09:11.942246 | 2026-02-22 00:09:11.942547 | TASK [bindep : Include install tasks] 2026-02-22 00:09:11.969590 | controller | skipping: Conditional result was False 2026-02-22 00:09:11.986155 | 2026-02-22 00:09:11.986314 | LOOP [bindep : Include package tasks] 2026-02-22 00:09:12.069188 | 2026-02-22 00:09:12.069431 | TASK [Run test-setup role] 2026-02-22 00:09:12.100371 | controller | ok 2026-02-22 00:09:12.129825 | 2026-02-22 00:09:12.129921 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-22 00:09:12.342127 | controller | ok 2026-02-22 00:09:12.356964 | 2026-02-22 00:09:12.357103 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-22 00:09:12.909405 | controller | skipping: Conditional result was False 2026-02-22 00:09:12.935991 | 2026-02-22 00:09:12.936103 | PLAY RECAP 2026-02-22 00:09:12.936151 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-22 00:09:12.936178 | 2026-02-22 00:09:13.047014 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-22 00:09:13.048013 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-22 00:09:13.790611 | 2026-02-22 00:09:13.790810 | PLAY [controller] 2026-02-22 00:09:13.824434 | 2026-02-22 00:09:13.824596 | TASK [Create the /root directory] 2026-02-22 00:09:14.265534 | controller | ok 2026-02-22 00:09:14.281297 | 2026-02-22 00:09:14.281464 | TASK [Install glibc-langpack-en] 2026-02-22 00:09:18.259122 | controller | ok: Nothing to do 2026-02-22 00:09:18.265920 | 2026-02-22 00:09:18.266014 | TASK [Ensure controller directory exists] 2026-02-22 00:09:18.484300 | controller | changed 2026-02-22 00:09:18.500606 | 2026-02-22 00:09:18.500801 | TASK [Install container runtime] 2026-02-22 00:09:18.558560 | controller | ok 2026-02-22 00:09:18.607771 | 2026-02-22 00:09:18.607903 | LOOP [ensure-podman : Find distribution installation] 2026-02-22 00:09:18.635236 | controller | ok: "/var/lib/zuul/builds/4c989de5d40347638d36784f57291544/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-22 00:09:18.650174 | controller | included: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-22 00:09:18.657491 | 2026-02-22 00:09:18.657627 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-22 00:10:26.470668 | controller | changed 2026-02-22 00:10:26.478490 | 2026-02-22 00:10:26.478588 | TASK [ensure-podman : Fetch podman version] 2026-02-22 00:10:26.999650 | controller | Client: Podman Engine 2026-02-22 00:10:26.999740 | controller | Version: 4.6.2 2026-02-22 00:10:26.999773 | controller | API Version: 4.6.2 2026-02-22 00:10:26.999803 | controller | Go Version: go1.19.12 2026-02-22 00:10:26.999843 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-22 00:10:26.999878 | controller | OS/Arch: linux/amd64 2026-02-22 00:10:27.512837 | controller | ok: Runtime: 0:00:00.178568 2026-02-22 00:10:27.527826 | 2026-02-22 00:10:27.528032 | TASK [ensure-podman : Print podman version installed] 2026-02-22 00:10:27.551455 | Podman version: Client: Podman Engine 2026-02-22 00:10:27.551614 | Version: 4.6.2 2026-02-22 00:10:27.551643 | API Version: 4.6.2 2026-02-22 00:10:27.551663 | Go Version: go1.19.12 2026-02-22 00:10:27.551682 | Built: Mon Aug 28 19:38:31 2023 2026-02-22 00:10:27.551702 | OS/Arch: linux/amd64 2026-02-22 00:10:27.557980 | 2026-02-22 00:10:27.558063 | TASK [ensure-podman : Validate podman engine] 2026-02-22 00:10:28.092140 | controller | skipping: Conditional result was False 2026-02-22 00:10:28.099215 | 2026-02-22 00:10:28.099307 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-22 00:10:28.113326 | controller | skipping: Conditional result was False 2026-02-22 00:10:28.125831 | 2026-02-22 00:10:28.125906 | TASK [Ensure python3.8 is present] 2026-02-22 00:10:28.140114 | controller | skipping: Conditional result was False 2026-02-22 00:10:28.146826 | 2026-02-22 00:10:28.146910 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-22 00:10:28.166314 | controller | ok 2026-02-22 00:10:28.186674 | 2026-02-22 00:10:28.186804 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-22 00:10:29.629785 | controller | ok: Nothing to do 2026-02-22 00:10:29.635909 | 2026-02-22 00:10:29.635989 | TASK [our-ensure-python : Also install python3-devel] 2026-02-22 00:10:39.194229 | controller | changed 2026-02-22 00:10:39.207539 | 2026-02-22 00:10:39.207698 | TASK [Run ensure-virtualenv role] 2026-02-22 00:10:39.231762 | controller | ok 2026-02-22 00:10:39.256186 | 2026-02-22 00:10:39.256340 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-22 00:10:39.470150 | controller | /usr/bin/virtualenv 2026-02-22 00:10:39.793806 | controller | ok: Runtime: 0:00:00.005454 2026-02-22 00:10:39.800486 | 2026-02-22 00:10:39.800571 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-22 00:10:39.827153 | controller | skipping: Conditional result was False 2026-02-22 00:10:39.827491 | controller | ok: All items complete 2026-02-22 00:10:39.827531 | 2026-02-22 00:10:39.845771 | 2026-02-22 00:10:39.845883 | TASK [Find the full path of the Python interpreter] 2026-02-22 00:10:40.070620 | controller | /usr/bin/python3 2026-02-22 00:10:40.405094 | controller | ok 2026-02-22 00:10:40.418516 | 2026-02-22 00:10:40.418764 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-22 00:10:41.410362 | controller | created virtual environment CPython3.11.0.final.0-64 in 508ms 2026-02-22 00:10:41.428021 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-22 00:10:41.428038 | 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-22 00:10:41.428054 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-22 00:10:41.428067 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-22 00:10:41.474261 | controller | changed 2026-02-22 00:10:41.486640 | 2026-02-22 00:10:41.486872 | TASK [Set selinux package] 2026-02-22 00:10:41.522519 | controller | ok 2026-02-22 00:10:41.532191 | 2026-02-22 00:10:41.532328 | TASK [Set selinux package (Fedora)] 2026-02-22 00:10:41.575579 | controller | ok 2026-02-22 00:10:41.582848 | 2026-02-22 00:10:41.582942 | TASK [Install selinux into virtualenv] 2026-02-22 00:11:07.055586 | controller | Collecting selinux-please-lie-to-me 2026-02-22 00:11:19.319743 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-22 00:11:19.626283 | controller | Collecting setuptools<50.0.0 2026-02-22 00:11:19.632952 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-22 00:11:19.671436 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 23.1 MB/s eta 0:00:00 2026-02-22 00:11:19.752278 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-22 00:11:19.752514 | controller | Attempting uninstall: setuptools 2026-02-22 00:11:19.754903 | controller | Found existing installation: setuptools 62.6.0 2026-02-22 00:11:19.813521 | controller | Uninstalling setuptools-62.6.0: 2026-02-22 00:11:19.821365 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-22 00:11:20.161913 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-22 00:11:31.691031 | controller | 2026-02-22 00:11:31.773132 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-22 00:11:31.773174 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-22 00:11:32.145088 | controller | ok: Runtime: 0:00:49.975721 2026-02-22 00:11:32.168849 | 2026-02-22 00:11:32.176162 | TASK [Install pytest-forked into virtualenv] 2026-02-22 00:11:43.938622 | controller | Collecting pytest-forked 2026-02-22 00:11:54.200814 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-22 00:11:54.254375 | controller | Collecting py 2026-02-22 00:11:54.260950 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-22 00:11:54.286844 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.6 MB/s eta 0:00:00 2026-02-22 00:11:54.398379 | controller | Collecting pytest>=3.10 2026-02-22 00:11:54.406037 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-22 00:11:54.433209 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 15.4 MB/s eta 0:00:00 2026-02-22 00:11:54.474496 | controller | Collecting iniconfig>=1.0.1 2026-02-22 00:11:54.478565 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-22 00:11:54.525750 | controller | Collecting packaging>=22 2026-02-22 00:11:54.529359 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-22 00:11:54.537018 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 12.1 MB/s eta 0:00:00 2026-02-22 00:11:54.568009 | controller | Collecting pluggy<2,>=1.5 2026-02-22 00:11:54.571213 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-22 00:11:54.623627 | controller | Collecting pygments>=2.7.2 2026-02-22 00:11:54.626906 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-22 00:11:54.657731 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 43.4 MB/s eta 0:00:00 2026-02-22 00:11:54.726427 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-22 00:11:55.807251 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-02-22 00:11:55.816079 | controller | 2026-02-22 00:11:55.884359 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-22 00:11:55.884398 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-22 00:11:56.236474 | controller | ok: Runtime: 0:00:23.491211 2026-02-22 00:11:56.243663 | 2026-02-22 00:11:56.243787 | TASK [Update pip] 2026-02-22 00:11:56.770243 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-22 00:12:09.214307 | controller | Collecting pip 2026-02-22 00:12:21.528479 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-22 00:12:21.583174 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.1 MB/s eta 0:00:00 2026-02-22 00:12:21.647068 | controller | Installing collected packages: pip 2026-02-22 00:12:21.647225 | controller | Attempting uninstall: pip 2026-02-22 00:12:21.649415 | controller | Found existing installation: pip 22.2.2 2026-02-22 00:12:21.785578 | controller | Uninstalling pip-22.2.2: 2026-02-22 00:12:21.800749 | controller | Successfully uninstalled pip-22.2.2 2026-02-22 00:12:22.605720 | controller | Successfully installed pip-26.0.1 2026-02-22 00:12:22.792178 | controller | ok: Runtime: 0:00:26.200521 2026-02-22 00:12:22.800639 | 2026-02-22 00:12:22.800762 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-22 00:12:23.021540 | controller | changed 2026-02-22 00:12:23.026938 | 2026-02-22 00:12:23.026998 | TASK [Install ansible into virtualenv] 2026-02-22 00:12:23.533026 | controller | Processing ./src/github.com/ansible/ansible 2026-02-22 00:12:23.535513 | controller | Installing build dependencies: started 2026-02-22 00:12:46.402067 | controller | Installing build dependencies: finished with status 'done' 2026-02-22 00:12:46.402636 | controller | Getting requirements to build wheel: started 2026-02-22 00:12:47.145218 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-22 00:12:47.146023 | controller | Preparing metadata (pyproject.toml): started 2026-02-22 00:12:47.617330 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-22 00:12:47.619495 | 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-02-22 00:12:47.622080 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-22 00:12:48.078826 | controller | ERROR 2026-02-22 00:12:48.079032 | controller | { 2026-02-22 00:12:48.079077 | controller | "delta": "0:00:24.430943", 2026-02-22 00:12:48.079136 | controller | "end": "2026-02-22 00:12:47.680971", 2026-02-22 00:12:48.079169 | controller | "msg": "non-zero return code", 2026-02-22 00:12:48.079215 | controller | "rc": 1, 2026-02-22 00:12:48.079250 | controller | "start": "2026-02-22 00:12:23.250028" 2026-02-22 00:12:48.079280 | controller | } failure 2026-02-22 00:12:48.081382 | 2026-02-22 00:12:48.081467 | PLAY RECAP 2026-02-22 00:12:48.081546 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-22 00:12:48.081589 | 2026-02-22 00:12:48.228975 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-22 00:12:48.230304 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-22 00:12:48.894865 | 2026-02-22 00:12:48.895016 | PLAY [all] 2026-02-22 00:12:48.923247 | 2026-02-22 00:12:48.923384 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-22 00:12:49.183634 | controller | changed: non-zero return code 2026-02-22 00:12:49.192012 | 2026-02-22 00:12:49.192121 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-22 00:12:49.217487 | controller | skipping: Conditional result was False 2026-02-22 00:12:49.228432 | 2026-02-22 00:12:49.228563 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-22 00:12:49.267194 | 2026-02-22 00:12:49.267427 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-22 00:12:49.294693 | 2026-02-22 00:12:49.294946 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-22 00:12:49.310145 | controller | skipping: Conditional result was False 2026-02-22 00:12:49.321588 | 2026-02-22 00:12:49.321717 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-22 00:12:49.347223 | 2026-02-22 00:12:49.347401 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-22 00:12:49.361828 | controller | skipping: Conditional result was False 2026-02-22 00:12:49.370451 | 2026-02-22 00:12:49.370547 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-22 00:12:49.385135 | controller | skipping: Conditional result was False 2026-02-22 00:12:49.394645 | 2026-02-22 00:12:49.394822 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-22 00:12:49.409873 | controller | skipping: Conditional result was False 2026-02-22 00:12:49.451557 | 2026-02-22 00:12:49.451648 | PLAY RECAP 2026-02-22 00:12:49.451690 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-22 00:12:49.451711 | 2026-02-22 00:12:49.554927 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-22 00:12:49.556016 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-22 00:12:50.152617 | 2026-02-22 00:12:50.152778 | PLAY [all:!appliance*] 2026-02-22 00:12:50.176695 | 2026-02-22 00:12:50.176863 | TASK [unregister the node] 2026-02-22 00:12:50.713621 | controller | skipping: Conditional result was False 2026-02-22 00:12:50.721185 | 2026-02-22 00:12:50.721335 | TASK [include_role : fetch-output] 2026-02-22 00:12:50.763032 | controller | ok 2026-02-22 00:12:50.784374 | 2026-02-22 00:12:50.784490 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-22 00:12:50.849926 | controller | skipping: Conditional result was False 2026-02-22 00:12:50.859789 | 2026-02-22 00:12:50.859929 | TASK [fetch-output : Set log path for single node] 2026-02-22 00:12:50.894182 | controller | ok 2026-02-22 00:12:50.900000 | 2026-02-22 00:12:50.900076 | LOOP [fetch-output : Ensure local output dirs] 2026-02-22 00:12:51.320675 | controller -> localhost | ok: "/var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/logs" 2026-02-22 00:12:51.583922 | controller -> localhost | changed: "/var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/artifacts" 2026-02-22 00:12:51.806065 | controller -> localhost | changed: "/var/lib/zuul/builds/4c989de5d40347638d36784f57291544/work/docs" 2026-02-22 00:12:51.830753 | 2026-02-22 00:12:51.830939 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-22 00:12:52.594280 | controller | changed: 2026-02-22 00:12:52.594615 | controller | .d..t...... ./ 2026-02-22 00:12:52.594675 | controller | cd+++++++++ controller/ 2026-02-22 00:12:52.594776 | controller | changed: All items complete 2026-02-22 00:12:52.594830 | 2026-02-22 00:12:53.066123 | controller | changed: .d..t...... ./ 2026-02-22 00:12:53.527888 | controller | changed: .d..t...... ./ 2026-02-22 00:12:53.566051 | 2026-02-22 00:12:53.566289 | TASK [include_role : fetch-output-openshift] 2026-02-22 00:12:53.584411 | controller | skipping: Conditional result was False 2026-02-22 00:12:53.594429 | 2026-02-22 00:12:53.594562 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-22 00:12:53.633993 | controller | skipping: Conditional result was False 2026-02-22 00:12:53.648147 | controller | skipping: Conditional result was False 2026-02-22 00:12:53.692353 | 2026-02-22 00:12:53.692474 | PLAY [localhost] 2026-02-22 00:12:53.710058 | 2026-02-22 00:12:53.710166 | TASK [Run Zuul manifest role] 2026-02-22 00:12:53.734048 | localhost | ok 2026-02-22 00:12:53.754107 | 2026-02-22 00:12:53.754215 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-22 00:12:54.192132 | localhost | changed 2026-02-22 00:12:54.197059 | 2026-02-22 00:12:54.197139 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-22 00:12:54.228399 | localhost | ok 2026-02-22 00:12:54.240864 | 2026-02-22 00:12:54.240962 | TASK [Set zuul-log-path fact] 2026-02-22 00:12:54.262272 | localhost | ok 2026-02-22 00:12:54.282703 | 2026-02-22 00:12:54.282849 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-22 00:12:54.313285 | localhost | ok 2026-02-22 00:12:54.323825 | 2026-02-22 00:12:54.323907 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-02-22 00:12:54.357542 | localhost | ok: 2026-02-22 00:12:54.357852 | localhost | { 2026-02-22 00:12:54.357891 | localhost | "auth": { 2026-02-22 00:12:54.357928 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-02-22 00:12:54.357955 | localhost | "username": "9LF91O0RK7JU" 2026-02-22 00:12:54.357980 | localhost | }, 2026-02-22 00:12:54.358004 | localhost | "profile": "rackspace", 2026-02-22 00:12:54.358026 | localhost | "project_name": "1251317", 2026-02-22 00:12:54.358049 | localhost | "region_name": "DFW" 2026-02-22 00:12:54.358072 | localhost | } 2026-02-22 00:12:54.358110 | 2026-02-22 00:12:54.376267 | 2026-02-22 00:12:54.376383 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-02-22 00:12:54.397925 | localhost | Output suppressed because no_log was given 2026-02-22 00:12:54.415851 | 2026-02-22 00:12:54.415947 | TASK [upload-logs-failover : Initialize control vars] 2026-02-22 00:12:54.437369 | localhost | ok 2026-02-22 00:12:54.443627 | 2026-02-22 00:12:54.443714 | LOOP [upload-logs-failover : Perform log upload] 2026-02-22 00:12:54.533290 | localhost | Output suppressed because no_log was given 2026-02-22 00:12:54.542381 | localhost | included: /var/lib/zuul/builds/4c989de5d40347638d36784f57291544/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-02-22 00:12:54.551039 | 2026-02-22 00:12:54.551133 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-02-22 00:12:54.628386 | localhost | Output suppressed because no_log was given 2026-02-22 00:12:54.635696 | 2026-02-22 00:12:54.635844 | TASK [Upload logs to swift] 2026-02-22 00:12:54.656984 | localhost | ok 2026-02-22 00:12:54.693838 | 2026-02-22 00:12:54.693984 | TASK [Set zuul-log-path fact] 2026-02-22 00:12:54.719655 | localhost | skipping: Conditional result was False 2026-02-22 00:12:54.727114 | 2026-02-22 00:12:54.727265 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-22 00:12:55.120065 | localhost -> localhost | ok: Runtime: 0:00:00.005738 2026-02-22 00:12:55.126371 | 2026-02-22 00:12:55.126502 | TASK [upload-logs-swift : Upload logs to swift]