2026-03-18 00:07:15.929481 | Job console starting... 2026-03-18 00:07:15.939473 | Updating repositories 2026-03-18 00:07:16.100040 | Preparing job workspace 2026-03-18 00:07:19.897200 | Running Ansible setup... 2026-03-18 00:07:24.736158 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-18 00:07:25.396490 | 2026-03-18 00:07:25.396685 | PLAY [localhost] 2026-03-18 00:07:25.407970 | 2026-03-18 00:07:25.408255 | TASK [Gathering Facts] 2026-03-18 00:07:26.390507 | localhost | ok 2026-03-18 00:07:26.409718 | 2026-03-18 00:07:26.409849 | TASK [Setup log path fact] 2026-03-18 00:07:26.429262 | localhost | ok 2026-03-18 00:07:26.448602 | 2026-03-18 00:07:26.448788 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-18 00:07:26.478877 | localhost | ok 2026-03-18 00:07:26.490214 | 2026-03-18 00:07:26.490312 | TASK [emit-job-header : Print job information] 2026-03-18 00:07:26.522044 | # Job Information 2026-03-18 00:07:26.522273 | Ansible Version: 2.15.12 2026-03-18 00:07:26.522345 | Job: ansible-test-sanity-docker-devel 2026-03-18 00:07:26.522383 | Pipeline: periodic 2026-03-18 00:07:26.522411 | Executor: ze02.softwarefactory-project.io 2026-03-18 00:07:26.522437 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-03-18 00:07:26.522468 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/131/ansible/13144c5488534a27825436bbad884074/ 2026-03-18 00:07:26.522495 | Event ID: 22a3eae7e0c54c09bc4e332b89f2059b 2026-03-18 00:07:26.527960 | 2026-03-18 00:07:26.528055 | LOOP [emit-job-header : Print node information] 2026-03-18 00:07:26.631480 | localhost | ok: 2026-03-18 00:07:26.631799 | localhost | # Node Information 2026-03-18 00:07:26.631849 | localhost | Inventory Hostname: controller 2026-03-18 00:07:26.631882 | localhost | Hostname: np0005650280 2026-03-18 00:07:26.631914 | localhost | Username: zuul 2026-03-18 00:07:26.631946 | localhost | Distro: Fedora 37 2026-03-18 00:07:26.631971 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-03-18 00:07:26.631989 | localhost | Region: ca-ymq-1 2026-03-18 00:07:26.632011 | localhost | Label: ansible-fedora-37-1vcpu 2026-03-18 00:07:26.632036 | localhost | Product Name: OpenStack Nova 2026-03-18 00:07:26.632060 | localhost | Interface IP: 162.253.55.227 2026-03-18 00:07:26.661881 | 2026-03-18 00:07:26.662199 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-18 00:07:27.078621 | localhost -> localhost | changed 2026-03-18 00:07:27.087318 | 2026-03-18 00:07:27.087425 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-18 00:07:27.990933 | localhost -> localhost | changed 2026-03-18 00:07:28.011803 | 2026-03-18 00:07:28.011939 | PLAY [all:!appliance*] 2026-03-18 00:07:28.028641 | 2026-03-18 00:07:28.028747 | TASK [include_role : start-zuul-console] 2026-03-18 00:07:28.051746 | controller | ok 2026-03-18 00:07:28.070482 | 2026-03-18 00:07:28.070574 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-03-18 00:07:28.421025 | controller | ok 2026-03-18 00:07:28.439717 | 2026-03-18 00:07:28.439874 | TASK [use-our-mirror : Retrieve the IP address] 2026-03-18 00:07:29.281063 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-03-18 00:07:29.295477 | 2026-03-18 00:07:29.295621 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-03-18 00:07:29.841892 | controller | skipping: Conditional result was False 2026-03-18 00:07:29.856958 | 2026-03-18 00:07:29.857118 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-03-18 00:07:29.904464 | controller | skipping: Conditional result was False 2026-03-18 00:07:29.927628 | 2026-03-18 00:07:29.928838 | TASK [use-our-mirror : Create the podman configuration directory] 2026-03-18 00:07:29.966924 | controller | skipping: Conditional result was False 2026-03-18 00:07:29.983119 | 2026-03-18 00:07:29.983294 | TASK [use-our-mirror : Copy the podman configuration] 2026-03-18 00:07:30.020178 | controller | skipping: Conditional result was False 2026-03-18 00:07:30.026581 | 2026-03-18 00:07:30.026657 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-03-18 00:07:30.050924 | controller | skipping: Conditional result was False 2026-03-18 00:07:30.058090 | 2026-03-18 00:07:30.058172 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-03-18 00:07:30.082394 | controller | skipping: Conditional result was False 2026-03-18 00:07:30.094513 | 2026-03-18 00:07:30.094604 | TASK [Disable Fedora Modular] 2026-03-18 00:07:30.351474 | controller | changed 2026-03-18 00:07:30.367258 | 2026-03-18 00:07:30.367413 | TASK [Enable EPEL] 2026-03-18 00:07:30.384315 | controller | skipping: Conditional result was False 2026-03-18 00:07:30.394563 | 2026-03-18 00:07:30.394730 | TASK [Register the RHEL node] 2026-03-18 00:07:30.944031 | 2026-03-18 00:07:30.944218 | TASK [Show the subscription-manager status] 2026-03-18 00:07:31.516199 | controller | skipping: Conditional result was False 2026-03-18 00:07:31.531991 | 2026-03-18 00:07:31.532201 | TASK [Enable EPEL on RHEL] 2026-03-18 00:07:32.196434 | controller | skipping: Conditional result was False 2026-03-18 00:07:32.210178 | 2026-03-18 00:07:32.210371 | TASK [Install git and tox] 2026-03-18 00:08:55.693435 | controller | changed 2026-03-18 00:08:55.712533 | 2026-03-18 00:08:55.712698 | TASK [include_role : prepare-workspace] 2026-03-18 00:08:55.750565 | controller | ok 2026-03-18 00:08:55.779940 | 2026-03-18 00:08:55.780097 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-18 00:08:56.024020 | controller | ok 2026-03-18 00:08:56.030358 | 2026-03-18 00:08:56.030421 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-18 00:09:08.665975 | controller | Output suppressed because no_log was given 2026-03-18 00:09:08.720166 | 2026-03-18 00:09:08.720282 | TASK [include_role : prepare-workspace-openshift] 2026-03-18 00:09:08.744233 | controller | skipping: Conditional result was False 2026-03-18 00:09:08.767116 | 2026-03-18 00:09:08.767216 | PLAY [all:!appliance] 2026-03-18 00:09:08.785073 | 2026-03-18 00:09:08.785166 | TASK [Run add-build-sshkey role (RSA)] 2026-03-18 00:09:08.814707 | controller | ok 2026-03-18 00:09:08.829657 | 2026-03-18 00:09:08.829778 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-18 00:09:09.120059 | controller -> localhost | ok 2026-03-18 00:09:09.135645 | 2026-03-18 00:09:09.135822 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-18 00:09:09.159544 | controller | ok 2026-03-18 00:09:09.178914 | controller | included: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-18 00:09:09.187407 | 2026-03-18 00:09:09.187510 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-18 00:09:09.777900 | controller -> localhost | Generating public/private rsa key pair. 2026-03-18 00:09:09.778187 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/13144c5488534a27825436bbad884074_id_rsa. 2026-03-18 00:09:09.778230 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/13144c5488534a27825436bbad884074_id_rsa.pub. 2026-03-18 00:09:09.778261 | controller -> localhost | The key fingerprint is: 2026-03-18 00:09:09.778289 | controller -> localhost | SHA256:CT5uRSuZVGtIbRZoBYa7bw61oVfsl2YFSUrr78ISYIU zuul-build-sshkey 2026-03-18 00:09:09.778316 | controller -> localhost | The key's randomart image is: 2026-03-18 00:09:09.778342 | controller -> localhost | +---[RSA 2048]----+ 2026-03-18 00:09:09.778368 | controller -> localhost | | o+==.. | 2026-03-18 00:09:09.778394 | controller -> localhost | | Eo+++= . | 2026-03-18 00:09:09.778420 | controller -> localhost | | ++o* o | 2026-03-18 00:09:09.778445 | controller -> localhost | | +o O o . | 2026-03-18 00:09:09.778470 | controller -> localhost | | . oO S . | 2026-03-18 00:09:09.778507 | controller -> localhost | | .+.O . o | 2026-03-18 00:09:09.778540 | controller -> localhost | | o.=o. * | 2026-03-18 00:09:09.778567 | controller -> localhost | | ++ o= | 2026-03-18 00:09:09.778594 | controller -> localhost | | o.. .. | 2026-03-18 00:09:09.778624 | controller -> localhost | +----[SHA256]-----+ 2026-03-18 00:09:09.778718 | controller -> localhost | ok: Runtime: 0:00:00.167802 2026-03-18 00:09:09.793186 | 2026-03-18 00:09:09.793301 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-18 00:09:09.820580 | controller | ok 2026-03-18 00:09:09.834731 | controller | included: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-18 00:09:09.844543 | 2026-03-18 00:09:09.844650 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-18 00:09:09.869375 | controller | skipping: Conditional result was False 2026-03-18 00:09:09.876123 | 2026-03-18 00:09:09.876203 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-18 00:09:10.331679 | controller | changed 2026-03-18 00:09:10.339302 | 2026-03-18 00:09:10.339390 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-18 00:09:10.611160 | controller | ok 2026-03-18 00:09:10.625212 | 2026-03-18 00:09:10.625353 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-18 00:09:11.293382 | controller | changed 2026-03-18 00:09:11.308454 | 2026-03-18 00:09:11.308628 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-18 00:09:11.990373 | controller | changed 2026-03-18 00:09:12.004446 | 2026-03-18 00:09:12.004588 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-18 00:09:12.033706 | controller | skipping: Conditional result was False 2026-03-18 00:09:12.044038 | 2026-03-18 00:09:12.044142 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-18 00:09:12.537989 | controller -> localhost | changed 2026-03-18 00:09:12.558325 | 2026-03-18 00:09:12.558496 | TASK [add-build-sshkey : Add back temp key] 2026-03-18 00:09:12.852747 | controller -> localhost | Identity added: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/13144c5488534a27825436bbad884074_id_rsa (zuul-build-sshkey) 2026-03-18 00:09:12.853011 | controller -> localhost | ok: Runtime: 0:00:00.010118 2026-03-18 00:09:12.860853 | 2026-03-18 00:09:12.860929 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-18 00:09:13.227993 | controller | ok 2026-03-18 00:09:13.241978 | 2026-03-18 00:09:13.242120 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-18 00:09:13.293705 | controller | skipping: Conditional result was False 2026-03-18 00:09:13.312314 | 2026-03-18 00:09:13.312453 | TASK [Run add-build-sshkey role (ECDSA)] 2026-03-18 00:09:13.346695 | controller | ok 2026-03-18 00:09:13.363277 | 2026-03-18 00:09:13.363399 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-18 00:09:13.592945 | controller -> localhost | ok 2026-03-18 00:09:13.608200 | 2026-03-18 00:09:13.608319 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-18 00:09:13.633835 | controller | ok 2026-03-18 00:09:13.653892 | controller | included: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-18 00:09:13.663891 | 2026-03-18 00:09:13.663986 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-18 00:09:14.006573 | controller -> localhost | Generating public/private ecdsa key pair. 2026-03-18 00:09:14.006808 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/13144c5488534a27825436bbad884074_id_ecdsa. 2026-03-18 00:09:14.006837 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/13144c5488534a27825436bbad884074_id_ecdsa.pub. 2026-03-18 00:09:14.006867 | controller -> localhost | The key fingerprint is: 2026-03-18 00:09:14.006887 | controller -> localhost | SHA256:wZpUizsZcJsdyupYREGhVpmpIxuMOg/hLBSLkN4WWTE zuul-build-sshkey 2026-03-18 00:09:14.006904 | controller -> localhost | The key's randomart image is: 2026-03-18 00:09:14.006921 | controller -> localhost | +---[ECDSA 521]---+ 2026-03-18 00:09:14.006938 | controller -> localhost | | . .XEo o | 2026-03-18 00:09:14.006954 | controller -> localhost | |o. *++.O o | 2026-03-18 00:09:14.006971 | controller -> localhost | |* *.o O = | 2026-03-18 00:09:14.006987 | controller -> localhost | |**o+ o * . | 2026-03-18 00:09:14.007004 | controller -> localhost | |==..o * S | 2026-03-18 00:09:14.007019 | controller -> localhost | |*o + . | 2026-03-18 00:09:14.007035 | controller -> localhost | |.+. . | 2026-03-18 00:09:14.007051 | controller -> localhost | | . | 2026-03-18 00:09:14.007067 | controller -> localhost | | | 2026-03-18 00:09:14.007083 | controller -> localhost | +----[SHA256]-----+ 2026-03-18 00:09:14.007145 | controller -> localhost | ok: Runtime: 0:00:00.013123 2026-03-18 00:09:14.014180 | 2026-03-18 00:09:14.014246 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-18 00:09:14.050766 | controller | ok 2026-03-18 00:09:14.061517 | controller | included: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-18 00:09:14.076099 | 2026-03-18 00:09:14.076328 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-18 00:09:14.101491 | controller | skipping: Conditional result was False 2026-03-18 00:09:14.108595 | 2026-03-18 00:09:14.108689 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-18 00:09:14.382323 | controller | changed 2026-03-18 00:09:14.397513 | 2026-03-18 00:09:14.397661 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-18 00:09:14.656691 | controller | ok 2026-03-18 00:09:14.670305 | 2026-03-18 00:09:14.670449 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-18 00:09:15.336959 | controller | changed 2026-03-18 00:09:15.351891 | 2026-03-18 00:09:15.352059 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-18 00:09:15.987223 | controller | changed 2026-03-18 00:09:16.000984 | 2026-03-18 00:09:16.001138 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-18 00:09:16.029447 | controller | skipping: Conditional result was False 2026-03-18 00:09:16.086774 | 2026-03-18 00:09:16.086927 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-18 00:09:16.388176 | controller -> localhost | changed 2026-03-18 00:09:16.417568 | 2026-03-18 00:09:16.417768 | TASK [add-build-sshkey : Add back temp key] 2026-03-18 00:09:16.721618 | controller -> localhost | Identity added: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/13144c5488534a27825436bbad884074_id_ecdsa (zuul-build-sshkey) 2026-03-18 00:09:16.722066 | controller -> localhost | ok: Runtime: 0:00:00.014455 2026-03-18 00:09:16.739027 | 2026-03-18 00:09:16.739202 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-18 00:09:16.946813 | controller | ok 2026-03-18 00:09:16.954588 | 2026-03-18 00:09:16.954810 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-18 00:09:16.979439 | controller | skipping: Conditional result was False 2026-03-18 00:09:16.992329 | 2026-03-18 00:09:16.992422 | TASK [include_role : remove-zuul-sshkey] 2026-03-18 00:09:17.017972 | controller | skipping: Conditional result was False 2026-03-18 00:09:17.024887 | 2026-03-18 00:09:17.024962 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-18 00:09:17.262121 | controller | ok: "logs" 2026-03-18 00:09:17.262591 | controller | ok: All items complete 2026-03-18 00:09:17.262658 | 2026-03-18 00:09:17.456991 | controller | ok: "artifacts" 2026-03-18 00:09:17.653417 | controller | ok: "docs" 2026-03-18 00:09:17.664600 | 2026-03-18 00:09:17.664765 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-18 00:09:17.917318 | controller | changed: "logs" 2026-03-18 00:09:18.111825 | controller | changed: "artifacts" 2026-03-18 00:09:18.317546 | controller | changed: "docs" 2026-03-18 00:09:18.389804 | 2026-03-18 00:09:18.389926 | PLAY RECAP 2026-03-18 00:09:18.389983 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-03-18 00:09:18.390017 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-18 00:09:18.390041 | 2026-03-18 00:09:18.517869 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-18 00:09:18.519910 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-18 00:09:19.139807 | 2026-03-18 00:09:19.139936 | PLAY [all] 2026-03-18 00:09:19.164314 | 2026-03-18 00:09:19.164442 | TASK [Install binary dependencies] 2026-03-18 00:09:19.214808 | controller | ok 2026-03-18 00:09:19.235499 | 2026-03-18 00:09:19.235633 | TASK [bindep : Include find tasks] 2026-03-18 00:09:19.265402 | controller | ok 2026-03-18 00:09:19.275595 | controller | included: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-03-18 00:09:19.283902 | 2026-03-18 00:09:19.284034 | TASK [bindep : Look for bindep.txt] 2026-03-18 00:09:19.643896 | controller | ok 2026-03-18 00:09:19.653388 | 2026-03-18 00:09:19.653527 | TASK [bindep : Define bindep_file fact] 2026-03-18 00:09:19.670310 | controller | skipping: Conditional result was False 2026-03-18 00:09:19.679600 | 2026-03-18 00:09:19.679730 | TASK [bindep : Look for other-requirements.txt] 2026-03-18 00:09:19.891394 | controller | ok 2026-03-18 00:09:19.904985 | 2026-03-18 00:09:19.905170 | TASK [bindep : Define bindep_file fact] 2026-03-18 00:09:19.933373 | controller | skipping: Conditional result was False 2026-03-18 00:09:19.949567 | 2026-03-18 00:09:19.949785 | TASK [bindep : Look for bindep fallback file] 2026-03-18 00:09:19.979414 | controller | skipping: Conditional result was False 2026-03-18 00:09:19.995357 | 2026-03-18 00:09:19.995506 | TASK [bindep : Define bindep_file fact] 2026-03-18 00:09:20.023489 | controller | skipping: Conditional result was False 2026-03-18 00:09:20.032984 | 2026-03-18 00:09:20.033076 | TASK [bindep : Include bindep tasks] 2026-03-18 00:09:20.058195 | controller | skipping: Conditional result was False 2026-03-18 00:09:20.067090 | 2026-03-18 00:09:20.067176 | TASK [bindep : Include install tasks] 2026-03-18 00:09:20.091971 | controller | skipping: Conditional result was False 2026-03-18 00:09:20.100483 | 2026-03-18 00:09:20.100567 | LOOP [bindep : Include package tasks] 2026-03-18 00:09:20.161773 | 2026-03-18 00:09:20.161928 | TASK [Run test-setup role] 2026-03-18 00:09:20.186283 | controller | ok 2026-03-18 00:09:20.211477 | 2026-03-18 00:09:20.211610 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-03-18 00:09:20.416818 | controller | ok 2026-03-18 00:09:20.425457 | 2026-03-18 00:09:20.425542 | TASK [test-setup : Run tools/test-setup.sh] 2026-03-18 00:09:20.967560 | controller | skipping: Conditional result was False 2026-03-18 00:09:21.012787 | 2026-03-18 00:09:21.012918 | PLAY RECAP 2026-03-18 00:09:21.012980 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-18 00:09:21.013014 | 2026-03-18 00:09:21.131022 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-18 00:09:21.131876 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-18 00:09:21.752182 | 2026-03-18 00:09:21.752385 | PLAY [controller] 2026-03-18 00:09:21.774207 | 2026-03-18 00:09:21.774311 | TASK [Create the /root directory] 2026-03-18 00:09:22.185257 | controller | ok 2026-03-18 00:09:22.202562 | 2026-03-18 00:09:22.202896 | TASK [Install glibc-langpack-en] 2026-03-18 00:09:26.128553 | controller | ok: Nothing to do 2026-03-18 00:09:26.141159 | 2026-03-18 00:09:26.141321 | TASK [Ensure controller directory exists] 2026-03-18 00:09:26.379021 | controller | changed 2026-03-18 00:09:26.395952 | 2026-03-18 00:09:26.396189 | TASK [Install container runtime] 2026-03-18 00:09:26.471905 | controller | ok 2026-03-18 00:09:26.522281 | 2026-03-18 00:09:26.522566 | LOOP [ensure-podman : Find distribution installation] 2026-03-18 00:09:26.561550 | controller | ok: "/var/lib/zuul/builds/13144c5488534a27825436bbad884074/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-03-18 00:09:26.584817 | controller | included: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-03-18 00:09:26.600626 | 2026-03-18 00:09:26.600827 | TASK [ensure-podman : Install podman (RedHat)] 2026-03-18 00:10:31.375264 | controller | changed 2026-03-18 00:10:31.390209 | 2026-03-18 00:10:31.390348 | TASK [ensure-podman : Fetch podman version] 2026-03-18 00:10:31.966673 | controller | Client: Podman Engine 2026-03-18 00:10:31.966743 | controller | Version: 4.6.2 2026-03-18 00:10:31.966776 | controller | API Version: 4.6.2 2026-03-18 00:10:31.966810 | controller | Go Version: go1.19.12 2026-03-18 00:10:31.966860 | controller | Built: Mon Aug 28 19:38:31 2023 2026-03-18 00:10:31.966892 | controller | OS/Arch: linux/amd64 2026-03-18 00:10:32.437546 | controller | ok: Runtime: 0:00:00.186421 2026-03-18 00:10:32.453585 | 2026-03-18 00:10:32.453810 | TASK [ensure-podman : Print podman version installed] 2026-03-18 00:10:32.499392 | Podman version: Client: Podman Engine 2026-03-18 00:10:32.499661 | Version: 4.6.2 2026-03-18 00:10:32.499860 | API Version: 4.6.2 2026-03-18 00:10:32.499912 | Go Version: go1.19.12 2026-03-18 00:10:32.499953 | Built: Mon Aug 28 19:38:31 2023 2026-03-18 00:10:32.499993 | OS/Arch: linux/amd64 2026-03-18 00:10:32.513755 | 2026-03-18 00:10:32.513918 | TASK [ensure-podman : Validate podman engine] 2026-03-18 00:10:33.057458 | controller | skipping: Conditional result was False 2026-03-18 00:10:33.072949 | 2026-03-18 00:10:33.073125 | TASK [ensure-podman : Set up docker compatability socket] 2026-03-18 00:10:33.100509 | controller | skipping: Conditional result was False 2026-03-18 00:10:33.128425 | 2026-03-18 00:10:33.128642 | TASK [Ensure python3.8 is present] 2026-03-18 00:10:33.155424 | controller | skipping: Conditional result was False 2026-03-18 00:10:33.167315 | 2026-03-18 00:10:33.167483 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-03-18 00:10:33.192575 | controller | ok 2026-03-18 00:10:33.223313 | 2026-03-18 00:10:33.223456 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-03-18 00:10:34.570576 | controller | ok: Nothing to do 2026-03-18 00:10:34.584173 | 2026-03-18 00:10:34.584331 | TASK [our-ensure-python : Also install python3-devel] 2026-03-18 00:10:44.731091 | controller | changed 2026-03-18 00:10:44.759950 | 2026-03-18 00:10:44.760097 | TASK [Run ensure-virtualenv role] 2026-03-18 00:10:44.785042 | controller | ok 2026-03-18 00:10:44.819830 | 2026-03-18 00:10:44.819980 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-03-18 00:10:45.083482 | controller | /usr/bin/virtualenv 2026-03-18 00:10:45.384996 | controller | ok: Runtime: 0:00:00.004354 2026-03-18 00:10:45.399360 | 2026-03-18 00:10:45.399533 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-03-18 00:10:45.437319 | controller | skipping: Conditional result was False 2026-03-18 00:10:45.437946 | controller | ok: All items complete 2026-03-18 00:10:45.438220 | 2026-03-18 00:10:45.473717 | 2026-03-18 00:10:45.473916 | TASK [Find the full path of the Python interpreter] 2026-03-18 00:10:45.728337 | controller | /usr/bin/python3 2026-03-18 00:10:46.024365 | controller | ok 2026-03-18 00:10:46.038527 | 2026-03-18 00:10:46.038705 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-03-18 00:10:47.013139 | controller | created virtual environment CPython3.11.0.final.0-64 in 508ms 2026-03-18 00:10:47.030875 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-03-18 00:10:47.030915 | 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-03-18 00:10:47.030923 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-03-18 00:10:47.030938 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-03-18 00:10:47.098255 | controller | changed 2026-03-18 00:10:47.107791 | 2026-03-18 00:10:47.107948 | TASK [Set selinux package] 2026-03-18 00:10:47.140102 | controller | ok 2026-03-18 00:10:47.147050 | 2026-03-18 00:10:47.147518 | TASK [Set selinux package (Fedora)] 2026-03-18 00:10:47.200515 | controller | ok 2026-03-18 00:10:47.207615 | 2026-03-18 00:10:47.207722 | TASK [Install selinux into virtualenv] 2026-03-18 00:11:36.581325 | controller | Collecting selinux-please-lie-to-me 2026-03-18 00:11:39.681003 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-03-18 00:11:39.983685 | controller | Collecting setuptools<50.0.0 2026-03-18 00:11:40.009427 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-03-18 00:11:40.108318 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 8.8 MB/s eta 0:00:00 2026-03-18 00:11:40.189915 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-03-18 00:11:40.190130 | controller | Attempting uninstall: setuptools 2026-03-18 00:11:40.192629 | controller | Found existing installation: setuptools 62.6.0 2026-03-18 00:11:40.251428 | controller | Uninstalling setuptools-62.6.0: 2026-03-18 00:11:40.259378 | controller | Successfully uninstalled setuptools-62.6.0 2026-03-18 00:11:40.607916 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-03-18 00:11:56.882256 | controller | 2026-03-18 00:11:56.970687 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-18 00:11:56.970731 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-03-18 00:11:57.286357 | controller | ok: Runtime: 0:01:09.538044 2026-03-18 00:11:57.297508 | 2026-03-18 00:11:57.297622 | TASK [Install pytest-forked into virtualenv] 2026-03-18 00:12:12.247691 | controller | Collecting pytest-forked 2026-03-18 00:12:14.340320 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-03-18 00:12:14.383613 | controller | Collecting py 2026-03-18 00:12:14.409195 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-03-18 00:12:14.452829 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.3 MB/s eta 0:00:00 2026-03-18 00:12:14.560541 | controller | Collecting pytest>=3.10 2026-03-18 00:12:14.585533 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-03-18 00:12:14.631061 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 9.0 MB/s eta 0:00:00 2026-03-18 00:12:14.671247 | controller | Collecting iniconfig>=1.0.1 2026-03-18 00:12:14.697285 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-03-18 00:12:14.741889 | controller | Collecting packaging>=22 2026-03-18 00:12:14.766851 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-03-18 00:12:14.773860 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 17.2 MB/s eta 0:00:00 2026-03-18 00:12:14.810157 | controller | Collecting pluggy<2,>=1.5 2026-03-18 00:12:14.834821 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-03-18 00:12:14.883087 | controller | Collecting pygments>=2.7.2 2026-03-18 00:12:14.908261 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-03-18 00:12:14.950329 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 31.5 MB/s eta 0:00:00 2026-03-18 00:12:15.021724 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-03-18 00:12:16.045395 | 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-03-18 00:12:16.053753 | controller | 2026-03-18 00:12:16.120622 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-18 00:12:16.120683 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-03-18 00:12:16.351855 | controller | ok: Runtime: 0:00:18.596215 2026-03-18 00:12:16.364952 | 2026-03-18 00:12:16.365093 | TASK [Update pip] 2026-03-18 00:12:16.921019 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-03-18 00:12:29.383542 | controller | Collecting pip 2026-03-18 00:12:32.545049 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-03-18 00:12:32.671069 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 14.7 MB/s eta 0:00:00 2026-03-18 00:12:32.740056 | controller | Installing collected packages: pip 2026-03-18 00:12:32.740182 | controller | Attempting uninstall: pip 2026-03-18 00:12:32.742438 | controller | Found existing installation: pip 22.2.2 2026-03-18 00:12:32.880242 | controller | Uninstalling pip-22.2.2: 2026-03-18 00:12:32.897846 | controller | Successfully uninstalled pip-22.2.2 2026-03-18 00:12:33.719571 | controller | Successfully installed pip-26.0.1 2026-03-18 00:12:33.941504 | controller | ok: Runtime: 0:00:17.175001 2026-03-18 00:12:33.955989 | 2026-03-18 00:12:33.956159 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-03-18 00:12:34.181504 | controller | changed 2026-03-18 00:12:34.237205 | 2026-03-18 00:12:34.237366 | TASK [Install ansible into virtualenv] 2026-03-18 00:12:34.731722 | controller | Processing ./src/github.com/ansible/ansible 2026-03-18 00:12:34.734550 | controller | Installing build dependencies: started 2026-03-18 00:12:48.295627 | controller | Installing build dependencies: finished with status 'done' 2026-03-18 00:12:48.296247 | controller | Getting requirements to build wheel: started 2026-03-18 00:12:49.041153 | controller | Getting requirements to build wheel: finished with status 'done' 2026-03-18 00:12:49.042047 | controller | Preparing metadata (pyproject.toml): started 2026-03-18 00:12:49.507737 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-03-18 00:12:49.511541 | 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-03-18 00:12:49.515163 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-03-18 00:12:49.785902 | controller | ERROR 2026-03-18 00:12:49.786073 | controller | { 2026-03-18 00:12:49.786112 | controller | "delta": "0:00:15.125693", 2026-03-18 00:12:49.786139 | controller | "end": "2026-03-18 00:12:49.575088", 2026-03-18 00:12:49.786163 | controller | "msg": "non-zero return code", 2026-03-18 00:12:49.786202 | controller | "rc": 1, 2026-03-18 00:12:49.786225 | controller | "start": "2026-03-18 00:12:34.449395" 2026-03-18 00:12:49.786248 | controller | } failure 2026-03-18 00:12:49.788543 | 2026-03-18 00:12:49.788627 | PLAY RECAP 2026-03-18 00:12:49.788724 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-03-18 00:12:49.788764 | 2026-03-18 00:12:49.918770 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-18 00:12:49.921069 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-18 00:12:50.552187 | 2026-03-18 00:12:50.552319 | PLAY [all] 2026-03-18 00:12:50.576412 | 2026-03-18 00:12:50.576550 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-03-18 00:12:50.836703 | controller | changed: non-zero return code 2026-03-18 00:12:50.844753 | 2026-03-18 00:12:50.844874 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-03-18 00:12:50.861801 | controller | skipping: Conditional result was False 2026-03-18 00:12:50.877627 | 2026-03-18 00:12:50.877849 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-03-18 00:12:50.922516 | 2026-03-18 00:12:50.922835 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-03-18 00:12:50.965164 | 2026-03-18 00:12:50.965439 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-03-18 00:12:50.990771 | controller | skipping: Conditional result was False 2026-03-18 00:12:51.001717 | 2026-03-18 00:12:51.001841 | LOOP [fetch-subunit-output : Generate subunit file] 2026-03-18 00:12:51.026486 | 2026-03-18 00:12:51.026720 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-03-18 00:12:51.041470 | controller | skipping: Conditional result was False 2026-03-18 00:12:51.050354 | 2026-03-18 00:12:51.050448 | TASK [fetch-subunit-output : Remove the temporary file] 2026-03-18 00:12:51.075317 | controller | skipping: Conditional result was False 2026-03-18 00:12:51.084371 | 2026-03-18 00:12:51.084471 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-03-18 00:12:51.109421 | controller | skipping: Conditional result was False 2026-03-18 00:12:51.148093 | 2026-03-18 00:12:51.148262 | PLAY RECAP 2026-03-18 00:12:51.148339 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-18 00:12:51.148370 | 2026-03-18 00:12:51.242167 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-18 00:12:51.243058 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-03-18 00:12:51.871462 | 2026-03-18 00:12:51.871572 | PLAY [all:!appliance*] 2026-03-18 00:12:51.892958 | 2026-03-18 00:12:51.893046 | TASK [unregister the node] 2026-03-18 00:12:52.424015 | controller | skipping: Conditional result was False 2026-03-18 00:12:52.432722 | 2026-03-18 00:12:52.432862 | TASK [include_role : fetch-output] 2026-03-18 00:12:52.481983 | controller | ok 2026-03-18 00:12:52.522351 | 2026-03-18 00:12:52.522509 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-18 00:12:52.600149 | controller | skipping: Conditional result was False 2026-03-18 00:12:52.608688 | 2026-03-18 00:12:52.608803 | TASK [fetch-output : Set log path for single node] 2026-03-18 00:12:52.652062 | controller | ok 2026-03-18 00:12:52.658859 | 2026-03-18 00:12:52.659007 | LOOP [fetch-output : Ensure local output dirs] 2026-03-18 00:12:53.072709 | controller -> localhost | ok: "/var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/logs" 2026-03-18 00:12:53.339441 | controller -> localhost | changed: "/var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/artifacts" 2026-03-18 00:12:53.595151 | controller -> localhost | changed: "/var/lib/zuul/builds/13144c5488534a27825436bbad884074/work/docs" 2026-03-18 00:12:53.614676 | 2026-03-18 00:12:53.614799 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-18 00:12:54.278267 | controller | changed: 2026-03-18 00:12:54.278621 | controller | .d..t...... ./ 2026-03-18 00:12:54.278736 | controller | cd+++++++++ controller/ 2026-03-18 00:12:54.278809 | controller | changed: All items complete 2026-03-18 00:12:54.278851 | 2026-03-18 00:12:54.834876 | controller | changed: .d..t...... ./ 2026-03-18 00:12:55.366274 | controller | changed: .d..t...... ./ 2026-03-18 00:12:55.392233 | 2026-03-18 00:12:55.392367 | TASK [include_role : fetch-output-openshift] 2026-03-18 00:12:55.407400 | controller | skipping: Conditional result was False 2026-03-18 00:12:55.415698 | 2026-03-18 00:12:55.415793 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-18 00:12:55.439923 | controller | skipping: Conditional result was False 2026-03-18 00:12:55.448966 | controller | skipping: Conditional result was False 2026-03-18 00:12:55.485326 | 2026-03-18 00:12:55.485434 | PLAY [localhost] 2026-03-18 00:12:55.498148 | 2026-03-18 00:12:55.498233 | TASK [Run Zuul manifest role] 2026-03-18 00:12:55.517383 | localhost | ok 2026-03-18 00:12:55.530729 | 2026-03-18 00:12:55.530810 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-18 00:12:55.969222 | localhost | changed 2026-03-18 00:12:55.976471 | 2026-03-18 00:12:55.976576 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-18 00:12:56.007104 | localhost | ok 2026-03-18 00:12:56.017584 | 2026-03-18 00:12:56.017699 | TASK [Set zuul-log-path fact] 2026-03-18 00:12:56.037463 | localhost | ok 2026-03-18 00:12:56.055492 | 2026-03-18 00:12:56.055600 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-18 00:12:56.096427 | localhost | ok 2026-03-18 00:12:56.105587 | 2026-03-18 00:12:56.105706 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-03-18 00:12:56.135722 | localhost | ok: 2026-03-18 00:12:56.135863 | localhost | { 2026-03-18 00:12:56.135887 | localhost | "auth": { 2026-03-18 00:12:56.135907 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-03-18 00:12:56.135925 | localhost | "username": "9LF91O0RK7JU" 2026-03-18 00:12:56.135941 | localhost | }, 2026-03-18 00:12:56.135957 | localhost | "profile": "rackspace", 2026-03-18 00:12:56.135972 | localhost | "region_name": "IAD" 2026-03-18 00:12:56.135987 | localhost | } 2026-03-18 00:12:56.136008 | 2026-03-18 00:12:56.145002 | 2026-03-18 00:12:56.145081 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-03-18 00:12:56.162647 | localhost | Output suppressed because no_log was given 2026-03-18 00:12:56.175730 | 2026-03-18 00:12:56.175844 | TASK [upload-logs-failover : Initialize control vars] 2026-03-18 00:12:56.194832 | localhost | ok 2026-03-18 00:12:56.199573 | 2026-03-18 00:12:56.199643 | LOOP [upload-logs-failover : Perform log upload] 2026-03-18 00:12:56.265412 | localhost | Output suppressed because no_log was given 2026-03-18 00:12:56.274517 | localhost | included: /var/lib/zuul/builds/13144c5488534a27825436bbad884074/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-03-18 00:12:56.283421 | 2026-03-18 00:12:56.283526 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-03-18 00:12:56.371199 | localhost | Output suppressed because no_log was given 2026-03-18 00:12:56.383159 | 2026-03-18 00:12:56.383344 | TASK [Upload logs to swift] 2026-03-18 00:12:56.410905 | localhost | ok 2026-03-18 00:12:56.456089 | 2026-03-18 00:12:56.456208 | TASK [Set zuul-log-path fact] 2026-03-18 00:12:56.481175 | localhost | skipping: Conditional result was False 2026-03-18 00:12:56.488379 | 2026-03-18 00:12:56.488489 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-03-18 00:12:56.911798 | localhost -> localhost | ok: Runtime: 0:00:00.004987 2026-03-18 00:12:56.921025 | 2026-03-18 00:12:56.921147 | TASK [upload-logs-swift : Upload logs to swift]