2026-01-03 00:21:24.501515 | Job console starting... 2026-01-03 00:21:24.514925 | Updating repositories 2026-01-03 00:21:24.668222 | Preparing job workspace 2026-01-03 00:21:28.504846 | Running Ansible setup... 2026-01-03 00:21:36.922329 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-03 00:21:37.569529 | 2026-01-03 00:21:37.569691 | PLAY [localhost] 2026-01-03 00:21:37.579302 | 2026-01-03 00:21:37.579410 | TASK [Gathering Facts] 2026-01-03 00:21:38.692392 | localhost | ok 2026-01-03 00:21:38.707519 | 2026-01-03 00:21:38.707708 | TASK [Setup log path fact] 2026-01-03 00:21:38.728140 | localhost | ok 2026-01-03 00:21:38.742422 | 2026-01-03 00:21:38.742588 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-03 00:21:38.772657 | localhost | ok 2026-01-03 00:21:38.781151 | 2026-01-03 00:21:38.781255 | TASK [emit-job-header : Print job information] 2026-01-03 00:21:38.823142 | # Job Information 2026-01-03 00:21:38.823364 | Ansible Version: 2.15.12 2026-01-03 00:21:38.823406 | Job: ansible-test-sanity-docker-milestone 2026-01-03 00:21:38.823431 | Pipeline: periodic 2026-01-03 00:21:38.823450 | Executor: ze03.softwarefactory-project.io 2026-01-03 00:21:38.823468 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-03 00:21:38.823489 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/1af/ansible/1af79657b06f4e4d846215db77b2f53d/ 2026-01-03 00:21:38.823509 | Event ID: 84f60a54a6bb4d9ab16f9cfd1e63d8f4 2026-01-03 00:21:38.827773 | 2026-01-03 00:21:38.827848 | LOOP [emit-job-header : Print node information] 2026-01-03 00:21:38.932826 | localhost | ok: 2026-01-03 00:21:38.933075 | localhost | # Node Information 2026-01-03 00:21:38.933109 | localhost | Inventory Hostname: controller 2026-01-03 00:21:38.933133 | localhost | Hostname: np0005573543 2026-01-03 00:21:38.933155 | localhost | Username: zuul 2026-01-03 00:21:38.933180 | localhost | Distro: Fedora 37 2026-01-03 00:21:38.933201 | localhost | Provider: ansible-vexxhost-ams1 2026-01-03 00:21:38.933222 | localhost | Region: ams1 2026-01-03 00:21:38.933243 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-03 00:21:38.933264 | localhost | Product Name: OpenStack Nova 2026-01-03 00:21:38.933284 | localhost | Interface IP: 38.129.16.101 2026-01-03 00:21:38.944376 | 2026-01-03 00:21:38.944566 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-03 00:21:39.428138 | localhost -> localhost | changed 2026-01-03 00:21:39.435091 | 2026-01-03 00:21:39.435179 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-03 00:21:40.504532 | localhost -> localhost | changed 2026-01-03 00:21:40.534680 | 2026-01-03 00:21:40.534822 | PLAY [all:!appliance*] 2026-01-03 00:21:40.558608 | 2026-01-03 00:21:40.558808 | TASK [include_role : start-zuul-console] 2026-01-03 00:21:40.582768 | controller | ok 2026-01-03 00:21:40.600102 | 2026-01-03 00:21:40.600276 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-03 00:21:41.654088 | controller | ok 2026-01-03 00:21:41.682072 | 2026-01-03 00:21:41.682230 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-03 00:21:43.955960 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-03 00:21:43.968279 | 2026-01-03 00:21:43.968432 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-03 00:21:44.329344 | controller | skipping: Conditional result was False 2026-01-03 00:21:44.345283 | 2026-01-03 00:21:44.345466 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-03 00:21:44.384381 | controller | skipping: Conditional result was False 2026-01-03 00:21:44.401331 | 2026-01-03 00:21:44.401547 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-03 00:21:44.429227 | controller | skipping: Conditional result was False 2026-01-03 00:21:44.437383 | 2026-01-03 00:21:44.437475 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-03 00:21:44.462699 | controller | skipping: Conditional result was False 2026-01-03 00:21:44.471539 | 2026-01-03 00:21:44.471916 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-03 00:21:44.499704 | controller | skipping: Conditional result was False 2026-01-03 00:21:44.508505 | 2026-01-03 00:21:44.508694 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-03 00:21:44.535095 | controller | skipping: Conditional result was False 2026-01-03 00:21:44.550618 | 2026-01-03 00:21:44.550819 | TASK [Disable Fedora Modular] 2026-01-03 00:21:45.723337 | controller | changed 2026-01-03 00:21:45.729766 | 2026-01-03 00:21:45.729850 | TASK [Enable EPEL] 2026-01-03 00:21:45.755413 | controller | skipping: Conditional result was False 2026-01-03 00:21:45.765736 | 2026-01-03 00:21:45.765894 | TASK [Register the RHEL node] 2026-01-03 00:21:46.169570 | 2026-01-03 00:21:46.169818 | TASK [Show the subscription-manager status] 2026-01-03 00:21:46.554599 | controller | skipping: Conditional result was False 2026-01-03 00:21:46.565493 | 2026-01-03 00:21:46.565669 | TASK [Enable EPEL on RHEL] 2026-01-03 00:21:46.960611 | controller | skipping: Conditional result was False 2026-01-03 00:21:46.977403 | 2026-01-03 00:21:46.977591 | TASK [Install git and tox] 2026-01-03 00:23:49.692424 | controller | changed 2026-01-03 00:23:49.706320 | 2026-01-03 00:23:49.706485 | TASK [include_role : prepare-workspace] 2026-01-03 00:23:49.746615 | controller | ok 2026-01-03 00:23:49.784797 | 2026-01-03 00:23:49.785022 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-03 00:23:50.707831 | controller | ok 2026-01-03 00:23:50.719876 | 2026-01-03 00:23:50.720011 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-03 00:24:06.625845 | controller | Output suppressed because no_log was given 2026-01-03 00:24:06.637428 | 2026-01-03 00:24:06.637527 | TASK [include_role : prepare-workspace-openshift] 2026-01-03 00:24:06.673480 | controller | skipping: Conditional result was False 2026-01-03 00:24:06.711752 | 2026-01-03 00:24:06.711912 | PLAY [all:!appliance] 2026-01-03 00:24:06.767346 | 2026-01-03 00:24:06.767611 | TASK [Run add-build-sshkey role (RSA)] 2026-01-03 00:24:06.804938 | controller | ok 2026-01-03 00:24:06.822733 | 2026-01-03 00:24:06.822891 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-03 00:24:07.089600 | controller -> localhost | ok 2026-01-03 00:24:07.098837 | 2026-01-03 00:24:07.098932 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-03 00:24:07.134853 | controller | ok 2026-01-03 00:24:07.153675 | controller | included: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-03 00:24:07.164316 | 2026-01-03 00:24:07.164429 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-03 00:24:07.665830 | controller -> localhost | Generating public/private rsa key pair. 2026-01-03 00:24:07.666128 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/1af79657b06f4e4d846215db77b2f53d_id_rsa. 2026-01-03 00:24:07.666174 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/1af79657b06f4e4d846215db77b2f53d_id_rsa.pub. 2026-01-03 00:24:07.666209 | controller -> localhost | The key fingerprint is: 2026-01-03 00:24:07.666268 | controller -> localhost | SHA256:Ew4GtWf5rM9Hvy7QDJTK9wTwlvcfktghz+K270ybfVY zuul-build-sshkey 2026-01-03 00:24:07.666301 | controller -> localhost | The key's randomart image is: 2026-01-03 00:24:07.666331 | controller -> localhost | +---[RSA 2048]----+ 2026-01-03 00:24:07.666361 | controller -> localhost | | ... .. . | 2026-01-03 00:24:07.666391 | controller -> localhost | | . . o+. | 2026-01-03 00:24:07.666422 | controller -> localhost | | +.=o+o.. | 2026-01-03 00:24:07.666450 | controller -> localhost | | . =o=o.B.o | 2026-01-03 00:24:07.666479 | controller -> localhost | | S.oO *.. | 2026-01-03 00:24:07.666523 | controller -> localhost | | oo * ..E| 2026-01-03 00:24:07.666558 | controller -> localhost | | . = o o| 2026-01-03 00:24:07.666597 | controller -> localhost | | o. * = o| 2026-01-03 00:24:07.666639 | controller -> localhost | | oooOo+.| 2026-01-03 00:24:07.666677 | controller -> localhost | +----[SHA256]-----+ 2026-01-03 00:24:07.666775 | controller -> localhost | ok: Runtime: 0:00:00.027348 2026-01-03 00:24:07.677912 | 2026-01-03 00:24:07.678062 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-03 00:24:07.711817 | controller | ok 2026-01-03 00:24:07.726465 | controller | included: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-03 00:24:07.740000 | 2026-01-03 00:24:07.740129 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-03 00:24:07.756810 | controller | skipping: Conditional result was False 2026-01-03 00:24:07.765004 | 2026-01-03 00:24:07.765141 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-03 00:24:08.935669 | controller | changed 2026-01-03 00:24:08.948416 | 2026-01-03 00:24:08.948576 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-03 00:24:09.637455 | controller | ok 2026-01-03 00:24:09.643861 | 2026-01-03 00:24:09.643950 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-03 00:24:12.754867 | controller | changed 2026-01-03 00:24:12.762160 | 2026-01-03 00:24:12.762231 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-03 00:24:15.788128 | controller | changed 2026-01-03 00:24:15.799400 | 2026-01-03 00:24:15.799578 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-03 00:24:15.827570 | controller | skipping: Conditional result was False 2026-01-03 00:24:15.837815 | 2026-01-03 00:24:15.837921 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-03 00:24:16.285900 | controller -> localhost | changed 2026-01-03 00:24:16.305144 | 2026-01-03 00:24:16.305322 | TASK [add-build-sshkey : Add back temp key] 2026-01-03 00:24:16.609705 | controller -> localhost | Identity added: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/1af79657b06f4e4d846215db77b2f53d_id_rsa (zuul-build-sshkey) 2026-01-03 00:24:16.610057 | controller -> localhost | ok: Runtime: 0:00:00.011661 2026-01-03 00:24:16.623438 | 2026-01-03 00:24:16.623640 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-03 00:24:17.592213 | controller | ok 2026-01-03 00:24:17.600260 | 2026-01-03 00:24:17.600611 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-03 00:24:17.627455 | controller | skipping: Conditional result was False 2026-01-03 00:24:17.645938 | 2026-01-03 00:24:17.646099 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-03 00:24:17.669768 | controller | ok 2026-01-03 00:24:17.686716 | 2026-01-03 00:24:17.686847 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-03 00:24:17.945266 | controller -> localhost | ok 2026-01-03 00:24:17.952657 | 2026-01-03 00:24:17.952762 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-03 00:24:17.983062 | controller | ok 2026-01-03 00:24:18.001536 | controller | included: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-03 00:24:18.008919 | 2026-01-03 00:24:18.009000 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-03 00:24:18.360213 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-03 00:24:18.360464 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/1af79657b06f4e4d846215db77b2f53d_id_ecdsa. 2026-01-03 00:24:18.360494 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/1af79657b06f4e4d846215db77b2f53d_id_ecdsa.pub. 2026-01-03 00:24:18.360525 | controller -> localhost | The key fingerprint is: 2026-01-03 00:24:18.360546 | controller -> localhost | SHA256:N3HYSpu6zYeP4PHUK6yHQE9ZPuZQeusz6jowNxuusYo zuul-build-sshkey 2026-01-03 00:24:18.360566 | controller -> localhost | The key's randomart image is: 2026-01-03 00:24:18.360585 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-03 00:24:18.360604 | controller -> localhost | | | 2026-01-03 00:24:18.360622 | controller -> localhost | | oo | 2026-01-03 00:24:18.360640 | controller -> localhost | | *+ o | 2026-01-03 00:24:18.360658 | controller -> localhost | | . =.=* | 2026-01-03 00:24:18.360676 | controller -> localhost | | . oS=*o | 2026-01-03 00:24:18.360693 | controller -> localhost | | o = .ooo | 2026-01-03 00:24:18.360711 | controller -> localhost | | .= =++... | 2026-01-03 00:24:18.360785 | controller -> localhost | | . o+..OO... | 2026-01-03 00:24:18.360807 | controller -> localhost | |E ..o..+*+=*o | 2026-01-03 00:24:18.360825 | controller -> localhost | +----[SHA256]-----+ 2026-01-03 00:24:18.360881 | controller -> localhost | ok: Runtime: 0:00:00.008343 2026-01-03 00:24:18.368444 | 2026-01-03 00:24:18.368573 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-03 00:24:18.401188 | controller | ok 2026-01-03 00:24:18.410173 | controller | included: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-03 00:24:18.421803 | 2026-01-03 00:24:18.421942 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-03 00:24:18.446028 | controller | skipping: Conditional result was False 2026-01-03 00:24:18.517333 | 2026-01-03 00:24:18.517494 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-03 00:24:19.477079 | controller | changed 2026-01-03 00:24:19.502704 | 2026-01-03 00:24:19.502964 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-03 00:24:20.193034 | controller | ok 2026-01-03 00:24:20.199897 | 2026-01-03 00:24:20.199973 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-03 00:24:23.278452 | controller | changed 2026-01-03 00:24:23.284991 | 2026-01-03 00:24:23.285064 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-03 00:24:26.338606 | controller | changed 2026-01-03 00:24:26.353927 | 2026-01-03 00:24:26.354121 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-03 00:24:26.380874 | controller | skipping: Conditional result was False 2026-01-03 00:24:26.391780 | 2026-01-03 00:24:26.391939 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-03 00:24:26.632387 | controller -> localhost | changed 2026-01-03 00:24:26.651932 | 2026-01-03 00:24:26.652084 | TASK [add-build-sshkey : Add back temp key] 2026-01-03 00:24:26.949807 | controller -> localhost | Identity added: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/1af79657b06f4e4d846215db77b2f53d_id_ecdsa (zuul-build-sshkey) 2026-01-03 00:24:26.950432 | controller -> localhost | ok: Runtime: 0:00:00.013895 2026-01-03 00:24:26.978271 | 2026-01-03 00:24:26.978544 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-03 00:24:27.703220 | controller | ok 2026-01-03 00:24:27.710707 | 2026-01-03 00:24:27.710863 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-03 00:24:27.736917 | controller | skipping: Conditional result was False 2026-01-03 00:24:27.750459 | 2026-01-03 00:24:27.750625 | TASK [include_role : remove-zuul-sshkey] 2026-01-03 00:24:27.766343 | controller | skipping: Conditional result was False 2026-01-03 00:24:27.776063 | 2026-01-03 00:24:27.776162 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-03 00:24:28.466323 | controller | ok: "logs" 2026-01-03 00:24:28.466979 | controller | ok: All items complete 2026-01-03 00:24:28.467052 | 2026-01-03 00:24:29.106801 | controller | ok: "artifacts" 2026-01-03 00:24:29.748520 | controller | ok: "docs" 2026-01-03 00:24:29.760426 | 2026-01-03 00:24:29.760559 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-03 00:24:30.453653 | controller | changed: "logs" 2026-01-03 00:24:31.099595 | controller | changed: "artifacts" 2026-01-03 00:24:31.716640 | controller | changed: "docs" 2026-01-03 00:24:31.767111 | 2026-01-03 00:24:31.767287 | PLAY RECAP 2026-01-03 00:24:31.767352 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-03 00:24:31.767389 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-03 00:24:31.767415 | 2026-01-03 00:24:31.938135 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-03 00:24:31.939217 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-03 00:24:32.599890 | 2026-01-03 00:24:32.600214 | PLAY [all] 2026-01-03 00:24:32.630929 | 2026-01-03 00:24:32.631133 | TASK [Install binary dependencies] 2026-01-03 00:24:32.691051 | controller | ok 2026-01-03 00:24:32.712409 | 2026-01-03 00:24:32.712554 | TASK [bindep : Include find tasks] 2026-01-03 00:24:32.744210 | controller | ok 2026-01-03 00:24:32.753082 | controller | included: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-03 00:24:32.760082 | 2026-01-03 00:24:32.760164 | TASK [bindep : Look for bindep.txt] 2026-01-03 00:24:33.755477 | controller | ok 2026-01-03 00:24:33.764381 | 2026-01-03 00:24:33.764522 | TASK [bindep : Define bindep_file fact] 2026-01-03 00:24:33.791519 | controller | skipping: Conditional result was False 2026-01-03 00:24:33.800536 | 2026-01-03 00:24:33.800640 | TASK [bindep : Look for other-requirements.txt] 2026-01-03 00:24:34.477246 | controller | ok 2026-01-03 00:24:34.486270 | 2026-01-03 00:24:34.486454 | TASK [bindep : Define bindep_file fact] 2026-01-03 00:24:34.523055 | controller | skipping: Conditional result was False 2026-01-03 00:24:34.532676 | 2026-01-03 00:24:34.532797 | TASK [bindep : Look for bindep fallback file] 2026-01-03 00:24:34.569698 | controller | skipping: Conditional result was False 2026-01-03 00:24:34.578653 | 2026-01-03 00:24:34.578766 | TASK [bindep : Define bindep_file fact] 2026-01-03 00:24:34.606651 | controller | skipping: Conditional result was False 2026-01-03 00:24:34.619588 | 2026-01-03 00:24:34.619819 | TASK [bindep : Include bindep tasks] 2026-01-03 00:24:34.646588 | controller | skipping: Conditional result was False 2026-01-03 00:24:34.657674 | 2026-01-03 00:24:34.657833 | TASK [bindep : Include install tasks] 2026-01-03 00:24:34.684418 | controller | skipping: Conditional result was False 2026-01-03 00:24:34.694340 | 2026-01-03 00:24:34.694443 | LOOP [bindep : Include package tasks] 2026-01-03 00:24:34.767918 | 2026-01-03 00:24:34.768100 | TASK [Run test-setup role] 2026-01-03 00:24:34.788315 | controller | ok 2026-01-03 00:24:34.806966 | 2026-01-03 00:24:34.807082 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-03 00:24:35.462481 | controller | ok 2026-01-03 00:24:35.469513 | 2026-01-03 00:24:35.469595 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-03 00:24:35.845679 | controller | skipping: Conditional result was False 2026-01-03 00:24:35.900110 | 2026-01-03 00:24:35.900270 | PLAY RECAP 2026-01-03 00:24:35.900350 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-03 00:24:35.900384 | 2026-01-03 00:24:36.062289 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-03 00:24:36.063258 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-03 00:24:36.775763 | 2026-01-03 00:24:36.775962 | PLAY [controller] 2026-01-03 00:24:36.799281 | 2026-01-03 00:24:36.799492 | TASK [Create the /root directory] 2026-01-03 00:24:37.944419 | controller | ok 2026-01-03 00:24:37.954131 | 2026-01-03 00:24:37.954320 | TASK [Install glibc-langpack-en] 2026-01-03 00:24:46.105514 | controller | ok: Nothing to do 2026-01-03 00:24:46.111629 | 2026-01-03 00:24:46.111703 | TASK [Ensure controller directory exists] 2026-01-03 00:24:46.977186 | controller | changed 2026-01-03 00:24:46.991853 | 2026-01-03 00:24:46.992076 | TASK [Install container runtime] 2026-01-03 00:24:47.059562 | controller | ok 2026-01-03 00:24:47.112619 | 2026-01-03 00:24:47.112810 | LOOP [ensure-podman : Find distribution installation] 2026-01-03 00:24:47.138453 | controller | ok: "/var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-03 00:24:47.147220 | controller | included: /var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-03 00:24:47.153966 | 2026-01-03 00:24:47.154055 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-03 00:26:53.892227 | controller | changed 2026-01-03 00:26:53.907471 | 2026-01-03 00:26:53.907667 | TASK [ensure-podman : Fetch podman version] 2026-01-03 00:26:55.102771 | controller | Client: Podman Engine 2026-01-03 00:26:55.102897 | controller | Version: 4.6.2 2026-01-03 00:26:55.102943 | controller | API Version: 4.6.2 2026-01-03 00:26:55.102984 | controller | Go Version: go1.19.12 2026-01-03 00:26:55.103042 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-03 00:26:55.103156 | controller | OS/Arch: linux/amd64 2026-01-03 00:26:55.282075 | controller | ok: Runtime: 0:00:00.287617 2026-01-03 00:26:55.296093 | 2026-01-03 00:26:55.296237 | TASK [ensure-podman : Print podman version installed] 2026-01-03 00:26:55.341292 | Podman version: Client: Podman Engine 2026-01-03 00:26:55.341581 | Version: 4.6.2 2026-01-03 00:26:55.341646 | API Version: 4.6.2 2026-01-03 00:26:55.341694 | Go Version: go1.19.12 2026-01-03 00:26:55.341788 | Built: Mon Aug 28 19:38:31 2023 2026-01-03 00:26:55.341843 | OS/Arch: linux/amd64 2026-01-03 00:26:55.356115 | 2026-01-03 00:26:55.356262 | TASK [ensure-podman : Validate podman engine] 2026-01-03 00:26:55.716208 | controller | skipping: Conditional result was False 2026-01-03 00:26:55.731387 | 2026-01-03 00:26:55.731555 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-03 00:26:55.758980 | controller | skipping: Conditional result was False 2026-01-03 00:26:55.773616 | 2026-01-03 00:26:55.773789 | TASK [Ensure python3.8 is present] 2026-01-03 00:26:55.787954 | controller | skipping: Conditional result was False 2026-01-03 00:26:55.795531 | 2026-01-03 00:26:55.795645 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-03 00:26:55.819832 | controller | ok 2026-01-03 00:26:55.845617 | 2026-01-03 00:26:55.845771 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-03 00:27:00.078968 | controller | ok: Nothing to do 2026-01-03 00:27:00.086679 | 2026-01-03 00:27:00.086784 | TASK [our-ensure-python : Also install python3-devel] 2026-01-03 00:27:16.551559 | controller | changed 2026-01-03 00:27:16.563721 | 2026-01-03 00:27:16.563828 | TASK [Run ensure-virtualenv role] 2026-01-03 00:27:16.592185 | controller | ok 2026-01-03 00:27:16.616113 | 2026-01-03 00:27:16.616252 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-03 00:27:17.481936 | controller | /usr/bin/virtualenv 2026-01-03 00:27:18.038338 | controller | ok: Runtime: 0:00:00.006172 2026-01-03 00:27:18.056057 | 2026-01-03 00:27:18.056258 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-03 00:27:18.096988 | controller | skipping: Conditional result was False 2026-01-03 00:27:18.097497 | controller | ok: All items complete 2026-01-03 00:27:18.097556 | 2026-01-03 00:27:18.132852 | 2026-01-03 00:27:18.133098 | TASK [Find the full path of the Python interpreter] 2026-01-03 00:27:18.958180 | controller | /usr/bin/python3 2026-01-03 00:27:19.507501 | controller | ok 2026-01-03 00:27:19.535498 | 2026-01-03 00:27:19.535785 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-03 00:27:21.497920 | controller | created virtual environment CPython3.11.0.final.0-64 in 864ms 2026-01-03 00:27:21.565145 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-03 00:27:21.565224 | 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-03 00:27:21.565239 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-03 00:27:21.565263 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-03 00:27:21.916704 | controller | changed 2026-01-03 00:27:21.933575 | 2026-01-03 00:27:21.933821 | TASK [Set selinux package] 2026-01-03 00:27:21.968465 | controller | ok 2026-01-03 00:27:21.983012 | 2026-01-03 00:27:21.983191 | TASK [Set selinux package (Fedora)] 2026-01-03 00:27:22.045957 | controller | ok 2026-01-03 00:27:22.060927 | 2026-01-03 00:27:22.061093 | TASK [Install selinux into virtualenv] 2026-01-03 00:27:25.055550 | controller | Collecting selinux-please-lie-to-me 2026-01-03 00:27:25.114950 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-03 00:27:25.626758 | controller | Collecting setuptools<50.0.0 2026-01-03 00:27:25.645127 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-03 00:27:25.699616 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.9 MB/s eta 0:00:00 2026-01-03 00:27:25.906749 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-03 00:27:25.907109 | controller | Attempting uninstall: setuptools 2026-01-03 00:27:25.910855 | controller | Found existing installation: setuptools 62.6.0 2026-01-03 00:27:26.021898 | controller | Uninstalling setuptools-62.6.0: 2026-01-03 00:27:26.037246 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-03 00:27:26.830167 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-03 00:27:27.049508 | controller | 2026-01-03 00:27:27.417716 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-03 00:27:27.417779 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-03 00:27:27.956118 | controller | ok: Runtime: 0:00:04.508425 2026-01-03 00:27:27.971721 | 2026-01-03 00:27:27.971903 | TASK [Install pytest-forked into virtualenv] 2026-01-03 00:27:29.521416 | controller | Collecting pytest-forked 2026-01-03 00:27:29.586861 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-03 00:27:29.638297 | controller | Collecting py 2026-01-03 00:27:29.643049 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-03 00:27:29.681564 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.5 MB/s eta 0:00:00 2026-01-03 00:27:29.920070 | controller | Collecting pytest>=3.10 2026-01-03 00:27:29.926482 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-03 00:27:29.952105 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 16.7 MB/s eta 0:00:00 2026-01-03 00:27:30.031269 | controller | Collecting iniconfig>=1.0.1 2026-01-03 00:27:30.039099 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-03 00:27:30.112431 | controller | Collecting packaging>=22 2026-01-03 00:27:30.120497 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-03 00:27:30.144066 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 4.1 MB/s eta 0:00:00 2026-01-03 00:27:30.204896 | controller | Collecting pluggy<2,>=1.5 2026-01-03 00:27:30.215449 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-03 00:27:30.316775 | controller | Collecting pygments>=2.7.2 2026-01-03 00:27:30.325431 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-03 00:27:30.360511 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 42.8 MB/s eta 0:00:00 2026-01-03 00:27:30.531168 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-03 00:27:32.862070 | 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-03 00:27:32.877906 | controller | 2026-01-03 00:27:33.102095 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-03 00:27:33.102134 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-03 00:27:33.378827 | controller | ok: Runtime: 0:00:04.282228 2026-01-03 00:27:33.391902 | 2026-01-03 00:27:33.392264 | TASK [Update pip] 2026-01-03 00:27:34.766165 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-03 00:27:35.089639 | controller | Collecting pip 2026-01-03 00:27:35.166790 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-03 00:27:35.243281 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 24.8 MB/s eta 0:00:00 2026-01-03 00:27:35.349399 | controller | Installing collected packages: pip 2026-01-03 00:27:35.352385 | controller | Attempting uninstall: pip 2026-01-03 00:27:35.352420 | controller | Found existing installation: pip 22.2.2 2026-01-03 00:27:35.561950 | controller | Uninstalling pip-22.2.2: 2026-01-03 00:27:35.589869 | controller | Successfully uninstalled pip-22.2.2 2026-01-03 00:27:37.329507 | controller | Successfully installed pip-25.3 2026-01-03 00:27:37.776087 | controller | ok: Runtime: 0:00:03.325994 2026-01-03 00:27:37.789404 | 2026-01-03 00:27:37.789685 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-03 00:27:38.643665 | controller | changed 2026-01-03 00:27:38.652534 | 2026-01-03 00:27:38.652669 | TASK [Install ansible into virtualenv] 2026-01-03 00:27:39.842000 | controller | Processing ./src/github.com/ansible/ansible 2026-01-03 00:27:39.851957 | controller | Installing build dependencies: started 2026-01-03 00:27:41.745544 | controller | Installing build dependencies: finished with status 'done' 2026-01-03 00:27:41.753105 | controller | Getting requirements to build wheel: started 2026-01-03 00:27:43.144297 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-03 00:27:43.145848 | controller | Preparing metadata (pyproject.toml): started 2026-01-03 00:27:44.040430 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-03 00:27:44.046455 | 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-03 00:27:44.051518 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-03 00:27:44.537517 | controller | ERROR 2026-01-03 00:27:44.537886 | controller | { 2026-01-03 00:27:44.537922 | controller | "delta": "0:00:04.936750", 2026-01-03 00:27:44.537942 | controller | "end": "2026-01-03 00:27:44.203022", 2026-01-03 00:27:44.537960 | controller | "msg": "non-zero return code", 2026-01-03 00:27:44.537991 | controller | "rc": 1, 2026-01-03 00:27:44.538009 | controller | "start": "2026-01-03 00:27:39.266272" 2026-01-03 00:27:44.538025 | controller | } failure 2026-01-03 00:27:44.540514 | 2026-01-03 00:27:44.540567 | PLAY RECAP 2026-01-03 00:27:44.540613 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-03 00:27:44.540634 | 2026-01-03 00:27:44.705903 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-03 00:27:44.708097 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-03 00:27:45.416167 | 2026-01-03 00:27:45.416378 | PLAY [all] 2026-01-03 00:27:45.441580 | 2026-01-03 00:27:45.441721 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-03 00:27:47.308513 | controller | changed: non-zero return code 2026-01-03 00:27:47.323865 | 2026-01-03 00:27:47.324035 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-03 00:27:47.341940 | controller | skipping: Conditional result was False 2026-01-03 00:27:47.349966 | 2026-01-03 00:27:47.350122 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-03 00:27:47.383193 | 2026-01-03 00:27:47.383390 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-03 00:27:47.414786 | 2026-01-03 00:27:47.414969 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-03 00:27:47.430447 | controller | skipping: Conditional result was False 2026-01-03 00:27:47.438685 | 2026-01-03 00:27:47.438801 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-03 00:27:47.460863 | 2026-01-03 00:27:47.461039 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-03 00:27:47.476141 | controller | skipping: Conditional result was False 2026-01-03 00:27:47.483208 | 2026-01-03 00:27:47.483280 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-03 00:27:47.508317 | controller | skipping: Conditional result was False 2026-01-03 00:27:47.515361 | 2026-01-03 00:27:47.515462 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-03 00:27:47.541828 | controller | skipping: Conditional result was False 2026-01-03 00:27:47.595261 | 2026-01-03 00:27:47.595437 | PLAY RECAP 2026-01-03 00:27:47.595502 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-03 00:27:47.595534 | 2026-01-03 00:27:47.814750 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-03 00:27:47.815850 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-03 00:27:48.414225 | 2026-01-03 00:27:48.414400 | PLAY [all:!appliance*] 2026-01-03 00:27:48.439337 | 2026-01-03 00:27:48.439467 | TASK [unregister the node] 2026-01-03 00:27:48.796526 | controller | skipping: Conditional result was False 2026-01-03 00:27:48.805257 | 2026-01-03 00:27:48.805351 | TASK [include_role : fetch-output] 2026-01-03 00:27:48.840136 | controller | ok 2026-01-03 00:27:48.868687 | 2026-01-03 00:27:48.868894 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-03 00:27:48.925931 | controller | skipping: Conditional result was False 2026-01-03 00:27:48.935910 | 2026-01-03 00:27:48.936024 | TASK [fetch-output : Set log path for single node] 2026-01-03 00:27:48.981540 | controller | ok 2026-01-03 00:27:48.990249 | 2026-01-03 00:27:48.990344 | LOOP [fetch-output : Ensure local output dirs] 2026-01-03 00:27:49.469757 | controller -> localhost | ok: "/var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/logs" 2026-01-03 00:27:49.726581 | controller -> localhost | changed: "/var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/artifacts" 2026-01-03 00:27:49.963188 | controller -> localhost | changed: "/var/lib/zuul/builds/1af79657b06f4e4d846215db77b2f53d/work/docs" 2026-01-03 00:27:49.997406 | 2026-01-03 00:27:49.997646 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-03 00:27:52.257776 | controller | changed: 2026-01-03 00:27:52.258007 | controller | .d..t...... ./ 2026-01-03 00:27:52.258035 | controller | cd+++++++++ controller/ 2026-01-03 00:27:52.258068 | controller | changed: All items complete 2026-01-03 00:27:52.258088 | 2026-01-03 00:27:54.293654 | controller | changed: .d..t...... ./ 2026-01-03 00:27:56.358165 | controller | changed: .d..t...... ./ 2026-01-03 00:27:56.387089 | 2026-01-03 00:27:56.387326 | TASK [include_role : fetch-output-openshift] 2026-01-03 00:27:56.414657 | controller | skipping: Conditional result was False 2026-01-03 00:27:56.430356 | 2026-01-03 00:27:56.430538 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-03 00:27:56.483158 | controller | skipping: Conditional result was False 2026-01-03 00:27:56.494127 | controller | skipping: Conditional result was False 2026-01-03 00:27:56.544011 | 2026-01-03 00:27:56.544161 | PLAY [localhost] 2026-01-03 00:27:56.562550 | 2026-01-03 00:27:56.562680 | TASK [Run Zuul manifest role] 2026-01-03 00:27:56.585202 | localhost | ok 2026-01-03 00:27:56.605573 | 2026-01-03 00:27:56.605793 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-03 00:27:57.062815 | localhost | changed 2026-01-03 00:27:57.069214 | 2026-01-03 00:27:57.069306 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-03 00:27:57.101712 | localhost | ok 2026-01-03 00:27:57.114434 | 2026-01-03 00:27:57.114603 | TASK [Set zuul-log-path fact] 2026-01-03 00:27:57.147408 | localhost | ok 2026-01-03 00:27:57.195617 | 2026-01-03 00:27:57.195775 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-03 00:27:57.225613 | localhost | ok 2026-01-03 00:27:57.234326 | 2026-01-03 00:27:57.234451 | LOOP [Run upload-logs-swift role] 2026-01-03 00:27:57.272982 | localhost | Output suppressed because no_log was given 2026-01-03 00:27:57.331869 | 2026-01-03 00:27:57.332390 | TASK [Set zuul-log-path fact] 2026-01-03 00:27:57.360475 | localhost | skipping: Conditional result was False 2026-01-03 00:27:57.369546 | 2026-01-03 00:27:57.369630 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-03 00:27:57.782813 | localhost -> localhost | ok: Runtime: 0:00:00.010534 2026-01-03 00:27:57.796172 | 2026-01-03 00:27:57.796332 | TASK [upload-logs-swift : Upload logs to swift]