2026-02-15 00:33:50.966714 | Job console starting... 2026-02-15 00:33:50.978844 | Updating repositories 2026-02-15 00:33:51.101252 | Preparing job workspace 2026-02-15 00:33:54.977893 | Running Ansible setup... 2026-02-15 00:34:00.984415 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-15 00:34:01.604055 | 2026-02-15 00:34:01.604176 | PLAY [localhost] 2026-02-15 00:34:01.612329 | 2026-02-15 00:34:01.612409 | TASK [Gathering Facts] 2026-02-15 00:34:02.710423 | localhost | ok 2026-02-15 00:34:02.733448 | 2026-02-15 00:34:02.733723 | TASK [Setup log path fact] 2026-02-15 00:34:02.753042 | localhost | ok 2026-02-15 00:34:02.772359 | 2026-02-15 00:34:02.772519 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-15 00:34:02.810857 | localhost | ok 2026-02-15 00:34:02.818971 | 2026-02-15 00:34:02.819052 | TASK [emit-job-header : Print job information] 2026-02-15 00:34:02.856929 | # Job Information 2026-02-15 00:34:02.857087 | Ansible Version: 2.15.12 2026-02-15 00:34:02.857142 | Job: ansible-test-sanity-docker-milestone 2026-02-15 00:34:02.857183 | Pipeline: periodic 2026-02-15 00:34:02.857209 | Executor: ze02.softwarefactory-project.io 2026-02-15 00:34:02.857235 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-15 00:34:02.857267 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/605/ansible/60555fd77fbe431bbbedcd37492facde/ 2026-02-15 00:34:02.857291 | Event ID: bfcfc7f67e194cfab2f082a1d8ce3d78 2026-02-15 00:34:02.861151 | 2026-02-15 00:34:02.861217 | LOOP [emit-job-header : Print node information] 2026-02-15 00:34:02.970963 | localhost | ok: 2026-02-15 00:34:02.971249 | localhost | # Node Information 2026-02-15 00:34:02.971310 | localhost | Inventory Hostname: controller 2026-02-15 00:34:02.971354 | localhost | Hostname: np0005620040 2026-02-15 00:34:02.971396 | localhost | Username: zuul 2026-02-15 00:34:02.971441 | localhost | Distro: Fedora 37 2026-02-15 00:34:02.971482 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-15 00:34:02.971812 | localhost | Region: ca-ymq-1 2026-02-15 00:34:02.971869 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-15 00:34:02.971910 | localhost | Product Name: OpenStack Nova 2026-02-15 00:34:02.971948 | localhost | Interface IP: 162.253.55.62 2026-02-15 00:34:02.992530 | 2026-02-15 00:34:02.992792 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-15 00:34:03.447464 | localhost -> localhost | changed 2026-02-15 00:34:03.452748 | 2026-02-15 00:34:03.452822 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-15 00:34:04.387649 | localhost -> localhost | changed 2026-02-15 00:34:04.407626 | 2026-02-15 00:34:04.407720 | PLAY [all:!appliance*] 2026-02-15 00:34:04.427357 | 2026-02-15 00:34:04.427456 | TASK [include_role : start-zuul-console] 2026-02-15 00:34:04.449969 | controller | ok 2026-02-15 00:34:04.469219 | 2026-02-15 00:34:04.469331 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-15 00:34:04.855596 | controller | ok 2026-02-15 00:34:04.871815 | 2026-02-15 00:34:04.871990 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-15 00:34:05.846511 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-15 00:34:05.861272 | 2026-02-15 00:34:05.861419 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-15 00:34:06.411261 | controller | skipping: Conditional result was False 2026-02-15 00:34:06.431530 | 2026-02-15 00:34:06.431973 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-15 00:34:06.460617 | controller | skipping: Conditional result was False 2026-02-15 00:34:06.476876 | 2026-02-15 00:34:06.477047 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-15 00:34:06.505070 | controller | skipping: Conditional result was False 2026-02-15 00:34:06.519906 | 2026-02-15 00:34:06.520071 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-15 00:34:06.547598 | controller | skipping: Conditional result was False 2026-02-15 00:34:06.561933 | 2026-02-15 00:34:06.562100 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-15 00:34:06.599943 | controller | skipping: Conditional result was False 2026-02-15 00:34:06.614098 | 2026-02-15 00:34:06.614243 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-15 00:34:06.651544 | controller | skipping: Conditional result was False 2026-02-15 00:34:06.664073 | 2026-02-15 00:34:06.664159 | TASK [Disable Fedora Modular] 2026-02-15 00:34:06.915485 | controller | changed 2026-02-15 00:34:06.929011 | 2026-02-15 00:34:06.929147 | TASK [Enable EPEL] 2026-02-15 00:34:06.957108 | controller | skipping: Conditional result was False 2026-02-15 00:34:06.973562 | 2026-02-15 00:34:06.973775 | TASK [Register the RHEL node] 2026-02-15 00:34:07.531747 | 2026-02-15 00:34:07.532033 | TASK [Show the subscription-manager status] 2026-02-15 00:34:08.109629 | controller | skipping: Conditional result was False 2026-02-15 00:34:08.124252 | 2026-02-15 00:34:08.124393 | TASK [Enable EPEL on RHEL] 2026-02-15 00:34:08.688359 | controller | skipping: Conditional result was False 2026-02-15 00:34:08.701275 | 2026-02-15 00:34:08.701415 | TASK [Install git and tox] 2026-02-15 00:35:29.497779 | controller | changed 2026-02-15 00:35:29.506652 | 2026-02-15 00:35:29.506804 | TASK [include_role : prepare-workspace] 2026-02-15 00:35:29.526391 | controller | ok 2026-02-15 00:35:29.548474 | 2026-02-15 00:35:29.548537 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-15 00:35:29.770571 | controller | ok 2026-02-15 00:35:29.776804 | 2026-02-15 00:35:29.776870 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-15 00:35:43.463087 | controller | Output suppressed because no_log was given 2026-02-15 00:35:43.502289 | 2026-02-15 00:35:43.502732 | TASK [include_role : prepare-workspace-openshift] 2026-02-15 00:35:43.528158 | controller | skipping: Conditional result was False 2026-02-15 00:35:43.550950 | 2026-02-15 00:35:43.551014 | PLAY [all:!appliance] 2026-02-15 00:35:43.567524 | 2026-02-15 00:35:43.567607 | TASK [Run add-build-sshkey role (RSA)] 2026-02-15 00:35:43.597963 | controller | ok 2026-02-15 00:35:43.613459 | 2026-02-15 00:35:43.613532 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-15 00:35:43.824115 | controller -> localhost | ok 2026-02-15 00:35:43.835616 | 2026-02-15 00:35:43.835915 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-15 00:35:43.868989 | controller | ok 2026-02-15 00:35:43.884586 | controller | included: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-15 00:35:43.891530 | 2026-02-15 00:35:43.891596 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-15 00:35:44.384163 | controller -> localhost | Generating public/private rsa key pair. 2026-02-15 00:35:44.384421 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/60555fd77fbe431bbbedcd37492facde_id_rsa. 2026-02-15 00:35:44.384451 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/60555fd77fbe431bbbedcd37492facde_id_rsa.pub. 2026-02-15 00:35:44.384472 | controller -> localhost | The key fingerprint is: 2026-02-15 00:35:44.384495 | controller -> localhost | SHA256:oMPPaz76uOPHIEqtz5mTLQgOi9Rk7GSVVrEzhTaJNdQ zuul-build-sshkey 2026-02-15 00:35:44.384516 | controller -> localhost | The key's randomart image is: 2026-02-15 00:35:44.384535 | controller -> localhost | +---[RSA 2048]----+ 2026-02-15 00:35:44.384554 | controller -> localhost | | **=. | 2026-02-15 00:35:44.384573 | controller -> localhost | | = =+E | 2026-02-15 00:35:44.384591 | controller -> localhost | | . o o+. | 2026-02-15 00:35:44.384608 | controller -> localhost | | B . .o | 2026-02-15 00:35:44.384625 | controller -> localhost | | O + S | 2026-02-15 00:35:44.384656 | controller -> localhost | |oo.+.+ | 2026-02-15 00:35:44.384702 | controller -> localhost | |Boo.ooo | 2026-02-15 00:35:44.384726 | controller -> localhost | |++.++o=. | 2026-02-15 00:35:44.384745 | controller -> localhost | | .*BO+. | 2026-02-15 00:35:44.384766 | controller -> localhost | +----[SHA256]-----+ 2026-02-15 00:35:44.384817 | controller -> localhost | ok: Runtime: 0:00:00.123753 2026-02-15 00:35:44.392024 | 2026-02-15 00:35:44.392087 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-15 00:35:44.423652 | controller | ok 2026-02-15 00:35:44.433645 | controller | included: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-15 00:35:44.442306 | 2026-02-15 00:35:44.442369 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-15 00:35:44.466808 | controller | skipping: Conditional result was False 2026-02-15 00:35:44.473848 | 2026-02-15 00:35:44.473914 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-15 00:35:44.901460 | controller | changed 2026-02-15 00:35:44.908412 | 2026-02-15 00:35:44.908480 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-15 00:35:45.156961 | controller | ok 2026-02-15 00:35:45.171080 | 2026-02-15 00:35:45.171231 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-15 00:35:45.829352 | controller | changed 2026-02-15 00:35:45.842563 | 2026-02-15 00:35:45.842752 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-15 00:35:46.483568 | controller | changed 2026-02-15 00:35:46.502287 | 2026-02-15 00:35:46.502491 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-15 00:35:46.528708 | controller | skipping: Conditional result was False 2026-02-15 00:35:46.541786 | 2026-02-15 00:35:46.541890 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-15 00:35:47.020815 | controller -> localhost | changed 2026-02-15 00:35:47.033617 | 2026-02-15 00:35:47.033719 | TASK [add-build-sshkey : Add back temp key] 2026-02-15 00:35:47.408800 | controller -> localhost | Identity added: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/60555fd77fbe431bbbedcd37492facde_id_rsa (zuul-build-sshkey) 2026-02-15 00:35:47.409154 | controller -> localhost | ok: Runtime: 0:00:00.026026 2026-02-15 00:35:47.416334 | 2026-02-15 00:35:47.416401 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-15 00:35:47.827210 | controller | ok 2026-02-15 00:35:47.839706 | 2026-02-15 00:35:47.839851 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-15 00:35:47.879117 | controller | skipping: Conditional result was False 2026-02-15 00:35:47.910226 | 2026-02-15 00:35:47.910705 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-15 00:35:47.978501 | controller | ok 2026-02-15 00:35:48.000506 | 2026-02-15 00:35:48.000612 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-15 00:35:48.240904 | controller -> localhost | ok 2026-02-15 00:35:48.255364 | 2026-02-15 00:35:48.255510 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-15 00:35:48.295214 | controller | ok 2026-02-15 00:35:48.320175 | controller | included: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-15 00:35:48.329065 | 2026-02-15 00:35:48.329159 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-15 00:35:48.672378 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-15 00:35:48.672737 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/60555fd77fbe431bbbedcd37492facde_id_ecdsa. 2026-02-15 00:35:48.672807 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/60555fd77fbe431bbbedcd37492facde_id_ecdsa.pub. 2026-02-15 00:35:48.672869 | controller -> localhost | The key fingerprint is: 2026-02-15 00:35:48.672914 | controller -> localhost | SHA256:4QI3OUL97CPD2xRU0WIrqEC7rULufaevRZUA405sf5Y zuul-build-sshkey 2026-02-15 00:35:48.672955 | controller -> localhost | The key's randomart image is: 2026-02-15 00:35:48.672997 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-15 00:35:48.673037 | controller -> localhost | | .+.. .oo | 2026-02-15 00:35:48.673075 | controller -> localhost | | ..o o.o + . | 2026-02-15 00:35:48.673113 | controller -> localhost | | . .o===.+ o | 2026-02-15 00:35:48.673151 | controller -> localhost | | o ++o+*.o | 2026-02-15 00:35:48.673188 | controller -> localhost | | + +.+SE | 2026-02-15 00:35:48.673226 | controller -> localhost | | .. o =.* | 2026-02-15 00:35:48.673263 | controller -> localhost | |o . B . | 2026-02-15 00:35:48.673300 | controller -> localhost | |..o .o.. | 2026-02-15 00:35:48.673336 | controller -> localhost | |.o ..o=. | 2026-02-15 00:35:48.673373 | controller -> localhost | +----[SHA256]-----+ 2026-02-15 00:35:48.673483 | controller -> localhost | ok: Runtime: 0:00:00.017199 2026-02-15 00:35:48.688120 | 2026-02-15 00:35:48.688259 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-15 00:35:48.729023 | controller | ok 2026-02-15 00:35:48.745795 | controller | included: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-15 00:35:48.760636 | 2026-02-15 00:35:48.760749 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-15 00:35:48.796311 | controller | skipping: Conditional result was False 2026-02-15 00:35:48.811434 | 2026-02-15 00:35:48.811579 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-15 00:35:49.094946 | controller | changed 2026-02-15 00:35:49.108995 | 2026-02-15 00:35:49.109142 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-15 00:35:49.369429 | controller | ok 2026-02-15 00:35:49.388579 | 2026-02-15 00:35:49.388694 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-15 00:35:50.058829 | controller | changed 2026-02-15 00:35:50.077326 | 2026-02-15 00:35:50.077491 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-15 00:35:50.668620 | controller | changed 2026-02-15 00:35:50.682912 | 2026-02-15 00:35:50.683058 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-15 00:35:50.721859 | controller | skipping: Conditional result was False 2026-02-15 00:35:50.793795 | 2026-02-15 00:35:50.793985 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-15 00:35:51.104099 | controller -> localhost | changed 2026-02-15 00:35:51.116413 | 2026-02-15 00:35:51.116485 | TASK [add-build-sshkey : Add back temp key] 2026-02-15 00:35:51.468296 | controller -> localhost | Identity added: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/60555fd77fbe431bbbedcd37492facde_id_ecdsa (zuul-build-sshkey) 2026-02-15 00:35:51.468888 | controller -> localhost | ok: Runtime: 0:00:00.015075 2026-02-15 00:35:51.483505 | 2026-02-15 00:35:51.483640 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-15 00:35:51.709798 | controller | ok 2026-02-15 00:35:51.725026 | 2026-02-15 00:35:51.725168 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-15 00:35:51.763328 | controller | skipping: Conditional result was False 2026-02-15 00:35:51.790269 | 2026-02-15 00:35:51.790421 | TASK [include_role : remove-zuul-sshkey] 2026-02-15 00:35:51.817987 | controller | skipping: Conditional result was False 2026-02-15 00:35:51.831757 | 2026-02-15 00:35:51.831896 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-15 00:35:52.106336 | controller | ok: "logs" 2026-02-15 00:35:52.107140 | controller | ok: All items complete 2026-02-15 00:35:52.107223 | 2026-02-15 00:35:52.315659 | controller | ok: "artifacts" 2026-02-15 00:35:52.529974 | controller | ok: "docs" 2026-02-15 00:35:52.553715 | 2026-02-15 00:35:52.553973 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-15 00:35:52.826190 | controller | changed: "logs" 2026-02-15 00:35:53.030320 | controller | changed: "artifacts" 2026-02-15 00:35:53.231245 | controller | changed: "docs" 2026-02-15 00:35:53.302937 | 2026-02-15 00:35:53.303123 | PLAY RECAP 2026-02-15 00:35:53.303194 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-15 00:35:53.303231 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-15 00:35:53.303256 | 2026-02-15 00:35:53.512393 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-15 00:35:53.514372 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-15 00:35:54.153002 | 2026-02-15 00:35:54.153121 | PLAY [all] 2026-02-15 00:35:54.176367 | 2026-02-15 00:35:54.176477 | TASK [Install binary dependencies] 2026-02-15 00:35:54.254346 | controller | ok 2026-02-15 00:35:54.290033 | 2026-02-15 00:35:54.290190 | TASK [bindep : Include find tasks] 2026-02-15 00:35:54.338582 | controller | ok 2026-02-15 00:35:54.347865 | controller | included: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-15 00:35:54.355901 | 2026-02-15 00:35:54.355981 | TASK [bindep : Look for bindep.txt] 2026-02-15 00:35:54.785154 | controller | ok 2026-02-15 00:35:54.798268 | 2026-02-15 00:35:54.798422 | TASK [bindep : Define bindep_file fact] 2026-02-15 00:35:54.827014 | controller | skipping: Conditional result was False 2026-02-15 00:35:54.841544 | 2026-02-15 00:35:54.841723 | TASK [bindep : Look for other-requirements.txt] 2026-02-15 00:35:55.055963 | controller | ok 2026-02-15 00:35:55.069225 | 2026-02-15 00:35:55.069523 | TASK [bindep : Define bindep_file fact] 2026-02-15 00:35:55.097769 | controller | skipping: Conditional result was False 2026-02-15 00:35:55.112032 | 2026-02-15 00:35:55.112195 | TASK [bindep : Look for bindep fallback file] 2026-02-15 00:35:55.150949 | controller | skipping: Conditional result was False 2026-02-15 00:35:55.168399 | 2026-02-15 00:35:55.168561 | TASK [bindep : Define bindep_file fact] 2026-02-15 00:35:55.198315 | controller | skipping: Conditional result was False 2026-02-15 00:35:55.218848 | 2026-02-15 00:35:55.219090 | TASK [bindep : Include bindep tasks] 2026-02-15 00:35:55.260027 | controller | skipping: Conditional result was False 2026-02-15 00:35:55.276172 | 2026-02-15 00:35:55.276371 | TASK [bindep : Include install tasks] 2026-02-15 00:35:55.317158 | controller | skipping: Conditional result was False 2026-02-15 00:35:55.332838 | 2026-02-15 00:35:55.332992 | LOOP [bindep : Include package tasks] 2026-02-15 00:35:55.413302 | 2026-02-15 00:35:55.413522 | TASK [Run test-setup role] 2026-02-15 00:35:55.437730 | controller | ok 2026-02-15 00:35:55.457240 | 2026-02-15 00:35:55.457354 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-15 00:35:55.679988 | controller | ok 2026-02-15 00:35:55.694486 | 2026-02-15 00:35:55.694623 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-15 00:35:56.247393 | controller | skipping: Conditional result was False 2026-02-15 00:35:56.303233 | 2026-02-15 00:35:56.303320 | PLAY RECAP 2026-02-15 00:35:56.303380 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-15 00:35:56.303408 | 2026-02-15 00:35:56.431229 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-15 00:35:56.432126 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-15 00:35:57.029195 | 2026-02-15 00:35:57.029332 | PLAY [controller] 2026-02-15 00:35:57.049323 | 2026-02-15 00:35:57.049410 | TASK [Create the /root directory] 2026-02-15 00:35:57.455029 | controller | ok 2026-02-15 00:35:57.468474 | 2026-02-15 00:35:57.468631 | TASK [Install glibc-langpack-en] 2026-02-15 00:36:01.357338 | controller | ok: Nothing to do 2026-02-15 00:36:01.372107 | 2026-02-15 00:36:01.372194 | TASK [Ensure controller directory exists] 2026-02-15 00:36:01.576428 | controller | changed 2026-02-15 00:36:01.584244 | 2026-02-15 00:36:01.584327 | TASK [Install container runtime] 2026-02-15 00:36:01.657249 | controller | ok 2026-02-15 00:36:01.703328 | 2026-02-15 00:36:01.703478 | LOOP [ensure-podman : Find distribution installation] 2026-02-15 00:36:01.737496 | controller | ok: "/var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-15 00:36:01.745045 | controller | included: /var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-15 00:36:01.751352 | 2026-02-15 00:36:01.751417 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-15 00:37:06.871856 | controller | changed 2026-02-15 00:37:06.881267 | 2026-02-15 00:37:06.881353 | TASK [ensure-podman : Fetch podman version] 2026-02-15 00:37:07.967591 | controller | Client: Podman Engine 2026-02-15 00:37:07.992958 | controller | Version: 4.6.2 2026-02-15 00:37:07.993000 | controller | API Version: 4.6.2 2026-02-15 00:37:07.993008 | controller | Go Version: go1.19.12 2026-02-15 00:37:07.993027 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-15 00:37:07.993035 | controller | OS/Arch: linux/amd64 2026-02-15 00:37:08.149230 | controller | ok: Runtime: 0:00:00.188183 2026-02-15 00:37:08.157734 | 2026-02-15 00:37:08.157823 | TASK [ensure-podman : Print podman version installed] 2026-02-15 00:37:08.191018 | Podman version: Client: Podman Engine 2026-02-15 00:37:08.191167 | Version: 4.6.2 2026-02-15 00:37:08.191205 | API Version: 4.6.2 2026-02-15 00:37:08.191232 | Go Version: go1.19.12 2026-02-15 00:37:08.191277 | Built: Mon Aug 28 19:38:31 2023 2026-02-15 00:37:08.191307 | OS/Arch: linux/amd64 2026-02-15 00:37:08.198575 | 2026-02-15 00:37:08.198657 | TASK [ensure-podman : Validate podman engine] 2026-02-15 00:37:08.742131 | controller | skipping: Conditional result was False 2026-02-15 00:37:08.757316 | 2026-02-15 00:37:08.757469 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-15 00:37:08.788487 | controller | skipping: Conditional result was False 2026-02-15 00:37:08.815879 | 2026-02-15 00:37:08.816306 | TASK [Ensure python3.8 is present] 2026-02-15 00:37:08.845156 | controller | skipping: Conditional result was False 2026-02-15 00:37:08.854444 | 2026-02-15 00:37:08.854534 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-15 00:37:08.878793 | controller | ok 2026-02-15 00:37:08.910857 | 2026-02-15 00:37:08.910992 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-15 00:37:10.210376 | controller | ok: Nothing to do 2026-02-15 00:37:10.224500 | 2026-02-15 00:37:10.224643 | TASK [our-ensure-python : Also install python3-devel] 2026-02-15 00:37:19.647235 | controller | changed 2026-02-15 00:37:19.675711 | 2026-02-15 00:37:19.675915 | TASK [Run ensure-virtualenv role] 2026-02-15 00:37:19.712379 | controller | ok 2026-02-15 00:37:19.743198 | 2026-02-15 00:37:19.743305 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-15 00:37:20.003823 | controller | /usr/bin/virtualenv 2026-02-15 00:37:20.319042 | controller | ok: Runtime: 0:00:00.005568 2026-02-15 00:37:20.332544 | 2026-02-15 00:37:20.332778 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-15 00:37:20.368815 | controller | skipping: Conditional result was False 2026-02-15 00:37:20.369648 | controller | ok: All items complete 2026-02-15 00:37:20.369821 | 2026-02-15 00:37:20.400087 | 2026-02-15 00:37:20.400318 | TASK [Find the full path of the Python interpreter] 2026-02-15 00:37:20.649797 | controller | /usr/bin/python3 2026-02-15 00:37:20.960385 | controller | ok 2026-02-15 00:37:20.973039 | 2026-02-15 00:37:20.973175 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-15 00:37:21.861326 | controller | created virtual environment CPython3.11.0.final.0-64 in 533ms 2026-02-15 00:37:21.893566 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-15 00:37:21.893617 | 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-15 00:37:21.893630 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-15 00:37:21.893643 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-15 00:37:22.030783 | controller | changed 2026-02-15 00:37:22.044827 | 2026-02-15 00:37:22.044961 | TASK [Set selinux package] 2026-02-15 00:37:22.084580 | controller | ok 2026-02-15 00:37:22.095854 | 2026-02-15 00:37:22.095987 | TASK [Set selinux package (Fedora)] 2026-02-15 00:37:22.157628 | controller | ok 2026-02-15 00:37:22.170064 | 2026-02-15 00:37:22.170198 | TASK [Install selinux into virtualenv] 2026-02-15 00:37:35.720967 | controller | Collecting selinux-please-lie-to-me 2026-02-15 00:37:47.975941 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-15 00:37:48.279250 | controller | Collecting setuptools<50.0.0 2026-02-15 00:37:48.285352 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-15 00:37:48.321754 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.9 MB/s eta 0:00:00 2026-02-15 00:37:48.400477 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-15 00:37:48.400701 | controller | Attempting uninstall: setuptools 2026-02-15 00:37:48.403045 | controller | Found existing installation: setuptools 62.6.0 2026-02-15 00:37:48.461649 | controller | Uninstalling setuptools-62.6.0: 2026-02-15 00:37:48.469337 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-15 00:37:48.824680 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-15 00:38:00.345954 | controller | 2026-02-15 00:38:00.430629 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-15 00:38:00.430666 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-15 00:38:00.743865 | controller | ok: Runtime: 0:00:38.023215 2026-02-15 00:38:00.758137 | 2026-02-15 00:38:00.758272 | TASK [Install pytest-forked into virtualenv] 2026-02-15 00:38:12.599899 | controller | Collecting pytest-forked 2026-02-15 00:38:24.838301 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-15 00:38:24.887251 | controller | Collecting py 2026-02-15 00:38:24.892390 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-15 00:38:24.911972 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.5 MB/s eta 0:00:00 2026-02-15 00:38:25.020284 | controller | Collecting pytest>=3.10 2026-02-15 00:38:25.027004 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-15 00:38:25.041547 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 31.8 MB/s eta 0:00:00 2026-02-15 00:38:25.083217 | controller | Collecting iniconfig>=1.0.1 2026-02-15 00:38:25.086754 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-15 00:38:25.135406 | controller | Collecting packaging>=22 2026-02-15 00:38:25.139519 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-15 00:38:25.147170 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 11.4 MB/s eta 0:00:00 2026-02-15 00:38:25.176650 | controller | Collecting pluggy<2,>=1.5 2026-02-15 00:38:25.181091 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-15 00:38:25.225185 | controller | Collecting pygments>=2.7.2 2026-02-15 00:38:25.228344 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-15 00:38:25.251698 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 64.6 MB/s eta 0:00:00 2026-02-15 00:38:25.316111 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-15 00:38:26.340412 | 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-15 00:38:26.349048 | controller | 2026-02-15 00:38:26.414075 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-15 00:38:26.414106 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-15 00:38:26.841978 | controller | ok: Runtime: 0:00:25.423298 2026-02-15 00:38:26.855465 | 2026-02-15 00:38:26.855607 | TASK [Update pip] 2026-02-15 00:38:27.601055 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-15 00:38:37.219733 | controller | Collecting pip 2026-02-15 00:38:49.414882 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-15 00:38:49.463208 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 41.9 MB/s eta 0:00:00 2026-02-15 00:38:49.526212 | controller | Installing collected packages: pip 2026-02-15 00:38:49.526364 | controller | Attempting uninstall: pip 2026-02-15 00:38:49.528459 | controller | Found existing installation: pip 22.2.2 2026-02-15 00:38:49.662083 | controller | Uninstalling pip-22.2.2: 2026-02-15 00:38:49.676719 | controller | Successfully uninstalled pip-22.2.2 2026-02-15 00:38:50.479364 | controller | Successfully installed pip-26.0.1 2026-02-15 00:38:50.670770 | controller | ok: Runtime: 0:00:23.241037 2026-02-15 00:38:50.685365 | 2026-02-15 00:38:50.685512 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-15 00:38:50.923082 | controller | changed 2026-02-15 00:38:50.935851 | 2026-02-15 00:38:50.936010 | TASK [Install ansible into virtualenv] 2026-02-15 00:38:51.505367 | controller | Processing ./src/github.com/ansible/ansible 2026-02-15 00:38:51.507903 | controller | Installing build dependencies: started 2026-02-15 00:39:14.339984 | controller | Installing build dependencies: finished with status 'done' 2026-02-15 00:39:14.340628 | controller | Getting requirements to build wheel: started 2026-02-15 00:39:15.072245 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-15 00:39:15.073442 | controller | Preparing metadata (pyproject.toml): started 2026-02-15 00:39:15.529246 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-15 00:39:15.534459 | 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-15 00:39:15.538582 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-15 00:39:16.031270 | controller | ERROR 2026-02-15 00:39:16.031661 | controller | { 2026-02-15 00:39:16.031761 | controller | "delta": "0:00:24.391837", 2026-02-15 00:39:16.031805 | controller | "end": "2026-02-15 00:39:15.606129", 2026-02-15 00:39:16.031858 | controller | "msg": "non-zero return code", 2026-02-15 00:39:16.031927 | controller | "rc": 1, 2026-02-15 00:39:16.031975 | controller | "start": "2026-02-15 00:38:51.214292" 2026-02-15 00:39:16.032015 | controller | } failure 2026-02-15 00:39:16.035604 | 2026-02-15 00:39:16.035765 | PLAY RECAP 2026-02-15 00:39:16.035857 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-15 00:39:16.035899 | 2026-02-15 00:39:16.210542 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-15 00:39:16.212902 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-15 00:39:16.829995 | 2026-02-15 00:39:16.830127 | PLAY [all] 2026-02-15 00:39:16.851317 | 2026-02-15 00:39:16.851399 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-15 00:39:17.138179 | controller | changed: non-zero return code 2026-02-15 00:39:17.151517 | 2026-02-15 00:39:17.151781 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-15 00:39:17.180474 | controller | skipping: Conditional result was False 2026-02-15 00:39:17.188555 | 2026-02-15 00:39:17.188651 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-15 00:39:17.222781 | 2026-02-15 00:39:17.222948 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-15 00:39:17.256984 | 2026-02-15 00:39:17.257149 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-15 00:39:17.282400 | controller | skipping: Conditional result was False 2026-02-15 00:39:17.291951 | 2026-02-15 00:39:17.292045 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-15 00:39:17.325548 | 2026-02-15 00:39:17.325733 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-15 00:39:17.350967 | controller | skipping: Conditional result was False 2026-02-15 00:39:17.360348 | 2026-02-15 00:39:17.360443 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-15 00:39:17.386346 | controller | skipping: Conditional result was False 2026-02-15 00:39:17.394701 | 2026-02-15 00:39:17.394790 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-15 00:39:17.419784 | controller | skipping: Conditional result was False 2026-02-15 00:39:17.455309 | 2026-02-15 00:39:17.455388 | PLAY RECAP 2026-02-15 00:39:17.455448 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-15 00:39:17.455475 | 2026-02-15 00:39:17.561787 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-15 00:39:17.562750 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-15 00:39:18.195556 | 2026-02-15 00:39:18.195771 | PLAY [all:!appliance*] 2026-02-15 00:39:18.227950 | 2026-02-15 00:39:18.228057 | TASK [unregister the node] 2026-02-15 00:39:18.759187 | controller | skipping: Conditional result was False 2026-02-15 00:39:18.771939 | 2026-02-15 00:39:18.772108 | TASK [include_role : fetch-output] 2026-02-15 00:39:18.831845 | controller | ok 2026-02-15 00:39:18.865961 | 2026-02-15 00:39:18.866067 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-15 00:39:18.942482 | controller | skipping: Conditional result was False 2026-02-15 00:39:18.955657 | 2026-02-15 00:39:18.955834 | TASK [fetch-output : Set log path for single node] 2026-02-15 00:39:19.010871 | controller | ok 2026-02-15 00:39:19.027162 | 2026-02-15 00:39:19.027238 | LOOP [fetch-output : Ensure local output dirs] 2026-02-15 00:39:19.413743 | controller -> localhost | ok: "/var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/logs" 2026-02-15 00:39:19.703124 | controller -> localhost | changed: "/var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/artifacts" 2026-02-15 00:39:19.953693 | controller -> localhost | changed: "/var/lib/zuul/builds/60555fd77fbe431bbbedcd37492facde/work/docs" 2026-02-15 00:39:19.965998 | 2026-02-15 00:39:19.966113 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-15 00:39:20.691332 | controller | changed: 2026-02-15 00:39:20.691994 | controller | .d..t...... ./ 2026-02-15 00:39:20.692121 | controller | cd+++++++++ controller/ 2026-02-15 00:39:20.692224 | controller | changed: All items complete 2026-02-15 00:39:20.692275 | 2026-02-15 00:39:21.159156 | controller | changed: .d..t...... ./ 2026-02-15 00:39:21.654017 | controller | changed: .d..t...... ./ 2026-02-15 00:39:21.681734 | 2026-02-15 00:39:21.681903 | TASK [include_role : fetch-output-openshift] 2026-02-15 00:39:21.707198 | controller | skipping: Conditional result was False 2026-02-15 00:39:21.716914 | 2026-02-15 00:39:21.717026 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-15 00:39:21.756318 | controller | skipping: Conditional result was False 2026-02-15 00:39:21.771133 | controller | skipping: Conditional result was False 2026-02-15 00:39:21.812608 | 2026-02-15 00:39:21.812822 | PLAY [localhost] 2026-02-15 00:39:21.824827 | 2026-02-15 00:39:21.824886 | TASK [Run Zuul manifest role] 2026-02-15 00:39:21.842899 | localhost | ok 2026-02-15 00:39:21.857337 | 2026-02-15 00:39:21.857411 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-15 00:39:22.249984 | localhost | changed 2026-02-15 00:39:22.256935 | 2026-02-15 00:39:22.257026 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-15 00:39:22.288535 | localhost | ok 2026-02-15 00:39:22.300001 | 2026-02-15 00:39:22.300087 | TASK [Set zuul-log-path fact] 2026-02-15 00:39:22.320517 | localhost | ok 2026-02-15 00:39:22.340590 | 2026-02-15 00:39:22.340748 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-15 00:39:22.371885 | localhost | ok 2026-02-15 00:39:22.383465 | 2026-02-15 00:39:22.383573 | LOOP [Run upload-logs-swift role] 2026-02-15 00:39:22.420095 | localhost | Output suppressed because no_log was given 2026-02-15 00:39:22.454310 | 2026-02-15 00:39:22.454444 | TASK [Set zuul-log-path fact] 2026-02-15 00:39:22.478870 | localhost | skipping: Conditional result was False 2026-02-15 00:39:22.484595 | 2026-02-15 00:39:22.484680 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-15 00:39:22.865691 | localhost -> localhost | ok: Runtime: 0:00:00.005334 2026-02-15 00:39:22.902926 | 2026-02-15 00:39:22.903066 | TASK [upload-logs-swift : Upload logs to swift]