2026-01-10 00:20:53.294091 | Job console starting... 2026-01-10 00:20:53.308043 | Updating repositories 2026-01-10 00:20:53.470067 | Preparing job workspace 2026-01-10 00:20:57.538183 | Running Ansible setup... 2026-01-10 00:21:02.481122 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-10 00:21:03.078417 | 2026-01-10 00:21:03.078535 | PLAY [localhost] 2026-01-10 00:21:03.087190 | 2026-01-10 00:21:03.087265 | TASK [Gathering Facts] 2026-01-10 00:21:04.149790 | localhost | ok 2026-01-10 00:21:04.164265 | 2026-01-10 00:21:04.164416 | TASK [Setup log path fact] 2026-01-10 00:21:04.186741 | localhost | ok 2026-01-10 00:21:04.212185 | 2026-01-10 00:21:04.212386 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-10 00:21:04.247294 | localhost | ok 2026-01-10 00:21:04.265583 | 2026-01-10 00:21:04.265772 | TASK [emit-job-header : Print job information] 2026-01-10 00:21:04.307040 | # Job Information 2026-01-10 00:21:04.307223 | Ansible Version: 2.15.12 2026-01-10 00:21:04.307279 | Job: ansible-test-sanity-docker-milestone 2026-01-10 00:21:04.307308 | Pipeline: periodic 2026-01-10 00:21:04.307331 | Executor: ze02.softwarefactory-project.io 2026-01-10 00:21:04.307353 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-10 00:21:04.307381 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/5ec/ansible/5ec85917668c48628b6130bf3950d5aa/ 2026-01-10 00:21:04.307406 | Event ID: 763e0e28d21845a4b1dbea19b60ebb5e 2026-01-10 00:21:04.311810 | 2026-01-10 00:21:04.311902 | LOOP [emit-job-header : Print node information] 2026-01-10 00:21:04.417367 | localhost | ok: 2026-01-10 00:21:04.417653 | localhost | # Node Information 2026-01-10 00:21:04.417797 | localhost | Inventory Hostname: controller 2026-01-10 00:21:04.417849 | localhost | Hostname: np0005580294 2026-01-10 00:21:04.417890 | localhost | Username: zuul 2026-01-10 00:21:04.417954 | localhost | Distro: Fedora 37 2026-01-10 00:21:04.417994 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-01-10 00:21:04.418043 | localhost | Region: ca-ymq-1 2026-01-10 00:21:04.418098 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-10 00:21:04.418141 | localhost | Product Name: OpenStack Nova 2026-01-10 00:21:04.418178 | localhost | Interface IP: 162.253.55.49 2026-01-10 00:21:04.427963 | 2026-01-10 00:21:04.428105 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-10 00:21:04.820896 | localhost -> localhost | changed 2026-01-10 00:21:04.826532 | 2026-01-10 00:21:04.826601 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-10 00:21:05.750868 | localhost -> localhost | changed 2026-01-10 00:21:05.793639 | 2026-01-10 00:21:05.793858 | PLAY [all:!appliance*] 2026-01-10 00:21:05.833580 | 2026-01-10 00:21:05.833788 | TASK [include_role : start-zuul-console] 2026-01-10 00:21:05.856434 | controller | ok 2026-01-10 00:21:05.876614 | 2026-01-10 00:21:05.876768 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-10 00:21:06.272647 | controller | ok 2026-01-10 00:21:06.298458 | 2026-01-10 00:21:06.298644 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-10 00:21:07.417529 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-10 00:21:07.434215 | 2026-01-10 00:21:07.434355 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-10 00:21:07.981836 | controller | skipping: Conditional result was False 2026-01-10 00:21:07.988968 | 2026-01-10 00:21:07.989104 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-10 00:21:08.013722 | controller | skipping: Conditional result was False 2026-01-10 00:21:08.030152 | 2026-01-10 00:21:08.030335 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-10 00:21:08.057206 | controller | skipping: Conditional result was False 2026-01-10 00:21:08.071504 | 2026-01-10 00:21:08.071714 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-10 00:21:08.098186 | controller | skipping: Conditional result was False 2026-01-10 00:21:08.113705 | 2026-01-10 00:21:08.113906 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-10 00:21:08.140570 | controller | skipping: Conditional result was False 2026-01-10 00:21:08.155915 | 2026-01-10 00:21:08.156261 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-10 00:21:08.172736 | controller | skipping: Conditional result was False 2026-01-10 00:21:08.191286 | 2026-01-10 00:21:08.191431 | TASK [Disable Fedora Modular] 2026-01-10 00:21:08.445036 | controller | changed 2026-01-10 00:21:08.457967 | 2026-01-10 00:21:08.458134 | TASK [Enable EPEL] 2026-01-10 00:21:08.485614 | controller | skipping: Conditional result was False 2026-01-10 00:21:08.500469 | 2026-01-10 00:21:08.500752 | TASK [Register the RHEL node] 2026-01-10 00:21:09.058398 | 2026-01-10 00:21:09.058557 | TASK [Show the subscription-manager status] 2026-01-10 00:21:09.623253 | controller | skipping: Conditional result was False 2026-01-10 00:21:09.631024 | 2026-01-10 00:21:09.631129 | TASK [Enable EPEL on RHEL] 2026-01-10 00:21:10.211815 | controller | skipping: Conditional result was False 2026-01-10 00:21:10.222208 | 2026-01-10 00:21:10.222351 | TASK [Install git and tox] 2026-01-10 00:22:28.552651 | controller | changed 2026-01-10 00:22:28.572628 | 2026-01-10 00:22:28.573563 | TASK [include_role : prepare-workspace] 2026-01-10 00:22:28.619365 | controller | ok 2026-01-10 00:22:28.646723 | 2026-01-10 00:22:28.646845 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-10 00:22:28.891941 | controller | ok 2026-01-10 00:22:28.902000 | 2026-01-10 00:22:28.902139 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-10 00:22:41.369466 | controller | Output suppressed because no_log was given 2026-01-10 00:22:41.383173 | 2026-01-10 00:22:41.383280 | TASK [include_role : prepare-workspace-openshift] 2026-01-10 00:22:41.409168 | controller | skipping: Conditional result was False 2026-01-10 00:22:41.468024 | 2026-01-10 00:22:41.468099 | PLAY [all:!appliance] 2026-01-10 00:22:41.483920 | 2026-01-10 00:22:41.483989 | TASK [Run add-build-sshkey role (RSA)] 2026-01-10 00:22:41.515519 | controller | ok 2026-01-10 00:22:41.530109 | 2026-01-10 00:22:41.530183 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-10 00:22:41.770093 | controller -> localhost | ok 2026-01-10 00:22:41.786648 | 2026-01-10 00:22:41.786831 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-10 00:22:41.813904 | controller | ok 2026-01-10 00:22:41.848449 | controller | included: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-10 00:22:41.854846 | 2026-01-10 00:22:41.854912 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-10 00:22:42.368721 | controller -> localhost | Generating public/private rsa key pair. 2026-01-10 00:22:42.368945 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/5ec85917668c48628b6130bf3950d5aa_id_rsa. 2026-01-10 00:22:42.368980 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/5ec85917668c48628b6130bf3950d5aa_id_rsa.pub. 2026-01-10 00:22:42.369004 | controller -> localhost | The key fingerprint is: 2026-01-10 00:22:42.369024 | controller -> localhost | SHA256:P9nJS2orh+d3YNT+vGw6WL2Xkss8EYzEuaRFregk06U zuul-build-sshkey 2026-01-10 00:22:42.369043 | controller -> localhost | The key's randomart image is: 2026-01-10 00:22:42.369062 | controller -> localhost | +---[RSA 2048]----+ 2026-01-10 00:22:42.369079 | controller -> localhost | | o.o | 2026-01-10 00:22:42.369098 | controller -> localhost | | B . | 2026-01-10 00:22:42.369116 | controller -> localhost | | . O =. | 2026-01-10 00:22:42.369134 | controller -> localhost | | o E +.o. | 2026-01-10 00:22:42.369151 | controller -> localhost | | S . .o | 2026-01-10 00:22:42.369185 | controller -> localhost | | o +o+.. | 2026-01-10 00:22:42.369207 | controller -> localhost | | .+.B.ooo| 2026-01-10 00:22:42.369226 | controller -> localhost | | o +=+*o++| 2026-01-10 00:22:42.369244 | controller -> localhost | | *+o.*Boo| 2026-01-10 00:22:42.369264 | controller -> localhost | +----[SHA256]-----+ 2026-01-10 00:22:42.369356 | controller -> localhost | ok: Runtime: 0:00:00.101424 2026-01-10 00:22:42.377109 | 2026-01-10 00:22:42.377181 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-10 00:22:42.407520 | controller | ok 2026-01-10 00:22:42.417697 | controller | included: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-10 00:22:42.427471 | 2026-01-10 00:22:42.427542 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-10 00:22:42.441798 | controller | skipping: Conditional result was False 2026-01-10 00:22:42.449361 | 2026-01-10 00:22:42.449452 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-10 00:22:42.908280 | controller | changed 2026-01-10 00:22:42.921899 | 2026-01-10 00:22:42.922002 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-10 00:22:43.154341 | controller | ok 2026-01-10 00:22:43.169815 | 2026-01-10 00:22:43.169967 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-10 00:22:43.786424 | controller | changed 2026-01-10 00:22:43.792180 | 2026-01-10 00:22:43.792253 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-10 00:22:44.408933 | controller | changed 2026-01-10 00:22:44.423552 | 2026-01-10 00:22:44.423732 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-10 00:22:44.451494 | controller | skipping: Conditional result was False 2026-01-10 00:22:44.465451 | 2026-01-10 00:22:44.465612 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-10 00:22:44.880232 | controller -> localhost | changed 2026-01-10 00:22:44.907616 | 2026-01-10 00:22:44.908028 | TASK [add-build-sshkey : Add back temp key] 2026-01-10 00:22:45.301381 | controller -> localhost | Identity added: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/5ec85917668c48628b6130bf3950d5aa_id_rsa (zuul-build-sshkey) 2026-01-10 00:22:45.301688 | controller -> localhost | ok: Runtime: 0:00:00.013647 2026-01-10 00:22:45.308188 | 2026-01-10 00:22:45.308254 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-10 00:22:45.676483 | controller | ok 2026-01-10 00:22:45.689243 | 2026-01-10 00:22:45.689431 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-10 00:22:45.737433 | controller | skipping: Conditional result was False 2026-01-10 00:22:45.753253 | 2026-01-10 00:22:45.753394 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-10 00:22:45.786788 | controller | ok 2026-01-10 00:22:45.815157 | 2026-01-10 00:22:45.815288 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-10 00:22:46.065189 | controller -> localhost | ok 2026-01-10 00:22:46.072529 | 2026-01-10 00:22:46.072627 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-10 00:22:46.129318 | controller | ok 2026-01-10 00:22:46.140482 | controller | included: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-10 00:22:46.149947 | 2026-01-10 00:22:46.150032 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-10 00:22:46.525544 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-10 00:22:46.525744 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/5ec85917668c48628b6130bf3950d5aa_id_ecdsa. 2026-01-10 00:22:46.525776 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/5ec85917668c48628b6130bf3950d5aa_id_ecdsa.pub. 2026-01-10 00:22:46.525806 | controller -> localhost | The key fingerprint is: 2026-01-10 00:22:46.525826 | controller -> localhost | SHA256:2BlsNbt2JT6+j68Nkn+uwHYlkIjbxZtZAE7R0V2z2Ms zuul-build-sshkey 2026-01-10 00:22:46.525845 | controller -> localhost | The key's randomart image is: 2026-01-10 00:22:46.525863 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-10 00:22:46.525883 | controller -> localhost | | ++=o . o.| 2026-01-10 00:22:46.525901 | controller -> localhost | | = +.=. + o| 2026-01-10 00:22:46.525920 | controller -> localhost | | . * * o..o | 2026-01-10 00:22:46.525938 | controller -> localhost | | * + O o. .| 2026-01-10 00:22:46.525956 | controller -> localhost | | o S * = .E | 2026-01-10 00:22:46.525974 | controller -> localhost | | o + + | 2026-01-10 00:22:46.525992 | controller -> localhost | | * + | 2026-01-10 00:22:46.526009 | controller -> localhost | | . = =. | 2026-01-10 00:22:46.526027 | controller -> localhost | | *B= | 2026-01-10 00:22:46.526044 | controller -> localhost | +----[SHA256]-----+ 2026-01-10 00:22:46.526094 | controller -> localhost | ok: Runtime: 0:00:00.020753 2026-01-10 00:22:46.533092 | 2026-01-10 00:22:46.533161 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-10 00:22:46.554124 | controller | ok 2026-01-10 00:22:46.561633 | controller | included: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-10 00:22:46.570802 | 2026-01-10 00:22:46.570872 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-10 00:22:46.585484 | controller | skipping: Conditional result was False 2026-01-10 00:22:46.592487 | 2026-01-10 00:22:46.592785 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-10 00:22:46.857850 | controller | changed 2026-01-10 00:22:46.863453 | 2026-01-10 00:22:46.863521 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-10 00:22:47.114441 | controller | ok 2026-01-10 00:22:47.124201 | 2026-01-10 00:22:47.124304 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-10 00:22:47.804172 | controller | changed 2026-01-10 00:22:47.813010 | 2026-01-10 00:22:47.813102 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-10 00:22:48.445349 | controller | changed 2026-01-10 00:22:48.454300 | 2026-01-10 00:22:48.454395 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-10 00:22:48.480287 | controller | skipping: Conditional result was False 2026-01-10 00:22:48.490167 | 2026-01-10 00:22:48.490260 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-10 00:22:48.791709 | controller -> localhost | changed 2026-01-10 00:22:48.859813 | 2026-01-10 00:22:48.859950 | TASK [add-build-sshkey : Add back temp key] 2026-01-10 00:22:49.200740 | controller -> localhost | Identity added: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/5ec85917668c48628b6130bf3950d5aa_id_ecdsa (zuul-build-sshkey) 2026-01-10 00:22:49.201004 | controller -> localhost | ok: Runtime: 0:00:00.013921 2026-01-10 00:22:49.208106 | 2026-01-10 00:22:49.208173 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-10 00:22:49.438388 | controller | ok 2026-01-10 00:22:49.450849 | 2026-01-10 00:22:49.451005 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-10 00:22:49.489003 | controller | skipping: Conditional result was False 2026-01-10 00:22:49.509839 | 2026-01-10 00:22:49.510004 | TASK [include_role : remove-zuul-sshkey] 2026-01-10 00:22:49.536945 | controller | skipping: Conditional result was False 2026-01-10 00:22:49.548179 | 2026-01-10 00:22:49.548332 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-10 00:22:49.807828 | controller | ok: "logs" 2026-01-10 00:22:49.808278 | controller | ok: All items complete 2026-01-10 00:22:49.808339 | 2026-01-10 00:22:50.007554 | controller | ok: "artifacts" 2026-01-10 00:22:50.214508 | controller | ok: "docs" 2026-01-10 00:22:50.236571 | 2026-01-10 00:22:50.236786 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-10 00:22:50.502292 | controller | changed: "logs" 2026-01-10 00:22:50.707401 | controller | changed: "artifacts" 2026-01-10 00:22:50.903333 | controller | changed: "docs" 2026-01-10 00:22:50.967362 | 2026-01-10 00:22:50.967481 | PLAY RECAP 2026-01-10 00:22:50.967540 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-10 00:22:50.967575 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-10 00:22:50.967600 | 2026-01-10 00:22:51.089509 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-10 00:22:51.090637 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-10 00:22:51.773678 | 2026-01-10 00:22:51.773798 | PLAY [all] 2026-01-10 00:22:51.799450 | 2026-01-10 00:22:51.799595 | TASK [Install binary dependencies] 2026-01-10 00:22:51.870953 | controller | ok 2026-01-10 00:22:51.891496 | 2026-01-10 00:22:51.891630 | TASK [bindep : Include find tasks] 2026-01-10 00:22:51.923580 | controller | ok 2026-01-10 00:22:51.933233 | controller | included: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-10 00:22:51.941878 | 2026-01-10 00:22:51.942088 | TASK [bindep : Look for bindep.txt] 2026-01-10 00:22:52.293833 | controller | ok 2026-01-10 00:22:52.300277 | 2026-01-10 00:22:52.300441 | TASK [bindep : Define bindep_file fact] 2026-01-10 00:22:52.328176 | controller | skipping: Conditional result was False 2026-01-10 00:22:52.336867 | 2026-01-10 00:22:52.337086 | TASK [bindep : Look for other-requirements.txt] 2026-01-10 00:22:52.551338 | controller | ok 2026-01-10 00:22:52.560112 | 2026-01-10 00:22:52.560861 | TASK [bindep : Define bindep_file fact] 2026-01-10 00:22:52.589278 | controller | skipping: Conditional result was False 2026-01-10 00:22:52.597470 | 2026-01-10 00:22:52.597599 | TASK [bindep : Look for bindep fallback file] 2026-01-10 00:22:52.634092 | controller | skipping: Conditional result was False 2026-01-10 00:22:52.643112 | 2026-01-10 00:22:52.643211 | TASK [bindep : Define bindep_file fact] 2026-01-10 00:22:52.668986 | controller | skipping: Conditional result was False 2026-01-10 00:22:52.676217 | 2026-01-10 00:22:52.676321 | TASK [bindep : Include bindep tasks] 2026-01-10 00:22:52.712504 | controller | skipping: Conditional result was False 2026-01-10 00:22:52.720511 | 2026-01-10 00:22:52.720626 | TASK [bindep : Include install tasks] 2026-01-10 00:22:52.766971 | controller | skipping: Conditional result was False 2026-01-10 00:22:52.778232 | 2026-01-10 00:22:52.778792 | LOOP [bindep : Include package tasks] 2026-01-10 00:22:52.856006 | 2026-01-10 00:22:52.856289 | TASK [Run test-setup role] 2026-01-10 00:22:52.883804 | controller | ok 2026-01-10 00:22:52.912764 | 2026-01-10 00:22:52.912898 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-10 00:22:53.124617 | controller | ok 2026-01-10 00:22:53.139490 | 2026-01-10 00:22:53.139647 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-10 00:22:53.692075 | controller | skipping: Conditional result was False 2026-01-10 00:22:53.748547 | 2026-01-10 00:22:53.748641 | PLAY RECAP 2026-01-10 00:22:53.748731 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-10 00:22:53.748762 | 2026-01-10 00:22:53.871724 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-10 00:22:53.872714 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-10 00:22:54.432932 | 2026-01-10 00:22:54.433057 | PLAY [controller] 2026-01-10 00:22:54.454218 | 2026-01-10 00:22:54.454355 | TASK [Create the /root directory] 2026-01-10 00:22:54.854000 | controller | ok 2026-01-10 00:22:54.863857 | 2026-01-10 00:22:54.863961 | TASK [Install glibc-langpack-en] 2026-01-10 00:22:58.748354 | controller | ok: Nothing to do 2026-01-10 00:22:58.754087 | 2026-01-10 00:22:58.754147 | TASK [Ensure controller directory exists] 2026-01-10 00:22:58.977242 | controller | changed 2026-01-10 00:22:58.992169 | 2026-01-10 00:22:58.992448 | TASK [Install container runtime] 2026-01-10 00:22:59.054905 | controller | ok 2026-01-10 00:22:59.119375 | 2026-01-10 00:22:59.119500 | LOOP [ensure-podman : Find distribution installation] 2026-01-10 00:22:59.160526 | controller | ok: "/var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-10 00:22:59.171530 | controller | included: /var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-10 00:22:59.178592 | 2026-01-10 00:22:59.178716 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-10 00:24:04.215690 | controller | changed 2026-01-10 00:24:04.222040 | 2026-01-10 00:24:04.222124 | TASK [ensure-podman : Fetch podman version] 2026-01-10 00:24:04.803619 | controller | Client: Podman Engine 2026-01-10 00:24:04.841373 | controller | Version: 4.6.2 2026-01-10 00:24:04.841483 | controller | API Version: 4.6.2 2026-01-10 00:24:04.841506 | controller | Go Version: go1.19.12 2026-01-10 00:24:04.841556 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-10 00:24:04.841578 | controller | OS/Arch: linux/amd64 2026-01-10 00:24:05.257542 | controller | ok: Runtime: 0:00:00.230597 2026-01-10 00:24:05.272342 | 2026-01-10 00:24:05.272758 | TASK [ensure-podman : Print podman version installed] 2026-01-10 00:24:05.320207 | Podman version: Client: Podman Engine 2026-01-10 00:24:05.320552 | Version: 4.6.2 2026-01-10 00:24:05.320624 | API Version: 4.6.2 2026-01-10 00:24:05.320729 | Go Version: go1.19.12 2026-01-10 00:24:05.320785 | Built: Mon Aug 28 19:38:31 2023 2026-01-10 00:24:05.320832 | OS/Arch: linux/amd64 2026-01-10 00:24:05.336962 | 2026-01-10 00:24:05.337113 | TASK [ensure-podman : Validate podman engine] 2026-01-10 00:24:05.880495 | controller | skipping: Conditional result was False 2026-01-10 00:24:05.895416 | 2026-01-10 00:24:05.895612 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-10 00:24:05.922832 | controller | skipping: Conditional result was False 2026-01-10 00:24:05.946611 | 2026-01-10 00:24:05.946819 | TASK [Ensure python3.8 is present] 2026-01-10 00:24:05.963532 | controller | skipping: Conditional result was False 2026-01-10 00:24:05.997627 | 2026-01-10 00:24:05.997832 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-10 00:24:06.022044 | controller | ok 2026-01-10 00:24:06.044447 | 2026-01-10 00:24:06.044567 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-10 00:24:07.618100 | controller | ok: Nothing to do 2026-01-10 00:24:07.623581 | 2026-01-10 00:24:07.623640 | TASK [our-ensure-python : Also install python3-devel] 2026-01-10 00:24:17.177381 | controller | changed 2026-01-10 00:24:17.190332 | 2026-01-10 00:24:17.190455 | TASK [Run ensure-virtualenv role] 2026-01-10 00:24:17.211133 | controller | ok 2026-01-10 00:24:17.234237 | 2026-01-10 00:24:17.234367 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-10 00:24:17.442055 | controller | /usr/bin/virtualenv 2026-01-10 00:24:17.768730 | controller | ok: Runtime: 0:00:00.003498 2026-01-10 00:24:17.776295 | 2026-01-10 00:24:17.776391 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-10 00:24:17.796037 | controller | skipping: Conditional result was False 2026-01-10 00:24:17.796316 | controller | ok: All items complete 2026-01-10 00:24:17.796346 | 2026-01-10 00:24:17.812254 | 2026-01-10 00:24:17.812399 | TASK [Find the full path of the Python interpreter] 2026-01-10 00:24:18.051433 | controller | /usr/bin/python3 2026-01-10 00:24:18.379970 | controller | ok 2026-01-10 00:24:18.393432 | 2026-01-10 00:24:18.393577 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-10 00:24:19.401382 | controller | created virtual environment CPython3.11.0.final.0-64 in 534ms 2026-01-10 00:24:19.422773 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-10 00:24:19.422808 | 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:24:19.422818 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-10 00:24:19.422831 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-10 00:24:19.464072 | controller | changed 2026-01-10 00:24:19.473838 | 2026-01-10 00:24:19.473943 | TASK [Set selinux package] 2026-01-10 00:24:19.494405 | controller | ok 2026-01-10 00:24:19.501950 | 2026-01-10 00:24:19.503777 | TASK [Set selinux package (Fedora)] 2026-01-10 00:24:19.532591 | controller | ok 2026-01-10 00:24:19.538374 | 2026-01-10 00:24:19.538444 | TASK [Install selinux into virtualenv] 2026-01-10 00:24:45.034851 | controller | Collecting selinux-please-lie-to-me 2026-01-10 00:24:57.293957 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-10 00:24:57.602286 | controller | Collecting setuptools<50.0.0 2026-01-10 00:24:57.607432 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-10 00:24:57.642390 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.9 MB/s eta 0:00:00 2026-01-10 00:24:57.724669 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-10 00:24:57.724915 | controller | Attempting uninstall: setuptools 2026-01-10 00:24:57.727324 | controller | Found existing installation: setuptools 62.6.0 2026-01-10 00:24:57.787433 | controller | Uninstalling setuptools-62.6.0: 2026-01-10 00:24:57.795465 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-10 00:24:58.151506 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-10 00:25:09.674659 | controller | 2026-01-10 00:25:09.819647 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-10 00:25:09.819728 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-10 00:25:10.104277 | controller | ok: Runtime: 0:00:50.069430 2026-01-10 00:25:10.117356 | 2026-01-10 00:25:10.117486 | TASK [Install pytest-forked into virtualenv] 2026-01-10 00:25:18.844550 | controller | Collecting pytest-forked 2026-01-10 00:25:31.212252 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-10 00:25:31.258310 | controller | Collecting py 2026-01-10 00:25:31.264181 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-10 00:25:31.284302 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.9 MB/s eta 0:00:00 2026-01-10 00:25:31.404959 | controller | Collecting pytest>=3.10 2026-01-10 00:25:31.409492 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-10 00:25:31.423893 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 33.0 MB/s eta 0:00:00 2026-01-10 00:25:31.463381 | controller | Collecting iniconfig>=1.0.1 2026-01-10 00:25:31.469222 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-10 00:25:31.517362 | controller | Collecting packaging>=22 2026-01-10 00:25:31.522811 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-10 00:25:31.532744 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.0 MB/s eta 0:00:00 2026-01-10 00:25:31.565673 | controller | Collecting pluggy<2,>=1.5 2026-01-10 00:25:31.568889 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-10 00:25:31.611949 | controller | Collecting pygments>=2.7.2 2026-01-10 00:25:31.624580 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-10 00:25:31.642169 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 82.9 MB/s eta 0:00:00 2026-01-10 00:25:31.709454 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-10 00:25:32.771118 | 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:25:32.781607 | controller | 2026-01-10 00:25:32.864783 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-10 00:25:32.864834 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-10 00:25:33.185201 | controller | ok: Runtime: 0:00:22.523542 2026-01-10 00:25:33.199077 | 2026-01-10 00:25:33.199250 | TASK [Update pip] 2026-01-10 00:25:33.730874 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-10 00:25:43.613866 | controller | Collecting pip 2026-01-10 00:25:55.983495 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-10 00:25:56.035965 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 38.5 MB/s eta 0:00:00 2026-01-10 00:25:56.106736 | controller | Installing collected packages: pip 2026-01-10 00:25:56.106895 | controller | Attempting uninstall: pip 2026-01-10 00:25:56.109017 | controller | Found existing installation: pip 22.2.2 2026-01-10 00:25:56.253015 | controller | Uninstalling pip-22.2.2: 2026-01-10 00:25:56.268457 | controller | Successfully uninstalled pip-22.2.2 2026-01-10 00:25:57.081837 | controller | Successfully installed pip-25.3 2026-01-10 00:25:57.271814 | controller | ok: Runtime: 0:00:23.723779 2026-01-10 00:25:57.284270 | 2026-01-10 00:25:57.284428 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-10 00:25:57.516912 | controller | changed 2026-01-10 00:25:57.528713 | 2026-01-10 00:25:57.528844 | TASK [Install ansible into virtualenv] 2026-01-10 00:25:58.050576 | controller | Processing ./src/github.com/ansible/ansible 2026-01-10 00:25:58.054982 | controller | Installing build dependencies: started 2026-01-10 00:26:18.938084 | controller | Installing build dependencies: finished with status 'done' 2026-01-10 00:26:18.939785 | controller | Getting requirements to build wheel: started 2026-01-10 00:26:19.664930 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-10 00:26:19.665887 | controller | Preparing metadata (pyproject.toml): started 2026-01-10 00:26:20.131149 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-10 00:26:20.136293 | 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:26:20.140393 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-10 00:26:20.593995 | controller | ERROR 2026-01-10 00:26:20.594228 | controller | { 2026-01-10 00:26:20.594269 | controller | "delta": "0:00:22.446860", 2026-01-10 00:26:20.594296 | controller | "end": "2026-01-10 00:26:20.205558", 2026-01-10 00:26:20.594322 | controller | "msg": "non-zero return code", 2026-01-10 00:26:20.594355 | controller | "rc": 1, 2026-01-10 00:26:20.594379 | controller | "start": "2026-01-10 00:25:57.758698" 2026-01-10 00:26:20.594400 | controller | } failure 2026-01-10 00:26:20.596313 | 2026-01-10 00:26:20.596379 | PLAY RECAP 2026-01-10 00:26:20.596435 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-10 00:26:20.596463 | 2026-01-10 00:26:20.706067 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-10 00:26:20.707344 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-10 00:26:21.349659 | 2026-01-10 00:26:21.349822 | PLAY [all] 2026-01-10 00:26:21.371270 | 2026-01-10 00:26:21.371379 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-10 00:26:21.646081 | controller | changed: non-zero return code 2026-01-10 00:26:21.660787 | 2026-01-10 00:26:21.661244 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-10 00:26:21.677285 | controller | skipping: Conditional result was False 2026-01-10 00:26:21.687467 | 2026-01-10 00:26:21.687623 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-10 00:26:21.713484 | 2026-01-10 00:26:21.713729 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-10 00:26:21.749466 | 2026-01-10 00:26:21.749842 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-10 00:26:21.766357 | controller | skipping: Conditional result was False 2026-01-10 00:26:21.779487 | 2026-01-10 00:26:21.779633 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-10 00:26:21.811630 | 2026-01-10 00:26:21.811824 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-10 00:26:21.836018 | controller | skipping: Conditional result was False 2026-01-10 00:26:21.842272 | 2026-01-10 00:26:21.842342 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-10 00:26:21.866003 | controller | skipping: Conditional result was False 2026-01-10 00:26:21.872704 | 2026-01-10 00:26:21.872780 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-10 00:26:21.896607 | controller | skipping: Conditional result was False 2026-01-10 00:26:21.924448 | 2026-01-10 00:26:21.924540 | PLAY RECAP 2026-01-10 00:26:21.924581 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-10 00:26:21.924603 | 2026-01-10 00:26:22.017380 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-10 00:26:22.018248 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-10 00:26:22.626233 | 2026-01-10 00:26:22.626349 | PLAY [all:!appliance*] 2026-01-10 00:26:22.648582 | 2026-01-10 00:26:22.648723 | TASK [unregister the node] 2026-01-10 00:26:23.179595 | controller | skipping: Conditional result was False 2026-01-10 00:26:23.192123 | 2026-01-10 00:26:23.192288 | TASK [include_role : fetch-output] 2026-01-10 00:26:23.232013 | controller | ok 2026-01-10 00:26:23.270917 | 2026-01-10 00:26:23.271065 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-10 00:26:23.317424 | controller | skipping: Conditional result was False 2026-01-10 00:26:23.330883 | 2026-01-10 00:26:23.331112 | TASK [fetch-output : Set log path for single node] 2026-01-10 00:26:23.370929 | controller | ok 2026-01-10 00:26:23.384081 | 2026-01-10 00:26:23.384249 | LOOP [fetch-output : Ensure local output dirs] 2026-01-10 00:26:23.834510 | controller -> localhost | ok: "/var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/logs" 2026-01-10 00:26:24.115378 | controller -> localhost | changed: "/var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/artifacts" 2026-01-10 00:26:24.421334 | controller -> localhost | changed: "/var/lib/zuul/builds/5ec85917668c48628b6130bf3950d5aa/work/docs" 2026-01-10 00:26:24.445105 | 2026-01-10 00:26:24.445254 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-10 00:26:25.112971 | controller | changed: 2026-01-10 00:26:25.113522 | controller | .d..t...... ./ 2026-01-10 00:26:25.113603 | controller | cd+++++++++ controller/ 2026-01-10 00:26:25.113729 | controller | changed: All items complete 2026-01-10 00:26:25.113790 | 2026-01-10 00:26:25.647015 | controller | changed: .d..t...... ./ 2026-01-10 00:26:26.152118 | controller | changed: .d..t...... ./ 2026-01-10 00:26:26.183919 | 2026-01-10 00:26:26.184109 | TASK [include_role : fetch-output-openshift] 2026-01-10 00:26:26.200963 | controller | skipping: Conditional result was False 2026-01-10 00:26:26.212058 | 2026-01-10 00:26:26.212174 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-10 00:26:26.247534 | controller | skipping: Conditional result was False 2026-01-10 00:26:26.260904 | controller | skipping: Conditional result was False 2026-01-10 00:26:26.319556 | 2026-01-10 00:26:26.319684 | PLAY [localhost] 2026-01-10 00:26:26.336191 | 2026-01-10 00:26:26.336284 | TASK [Run Zuul manifest role] 2026-01-10 00:26:26.356533 | localhost | ok 2026-01-10 00:26:26.376356 | 2026-01-10 00:26:26.376475 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-10 00:26:26.792398 | localhost | changed 2026-01-10 00:26:26.803849 | 2026-01-10 00:26:26.804030 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-10 00:26:26.840642 | localhost | ok 2026-01-10 00:26:26.859112 | 2026-01-10 00:26:26.859269 | TASK [Set zuul-log-path fact] 2026-01-10 00:26:26.881428 | localhost | ok 2026-01-10 00:26:26.901426 | 2026-01-10 00:26:26.901596 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-10 00:26:26.932871 | localhost | ok 2026-01-10 00:26:26.944339 | 2026-01-10 00:26:26.944434 | LOOP [Run upload-logs-swift role] 2026-01-10 00:26:26.993811 | localhost | Output suppressed because no_log was given 2026-01-10 00:26:27.032712 | 2026-01-10 00:26:27.032856 | TASK [Set zuul-log-path fact] 2026-01-10 00:26:27.068797 | localhost | skipping: Conditional result was False 2026-01-10 00:26:27.076461 | 2026-01-10 00:26:27.076559 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-10 00:26:27.534247 | localhost -> localhost | ok: Runtime: 0:00:00.004637 2026-01-10 00:26:27.564261 | 2026-01-10 00:26:27.564380 | TASK [upload-logs-swift : Upload logs to swift]