2026-02-14 00:21:39.542583 | Job console starting... 2026-02-14 00:21:39.553239 | Updating repositories 2026-02-14 00:21:39.705571 | Preparing job workspace 2026-02-14 00:21:48.976191 | Running Ansible setup... 2026-02-14 00:21:53.871963 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-14 00:21:54.494354 | 2026-02-14 00:21:54.494484 | PLAY [localhost] 2026-02-14 00:21:54.503593 | 2026-02-14 00:21:54.503717 | TASK [Gathering Facts] 2026-02-14 00:21:55.480842 | localhost | ok 2026-02-14 00:21:55.509851 | 2026-02-14 00:21:55.510059 | TASK [Setup log path fact] 2026-02-14 00:21:55.530089 | localhost | ok 2026-02-14 00:21:55.548793 | 2026-02-14 00:21:55.548910 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-14 00:21:55.589434 | localhost | ok 2026-02-14 00:21:55.598043 | 2026-02-14 00:21:55.598155 | TASK [emit-job-header : Print job information] 2026-02-14 00:21:55.626232 | # Job Information 2026-02-14 00:21:55.626398 | Ansible Version: 2.15.12 2026-02-14 00:21:55.626430 | Job: ansible-test-sanity-docker-milestone 2026-02-14 00:21:55.626451 | Pipeline: periodic 2026-02-14 00:21:55.626469 | Executor: ze04.softwarefactory-project.io 2026-02-14 00:21:55.626487 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-14 00:21:55.626507 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/0b9/ansible/0b9f649474324a3e8e21be865c815cdc/ 2026-02-14 00:21:55.626526 | Event ID: 343d777a1a684010b2f6abf2a6f30cb9 2026-02-14 00:21:55.630268 | 2026-02-14 00:21:55.630344 | LOOP [emit-job-header : Print node information] 2026-02-14 00:21:55.761886 | localhost | ok: 2026-02-14 00:21:55.762097 | localhost | # Node Information 2026-02-14 00:21:55.762126 | localhost | Inventory Hostname: controller 2026-02-14 00:21:55.762147 | localhost | Hostname: np0005619380 2026-02-14 00:21:55.762167 | localhost | Username: zuul 2026-02-14 00:21:55.762188 | localhost | Distro: Fedora 37 2026-02-14 00:21:55.762206 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-14 00:21:55.762227 | localhost | Region: ca-ymq-1 2026-02-14 00:21:55.762247 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-14 00:21:55.762265 | localhost | Product Name: OpenStack Nova 2026-02-14 00:21:55.762292 | localhost | Interface IP: 162.253.55.12 2026-02-14 00:21:55.774861 | 2026-02-14 00:21:55.774981 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-14 00:21:56.196922 | localhost -> localhost | changed 2026-02-14 00:21:56.203399 | 2026-02-14 00:21:56.203487 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-14 00:21:57.127446 | localhost -> localhost | changed 2026-02-14 00:21:57.148407 | 2026-02-14 00:21:57.148490 | PLAY [all:!appliance*] 2026-02-14 00:21:57.167350 | 2026-02-14 00:21:57.167484 | TASK [include_role : start-zuul-console] 2026-02-14 00:21:57.188638 | controller | ok 2026-02-14 00:21:57.207145 | 2026-02-14 00:21:57.207277 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-14 00:21:57.611802 | controller | ok 2026-02-14 00:21:57.628460 | 2026-02-14 00:21:57.628606 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-14 00:22:11.933887 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-14 00:22:11.943956 | 2026-02-14 00:22:11.944048 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-14 00:22:12.508842 | controller | skipping: Conditional result was False 2026-02-14 00:22:12.528964 | 2026-02-14 00:22:12.529191 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-14 00:22:12.557111 | controller | skipping: Conditional result was False 2026-02-14 00:22:12.577325 | 2026-02-14 00:22:12.577476 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-14 00:22:12.631884 | controller | skipping: Conditional result was False 2026-02-14 00:22:12.640252 | 2026-02-14 00:22:12.640402 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-14 00:22:12.665665 | controller | skipping: Conditional result was False 2026-02-14 00:22:12.672288 | 2026-02-14 00:22:12.672358 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-14 00:22:12.686226 | controller | skipping: Conditional result was False 2026-02-14 00:22:12.692783 | 2026-02-14 00:22:12.692849 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-14 00:22:12.707463 | controller | skipping: Conditional result was False 2026-02-14 00:22:12.720114 | 2026-02-14 00:22:12.720204 | TASK [Disable Fedora Modular] 2026-02-14 00:22:13.055866 | controller | changed 2026-02-14 00:22:13.065282 | 2026-02-14 00:22:13.065377 | TASK [Enable EPEL] 2026-02-14 00:22:13.090473 | controller | skipping: Conditional result was False 2026-02-14 00:22:13.100779 | 2026-02-14 00:22:13.100917 | TASK [Register the RHEL node] 2026-02-14 00:22:13.656188 | 2026-02-14 00:22:13.656396 | TASK [Show the subscription-manager status] 2026-02-14 00:22:14.209315 | controller | skipping: Conditional result was False 2026-02-14 00:22:14.221019 | 2026-02-14 00:22:14.221171 | TASK [Enable EPEL on RHEL] 2026-02-14 00:22:14.795917 | controller | skipping: Conditional result was False 2026-02-14 00:22:14.812650 | 2026-02-14 00:22:14.812914 | TASK [Install git and tox] 2026-02-14 00:23:49.065923 | controller | changed 2026-02-14 00:23:49.084227 | 2026-02-14 00:23:49.084475 | TASK [include_role : prepare-workspace] 2026-02-14 00:23:49.128136 | controller | ok 2026-02-14 00:23:49.175191 | 2026-02-14 00:23:49.175382 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-14 00:23:49.401740 | controller | ok 2026-02-14 00:23:49.452324 | 2026-02-14 00:23:49.452455 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-14 00:24:02.256207 | controller | Output suppressed because no_log was given 2026-02-14 00:24:02.273011 | 2026-02-14 00:24:02.273143 | TASK [include_role : prepare-workspace-openshift] 2026-02-14 00:24:02.308018 | controller | skipping: Conditional result was False 2026-02-14 00:24:02.344025 | 2026-02-14 00:24:02.344182 | PLAY [all:!appliance] 2026-02-14 00:24:02.373317 | 2026-02-14 00:24:02.373545 | TASK [Run add-build-sshkey role (RSA)] 2026-02-14 00:24:02.412178 | controller | ok 2026-02-14 00:24:02.437156 | 2026-02-14 00:24:02.437370 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-14 00:24:02.703900 | controller -> localhost | ok 2026-02-14 00:24:02.714443 | 2026-02-14 00:24:02.714569 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-14 00:24:02.741248 | controller | ok 2026-02-14 00:24:02.756188 | controller | included: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-14 00:24:02.762449 | 2026-02-14 00:24:02.762514 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-14 00:24:03.430192 | controller -> localhost | Generating public/private rsa key pair. 2026-02-14 00:24:03.430409 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/0b9f649474324a3e8e21be865c815cdc_id_rsa. 2026-02-14 00:24:03.430439 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/0b9f649474324a3e8e21be865c815cdc_id_rsa.pub. 2026-02-14 00:24:03.430461 | controller -> localhost | The key fingerprint is: 2026-02-14 00:24:03.430481 | controller -> localhost | SHA256:msTS+V/yD9k3s6yaVctQ2Evi0AI7+Lvz6hDDnOfDYqo zuul-build-sshkey 2026-02-14 00:24:03.430500 | controller -> localhost | The key's randomart image is: 2026-02-14 00:24:03.430519 | controller -> localhost | +---[RSA 2048]----+ 2026-02-14 00:24:03.430537 | controller -> localhost | | . | 2026-02-14 00:24:03.430556 | controller -> localhost | | . o . o | 2026-02-14 00:24:03.430574 | controller -> localhost | | . o o + + | 2026-02-14 00:24:03.430592 | controller -> localhost | | oo.o . + + .| 2026-02-14 00:24:03.430609 | controller -> localhost | | . =*So o o | 2026-02-14 00:24:03.430637 | controller -> localhost | | o +* . o+ .| 2026-02-14 00:24:03.430661 | controller -> localhost | | o+.=. +..=.| 2026-02-14 00:24:03.430699 | controller -> localhost | | o ooo+o...+| 2026-02-14 00:24:03.430722 | controller -> localhost | | E.. .+=+oooo | 2026-02-14 00:24:03.430744 | controller -> localhost | +----[SHA256]-----+ 2026-02-14 00:24:03.430788 | controller -> localhost | ok: Runtime: 0:00:00.141710 2026-02-14 00:24:03.439134 | 2026-02-14 00:24:03.439242 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-14 00:24:03.482827 | controller | ok 2026-02-14 00:24:03.494976 | controller | included: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-14 00:24:03.507841 | 2026-02-14 00:24:03.507932 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-14 00:24:03.535577 | controller | skipping: Conditional result was False 2026-02-14 00:24:03.543719 | 2026-02-14 00:24:03.543821 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-14 00:24:04.028932 | controller | changed 2026-02-14 00:24:04.037514 | 2026-02-14 00:24:04.037600 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-14 00:24:04.278099 | controller | ok 2026-02-14 00:24:04.286150 | 2026-02-14 00:24:04.286285 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-14 00:24:04.920827 | controller | changed 2026-02-14 00:24:04.978746 | 2026-02-14 00:24:04.978948 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-14 00:24:05.674502 | controller | changed 2026-02-14 00:24:05.695445 | 2026-02-14 00:24:05.695671 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-14 00:24:05.726712 | controller | skipping: Conditional result was False 2026-02-14 00:24:05.744550 | 2026-02-14 00:24:05.744820 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-14 00:24:06.172653 | controller -> localhost | changed 2026-02-14 00:24:06.204024 | 2026-02-14 00:24:06.204209 | TASK [add-build-sshkey : Add back temp key] 2026-02-14 00:24:06.553320 | controller -> localhost | Identity added: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/0b9f649474324a3e8e21be865c815cdc_id_rsa (zuul-build-sshkey) 2026-02-14 00:24:06.553791 | controller -> localhost | ok: Runtime: 0:00:00.015687 2026-02-14 00:24:06.569336 | 2026-02-14 00:24:06.569484 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-14 00:24:06.901939 | controller | ok 2026-02-14 00:24:06.916167 | 2026-02-14 00:24:06.916390 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-14 00:24:06.960163 | controller | skipping: Conditional result was False 2026-02-14 00:24:06.993092 | 2026-02-14 00:24:06.993274 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-14 00:24:07.031429 | controller | ok 2026-02-14 00:24:07.057535 | 2026-02-14 00:24:07.057736 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-14 00:24:07.412608 | controller -> localhost | ok 2026-02-14 00:24:07.419840 | 2026-02-14 00:24:07.419983 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-14 00:24:07.463131 | controller | ok 2026-02-14 00:24:07.474766 | controller | included: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-14 00:24:07.480815 | 2026-02-14 00:24:07.480880 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-14 00:24:07.883021 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-14 00:24:07.883258 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/0b9f649474324a3e8e21be865c815cdc_id_ecdsa. 2026-02-14 00:24:07.883287 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/0b9f649474324a3e8e21be865c815cdc_id_ecdsa.pub. 2026-02-14 00:24:07.883317 | controller -> localhost | The key fingerprint is: 2026-02-14 00:24:07.883338 | controller -> localhost | SHA256:H8oCMstmotM6vzjqDtatDh2HvXdhbQI8E8s5RaHQWHw zuul-build-sshkey 2026-02-14 00:24:07.883358 | controller -> localhost | The key's randomart image is: 2026-02-14 00:24:07.883376 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-14 00:24:07.883394 | controller -> localhost | | .=o.+. | 2026-02-14 00:24:07.883411 | controller -> localhost | | .+o*E | 2026-02-14 00:24:07.883428 | controller -> localhost | | @. | 2026-02-14 00:24:07.883445 | controller -> localhost | | o = . | 2026-02-14 00:24:07.883462 | controller -> localhost | | oo.o S+.o | 2026-02-14 00:24:07.883478 | controller -> localhost | | .o++....o+. | 2026-02-14 00:24:07.883495 | controller -> localhost | |o+=o o..o.. | 2026-02-14 00:24:07.883511 | controller -> localhost | |B=o . ... | 2026-02-14 00:24:07.883527 | controller -> localhost | |OO++ | 2026-02-14 00:24:07.883543 | controller -> localhost | +----[SHA256]-----+ 2026-02-14 00:24:07.883586 | controller -> localhost | ok: Runtime: 0:00:00.009750 2026-02-14 00:24:07.891491 | 2026-02-14 00:24:07.891587 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-14 00:24:07.934467 | controller | ok 2026-02-14 00:24:07.944265 | controller | included: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-14 00:24:07.954903 | 2026-02-14 00:24:07.955006 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-14 00:24:07.991770 | controller | skipping: Conditional result was False 2026-02-14 00:24:07.999532 | 2026-02-14 00:24:07.999607 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-14 00:24:08.291521 | controller | changed 2026-02-14 00:24:08.304488 | 2026-02-14 00:24:08.304659 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-14 00:24:08.539809 | controller | ok 2026-02-14 00:24:08.557212 | 2026-02-14 00:24:08.557514 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-14 00:24:09.205345 | controller | changed 2026-02-14 00:24:09.221002 | 2026-02-14 00:24:09.221227 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-14 00:24:09.871596 | controller | changed 2026-02-14 00:24:09.886345 | 2026-02-14 00:24:09.886485 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-14 00:24:09.925549 | controller | skipping: Conditional result was False 2026-02-14 00:24:09.941383 | 2026-02-14 00:24:09.941657 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-14 00:24:10.268750 | controller -> localhost | changed 2026-02-14 00:24:10.296299 | 2026-02-14 00:24:10.296484 | TASK [add-build-sshkey : Add back temp key] 2026-02-14 00:24:10.633904 | controller -> localhost | Identity added: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/0b9f649474324a3e8e21be865c815cdc_id_ecdsa (zuul-build-sshkey) 2026-02-14 00:24:10.634432 | controller -> localhost | ok: Runtime: 0:00:00.009241 2026-02-14 00:24:10.648837 | 2026-02-14 00:24:10.648972 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-14 00:24:10.866459 | controller | ok 2026-02-14 00:24:10.879226 | 2026-02-14 00:24:10.879373 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-14 00:24:10.929176 | controller | skipping: Conditional result was False 2026-02-14 00:24:10.957469 | 2026-02-14 00:24:10.957673 | TASK [include_role : remove-zuul-sshkey] 2026-02-14 00:24:10.986323 | controller | skipping: Conditional result was False 2026-02-14 00:24:10.997770 | 2026-02-14 00:24:10.997885 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-14 00:24:11.242737 | controller | ok: "logs" 2026-02-14 00:24:11.244061 | controller | ok: All items complete 2026-02-14 00:24:11.244174 | 2026-02-14 00:24:11.445270 | controller | ok: "artifacts" 2026-02-14 00:24:11.638301 | controller | ok: "docs" 2026-02-14 00:24:11.655869 | 2026-02-14 00:24:11.656013 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-14 00:24:11.910878 | controller | changed: "logs" 2026-02-14 00:24:12.106403 | controller | changed: "artifacts" 2026-02-14 00:24:12.294316 | controller | changed: "docs" 2026-02-14 00:24:12.352889 | 2026-02-14 00:24:12.353051 | PLAY RECAP 2026-02-14 00:24:12.353116 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-14 00:24:12.353152 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-14 00:24:12.353177 | 2026-02-14 00:24:12.511160 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-14 00:24:12.513093 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-14 00:24:13.174775 | 2026-02-14 00:24:13.174918 | PLAY [all] 2026-02-14 00:24:13.204178 | 2026-02-14 00:24:13.204324 | TASK [Install binary dependencies] 2026-02-14 00:24:13.294480 | controller | ok 2026-02-14 00:24:13.331658 | 2026-02-14 00:24:13.331901 | TASK [bindep : Include find tasks] 2026-02-14 00:24:13.390512 | controller | ok 2026-02-14 00:24:13.405884 | controller | included: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-14 00:24:13.416549 | 2026-02-14 00:24:13.416668 | TASK [bindep : Look for bindep.txt] 2026-02-14 00:24:13.828527 | controller | ok 2026-02-14 00:24:13.844856 | 2026-02-14 00:24:13.845040 | TASK [bindep : Define bindep_file fact] 2026-02-14 00:24:13.874046 | controller | skipping: Conditional result was False 2026-02-14 00:24:13.887500 | 2026-02-14 00:24:13.887646 | TASK [bindep : Look for other-requirements.txt] 2026-02-14 00:24:14.118891 | controller | ok 2026-02-14 00:24:14.129804 | 2026-02-14 00:24:14.129980 | TASK [bindep : Define bindep_file fact] 2026-02-14 00:24:14.166138 | controller | skipping: Conditional result was False 2026-02-14 00:24:14.182514 | 2026-02-14 00:24:14.182771 | TASK [bindep : Look for bindep fallback file] 2026-02-14 00:24:14.222258 | controller | skipping: Conditional result was False 2026-02-14 00:24:14.240288 | 2026-02-14 00:24:14.240505 | TASK [bindep : Define bindep_file fact] 2026-02-14 00:24:14.279899 | controller | skipping: Conditional result was False 2026-02-14 00:24:14.291954 | 2026-02-14 00:24:14.292073 | TASK [bindep : Include bindep tasks] 2026-02-14 00:24:14.328142 | controller | skipping: Conditional result was False 2026-02-14 00:24:14.340063 | 2026-02-14 00:24:14.340189 | TASK [bindep : Include install tasks] 2026-02-14 00:24:14.366395 | controller | skipping: Conditional result was False 2026-02-14 00:24:14.373417 | 2026-02-14 00:24:14.373491 | LOOP [bindep : Include package tasks] 2026-02-14 00:24:14.448689 | 2026-02-14 00:24:14.448983 | TASK [Run test-setup role] 2026-02-14 00:24:14.476818 | controller | ok 2026-02-14 00:24:14.504765 | 2026-02-14 00:24:14.504887 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-14 00:24:14.711794 | controller | ok 2026-02-14 00:24:14.718074 | 2026-02-14 00:24:14.718148 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-14 00:24:15.255472 | controller | skipping: Conditional result was False 2026-02-14 00:24:15.312123 | 2026-02-14 00:24:15.312245 | PLAY RECAP 2026-02-14 00:24:15.312300 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-14 00:24:15.312327 | 2026-02-14 00:24:15.440383 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-14 00:24:15.441362 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-14 00:24:16.066803 | 2026-02-14 00:24:16.066960 | PLAY [controller] 2026-02-14 00:24:16.090013 | 2026-02-14 00:24:16.090157 | TASK [Create the /root directory] 2026-02-14 00:24:16.502321 | controller | ok 2026-02-14 00:24:16.516094 | 2026-02-14 00:24:16.516283 | TASK [Install glibc-langpack-en] 2026-02-14 00:24:20.388531 | controller | ok: Nothing to do 2026-02-14 00:24:20.404026 | 2026-02-14 00:24:20.404248 | TASK [Ensure controller directory exists] 2026-02-14 00:24:20.641994 | controller | changed 2026-02-14 00:24:20.648265 | 2026-02-14 00:24:20.648350 | TASK [Install container runtime] 2026-02-14 00:24:20.717504 | controller | ok 2026-02-14 00:24:20.784935 | 2026-02-14 00:24:20.785106 | LOOP [ensure-podman : Find distribution installation] 2026-02-14 00:24:20.832830 | controller | ok: "/var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-14 00:24:20.841960 | controller | included: /var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-14 00:24:20.848946 | 2026-02-14 00:24:20.849037 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-14 00:25:28.669172 | controller | changed 2026-02-14 00:25:28.686045 | 2026-02-14 00:25:28.686258 | TASK [ensure-podman : Fetch podman version] 2026-02-14 00:25:29.267679 | controller | Client: Podman Engine 2026-02-14 00:25:29.302344 | controller | Version: 4.6.2 2026-02-14 00:25:29.302375 | controller | API Version: 4.6.2 2026-02-14 00:25:29.302385 | controller | Go Version: go1.19.12 2026-02-14 00:25:29.302405 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-14 00:25:29.302415 | controller | OS/Arch: linux/amd64 2026-02-14 00:25:29.742362 | controller | ok: Runtime: 0:00:00.194885 2026-02-14 00:25:29.760299 | 2026-02-14 00:25:29.760483 | TASK [ensure-podman : Print podman version installed] 2026-02-14 00:25:29.804748 | Podman version: Client: Podman Engine 2026-02-14 00:25:29.805032 | Version: 4.6.2 2026-02-14 00:25:29.805094 | API Version: 4.6.2 2026-02-14 00:25:29.805140 | Go Version: go1.19.12 2026-02-14 00:25:29.805181 | Built: Mon Aug 28 19:38:31 2023 2026-02-14 00:25:29.805223 | OS/Arch: linux/amd64 2026-02-14 00:25:29.820016 | 2026-02-14 00:25:29.820160 | TASK [ensure-podman : Validate podman engine] 2026-02-14 00:25:30.375629 | controller | skipping: Conditional result was False 2026-02-14 00:25:30.383074 | 2026-02-14 00:25:30.383182 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-14 00:25:30.411862 | controller | skipping: Conditional result was False 2026-02-14 00:25:30.427343 | 2026-02-14 00:25:30.427513 | TASK [Ensure python3.8 is present] 2026-02-14 00:25:30.453077 | controller | skipping: Conditional result was False 2026-02-14 00:25:30.460378 | 2026-02-14 00:25:30.460452 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-14 00:25:30.493319 | controller | ok 2026-02-14 00:25:30.533174 | 2026-02-14 00:25:30.533365 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-14 00:25:31.949459 | controller | ok: Nothing to do 2026-02-14 00:25:31.958707 | 2026-02-14 00:25:31.958794 | TASK [our-ensure-python : Also install python3-devel] 2026-02-14 00:25:40.816477 | controller | changed 2026-02-14 00:25:40.842433 | 2026-02-14 00:25:40.842654 | TASK [Run ensure-virtualenv role] 2026-02-14 00:25:40.879333 | controller | ok 2026-02-14 00:25:40.919642 | 2026-02-14 00:25:40.919882 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-14 00:25:41.156073 | controller | /usr/bin/virtualenv 2026-02-14 00:25:41.464527 | controller | ok: Runtime: 0:00:00.004824 2026-02-14 00:25:41.480433 | 2026-02-14 00:25:41.480652 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-14 00:25:41.507065 | controller | skipping: Conditional result was False 2026-02-14 00:25:41.507448 | controller | ok: All items complete 2026-02-14 00:25:41.507519 | 2026-02-14 00:25:41.547985 | 2026-02-14 00:25:41.548240 | TASK [Find the full path of the Python interpreter] 2026-02-14 00:25:41.812455 | controller | /usr/bin/python3 2026-02-14 00:25:42.130749 | controller | ok 2026-02-14 00:25:42.144438 | 2026-02-14 00:25:42.144629 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-14 00:25:43.010876 | controller | created virtual environment CPython3.11.0.final.0-64 in 475ms 2026-02-14 00:25:43.027524 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-14 00:25:43.027564 | 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-14 00:25:43.027575 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-14 00:25:43.027589 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-14 00:25:43.204966 | controller | changed 2026-02-14 00:25:43.219490 | 2026-02-14 00:25:43.219638 | TASK [Set selinux package] 2026-02-14 00:25:43.260643 | controller | ok 2026-02-14 00:25:43.275902 | 2026-02-14 00:25:43.276090 | TASK [Set selinux package (Fedora)] 2026-02-14 00:25:43.324421 | controller | ok 2026-02-14 00:25:43.335468 | 2026-02-14 00:25:43.335573 | TASK [Install selinux into virtualenv] 2026-02-14 00:26:08.742219 | controller | Collecting selinux-please-lie-to-me 2026-02-14 00:26:21.013495 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-14 00:26:21.328328 | controller | Collecting setuptools<50.0.0 2026-02-14 00:26:21.334059 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-14 00:26:21.373029 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 22.9 MB/s eta 0:00:00 2026-02-14 00:26:21.453877 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-14 00:26:21.454115 | controller | Attempting uninstall: setuptools 2026-02-14 00:26:21.456624 | controller | Found existing installation: setuptools 62.6.0 2026-02-14 00:26:21.517662 | controller | Uninstalling setuptools-62.6.0: 2026-02-14 00:26:21.526861 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-14 00:26:21.879898 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-14 00:26:33.403938 | controller | 2026-02-14 00:26:33.575474 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-14 00:26:33.575506 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-14 00:26:33.918212 | controller | ok: Runtime: 0:00:50.021738 2026-02-14 00:26:33.934431 | 2026-02-14 00:26:33.934586 | TASK [Install pytest-forked into virtualenv] 2026-02-14 00:26:45.630251 | controller | Collecting pytest-forked 2026-02-14 00:26:57.944656 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-14 00:26:57.978775 | controller | Collecting py 2026-02-14 00:26:57.995185 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-14 00:26:58.033229 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.6 MB/s eta 0:00:00 2026-02-14 00:26:58.144580 | controller | Collecting pytest>=3.10 2026-02-14 00:26:58.147831 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-14 00:26:58.161889 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 34.3 MB/s eta 0:00:00 2026-02-14 00:26:58.200349 | controller | Collecting iniconfig>=1.0.1 2026-02-14 00:26:58.203950 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-14 00:26:58.244846 | controller | Collecting packaging>=22 2026-02-14 00:26:58.248963 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-14 00:26:58.254512 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 20.8 MB/s eta 0:00:00 2026-02-14 00:26:58.285874 | controller | Collecting pluggy<2,>=1.5 2026-02-14 00:26:58.288909 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-14 00:26:58.331419 | controller | Collecting pygments>=2.7.2 2026-02-14 00:26:58.339239 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-14 00:26:58.364124 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 56.0 MB/s eta 0:00:00 2026-02-14 00:26:58.435884 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-14 00:26:59.501979 | 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-14 00:26:59.511080 | controller | 2026-02-14 00:26:59.578857 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-14 00:26:59.578900 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-14 00:27:00.020238 | controller | ok: Runtime: 0:00:25.379814 2026-02-14 00:27:00.033477 | 2026-02-14 00:27:00.033647 | TASK [Update pip] 2026-02-14 00:27:00.585995 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-14 00:27:10.323102 | controller | Collecting pip 2026-02-14 00:27:22.642350 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-14 00:27:22.721114 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 24.1 MB/s eta 0:00:00 2026-02-14 00:27:22.788300 | controller | Installing collected packages: pip 2026-02-14 00:27:22.788395 | controller | Attempting uninstall: pip 2026-02-14 00:27:22.790547 | controller | Found existing installation: pip 22.2.2 2026-02-14 00:27:22.929485 | controller | Uninstalling pip-22.2.2: 2026-02-14 00:27:22.945879 | controller | Successfully uninstalled pip-22.2.2 2026-02-14 00:27:23.746507 | controller | Successfully installed pip-26.0.1 2026-02-14 00:27:24.108813 | controller | ok: Runtime: 0:00:23.547703 2026-02-14 00:27:24.115653 | 2026-02-14 00:27:24.115769 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-14 00:27:24.330877 | controller | changed 2026-02-14 00:27:24.390184 | 2026-02-14 00:27:24.390366 | TASK [Install ansible into virtualenv] 2026-02-14 00:27:24.871381 | controller | Processing ./src/github.com/ansible/ansible 2026-02-14 00:27:24.873927 | controller | Installing build dependencies: started 2026-02-14 00:27:45.590141 | controller | Installing build dependencies: finished with status 'done' 2026-02-14 00:27:45.590911 | controller | Getting requirements to build wheel: started 2026-02-14 00:27:46.334343 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-14 00:27:46.335317 | controller | Preparing metadata (pyproject.toml): started 2026-02-14 00:27:46.799525 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-14 00:27:46.804203 | 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-14 00:27:46.807847 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-14 00:27:46.939058 | controller | ERROR 2026-02-14 00:27:46.939409 | controller | { 2026-02-14 00:27:46.939455 | controller | "delta": "0:00:22.279188", 2026-02-14 00:27:46.939484 | controller | "end": "2026-02-14 00:27:46.873154", 2026-02-14 00:27:46.939527 | controller | "msg": "non-zero return code", 2026-02-14 00:27:46.939579 | controller | "rc": 1, 2026-02-14 00:27:46.939623 | controller | "start": "2026-02-14 00:27:24.593966" 2026-02-14 00:27:46.939649 | controller | } failure 2026-02-14 00:27:46.943570 | 2026-02-14 00:27:46.943639 | PLAY RECAP 2026-02-14 00:27:46.943721 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-14 00:27:46.943758 | 2026-02-14 00:27:47.196423 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-14 00:27:47.199435 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-14 00:27:47.911518 | 2026-02-14 00:27:47.911732 | PLAY [all] 2026-02-14 00:27:47.945860 | 2026-02-14 00:27:47.946061 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-14 00:27:48.219413 | controller | changed: non-zero return code 2026-02-14 00:27:48.229045 | 2026-02-14 00:27:48.229190 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-14 00:27:48.255158 | controller | skipping: Conditional result was False 2026-02-14 00:27:48.266956 | 2026-02-14 00:27:48.267114 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-14 00:27:48.307185 | 2026-02-14 00:27:48.307415 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-14 00:27:48.345894 | 2026-02-14 00:27:48.346170 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-14 00:27:48.373063 | controller | skipping: Conditional result was False 2026-02-14 00:27:48.382135 | 2026-02-14 00:27:48.382251 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-14 00:27:48.415722 | 2026-02-14 00:27:48.415930 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-14 00:27:48.431582 | controller | skipping: Conditional result was False 2026-02-14 00:27:48.439775 | 2026-02-14 00:27:48.439902 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-14 00:27:48.468929 | controller | skipping: Conditional result was False 2026-02-14 00:27:48.475993 | 2026-02-14 00:27:48.476063 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-14 00:27:48.501467 | controller | skipping: Conditional result was False 2026-02-14 00:27:48.531416 | 2026-02-14 00:27:48.531529 | PLAY RECAP 2026-02-14 00:27:48.531585 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-14 00:27:48.531610 | 2026-02-14 00:27:48.682230 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-14 00:27:48.683197 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-14 00:27:49.313043 | 2026-02-14 00:27:49.313191 | PLAY [all:!appliance*] 2026-02-14 00:27:49.345973 | 2026-02-14 00:27:49.346133 | TASK [unregister the node] 2026-02-14 00:27:49.881252 | controller | skipping: Conditional result was False 2026-02-14 00:27:49.897290 | 2026-02-14 00:27:49.897488 | TASK [include_role : fetch-output] 2026-02-14 00:27:49.963022 | controller | ok 2026-02-14 00:27:50.006554 | 2026-02-14 00:27:50.006785 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-14 00:27:50.056149 | controller | skipping: Conditional result was False 2026-02-14 00:27:50.063735 | 2026-02-14 00:27:50.063814 | TASK [fetch-output : Set log path for single node] 2026-02-14 00:27:50.113966 | controller | ok 2026-02-14 00:27:50.123400 | 2026-02-14 00:27:50.123513 | LOOP [fetch-output : Ensure local output dirs] 2026-02-14 00:27:50.651481 | controller -> localhost | ok: "/var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/logs" 2026-02-14 00:27:50.910872 | controller -> localhost | changed: "/var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/artifacts" 2026-02-14 00:27:51.176522 | controller -> localhost | changed: "/var/lib/zuul/builds/0b9f649474324a3e8e21be865c815cdc/work/docs" 2026-02-14 00:27:51.196236 | 2026-02-14 00:27:51.196422 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-14 00:27:51.938321 | controller | changed: 2026-02-14 00:27:51.938548 | controller | .d..t...... ./ 2026-02-14 00:27:51.938576 | controller | cd+++++++++ controller/ 2026-02-14 00:27:51.938613 | controller | changed: All items complete 2026-02-14 00:27:51.938633 | 2026-02-14 00:27:52.562131 | controller | changed: .d..t...... ./ 2026-02-14 00:27:53.101440 | controller | changed: .d..t...... ./ 2026-02-14 00:27:53.122547 | 2026-02-14 00:27:53.122708 | TASK [include_role : fetch-output-openshift] 2026-02-14 00:27:53.138600 | controller | skipping: Conditional result was False 2026-02-14 00:27:53.147383 | 2026-02-14 00:27:53.147496 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-14 00:27:53.175589 | controller | skipping: Conditional result was False 2026-02-14 00:27:53.183413 | controller | skipping: Conditional result was False 2026-02-14 00:27:53.222026 | 2026-02-14 00:27:53.222149 | PLAY [localhost] 2026-02-14 00:27:53.235441 | 2026-02-14 00:27:53.235510 | TASK [Run Zuul manifest role] 2026-02-14 00:27:53.255510 | localhost | ok 2026-02-14 00:27:53.269887 | 2026-02-14 00:27:53.270011 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-14 00:27:53.704265 | localhost | changed 2026-02-14 00:27:53.717640 | 2026-02-14 00:27:53.717844 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-14 00:27:53.747743 | localhost | ok 2026-02-14 00:27:53.756331 | 2026-02-14 00:27:53.756394 | TASK [Set zuul-log-path fact] 2026-02-14 00:27:53.777723 | localhost | ok 2026-02-14 00:27:53.792198 | 2026-02-14 00:27:53.792279 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-14 00:27:53.822822 | localhost | ok 2026-02-14 00:27:53.832175 | 2026-02-14 00:27:53.832242 | LOOP [Run upload-logs-swift role] 2026-02-14 00:27:53.870621 | localhost | Output suppressed because no_log was given 2026-02-14 00:27:53.898821 | 2026-02-14 00:27:53.898938 | TASK [Set zuul-log-path fact] 2026-02-14 00:27:53.996293 | localhost | skipping: Conditional result was False 2026-02-14 00:27:54.086973 | 2026-02-14 00:27:54.087186 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-14 00:27:54.605765 | localhost -> localhost | ok: Runtime: 0:00:00.011213 2026-02-14 00:27:54.613869 | 2026-02-14 00:27:54.613972 | TASK [upload-logs-swift : Upload logs to swift]