2026-02-08 00:28:57.347213 | Job console starting... 2026-02-08 00:28:57.358703 | Updating repositories 2026-02-08 00:28:57.555336 | Preparing job workspace 2026-02-08 00:29:01.175475 | Running Ansible setup... 2026-02-08 00:29:09.365817 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-08 00:29:10.078283 | 2026-02-08 00:29:10.078443 | PLAY [localhost] 2026-02-08 00:29:10.088487 | 2026-02-08 00:29:10.088624 | TASK [Gathering Facts] 2026-02-08 00:29:11.116429 | localhost | ok 2026-02-08 00:29:11.155725 | 2026-02-08 00:29:11.155999 | TASK [Setup log path fact] 2026-02-08 00:29:11.181673 | localhost | ok 2026-02-08 00:29:11.199474 | 2026-02-08 00:29:11.199615 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-08 00:29:11.230636 | localhost | ok 2026-02-08 00:29:11.241646 | 2026-02-08 00:29:11.241766 | TASK [emit-job-header : Print job information] 2026-02-08 00:29:11.282336 | # Job Information 2026-02-08 00:29:11.282615 | Ansible Version: 2.15.12 2026-02-08 00:29:11.282654 | Job: ansible-test-sanity-docker-milestone 2026-02-08 00:29:11.282676 | Pipeline: periodic 2026-02-08 00:29:11.282695 | Executor: ze01.softwarefactory-project.io 2026-02-08 00:29:11.282712 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-08 00:29:11.282739 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/db7/ansible/db7cdaeac9414d2cbb57bd5a1698a51d/ 2026-02-08 00:29:11.282769 | Event ID: adfddf66f4044af990a67494b6debacf 2026-02-08 00:29:11.288035 | 2026-02-08 00:29:11.288116 | LOOP [emit-job-header : Print node information] 2026-02-08 00:29:11.399428 | localhost | ok: 2026-02-08 00:29:11.399674 | localhost | # Node Information 2026-02-08 00:29:11.399707 | localhost | Inventory Hostname: controller 2026-02-08 00:29:11.399729 | localhost | Hostname: np0005612585 2026-02-08 00:29:11.399754 | localhost | Username: zuul 2026-02-08 00:29:11.399780 | localhost | Distro: Fedora 37 2026-02-08 00:29:11.399805 | localhost | Provider: ansible-vexxhost-ams1 2026-02-08 00:29:11.399827 | localhost | Region: ams1 2026-02-08 00:29:11.399849 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-08 00:29:11.399872 | localhost | Product Name: OpenStack Nova 2026-02-08 00:29:11.399896 | localhost | Interface IP: 38.129.16.248 2026-02-08 00:29:11.418751 | 2026-02-08 00:29:11.418905 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-08 00:29:11.821658 | localhost -> localhost | changed 2026-02-08 00:29:11.827560 | 2026-02-08 00:29:11.827650 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-08 00:29:12.730039 | localhost -> localhost | changed 2026-02-08 00:29:12.750760 | 2026-02-08 00:29:12.750833 | PLAY [all:!appliance*] 2026-02-08 00:29:12.768464 | 2026-02-08 00:29:12.768593 | TASK [include_role : start-zuul-console] 2026-02-08 00:29:12.788676 | controller | ok 2026-02-08 00:29:12.805426 | 2026-02-08 00:29:12.805541 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-08 00:29:13.849135 | controller | ok 2026-02-08 00:29:13.868669 | 2026-02-08 00:29:13.868837 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-08 00:29:16.191700 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-08 00:29:16.198640 | 2026-02-08 00:29:16.198716 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-08 00:29:16.557817 | controller | skipping: Conditional result was False 2026-02-08 00:29:16.572655 | 2026-02-08 00:29:16.572824 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-08 00:29:16.601643 | controller | skipping: Conditional result was False 2026-02-08 00:29:16.618701 | 2026-02-08 00:29:16.618972 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-08 00:29:16.655790 | controller | skipping: Conditional result was False 2026-02-08 00:29:16.666040 | 2026-02-08 00:29:16.666199 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-08 00:29:16.681679 | controller | skipping: Conditional result was False 2026-02-08 00:29:16.691718 | 2026-02-08 00:29:16.691886 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-08 00:29:16.717271 | controller | skipping: Conditional result was False 2026-02-08 00:29:16.724767 | 2026-02-08 00:29:16.724917 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-08 00:29:16.749330 | controller | skipping: Conditional result was False 2026-02-08 00:29:16.762414 | 2026-02-08 00:29:16.762551 | TASK [Disable Fedora Modular] 2026-02-08 00:29:17.846752 | controller | changed 2026-02-08 00:29:17.855709 | 2026-02-08 00:29:17.856056 | TASK [Enable EPEL] 2026-02-08 00:29:17.871206 | controller | skipping: Conditional result was False 2026-02-08 00:29:17.879509 | 2026-02-08 00:29:17.879656 | TASK [Register the RHEL node] 2026-02-08 00:29:18.284940 | 2026-02-08 00:29:18.285192 | TASK [Show the subscription-manager status] 2026-02-08 00:29:18.662576 | controller | skipping: Conditional result was False 2026-02-08 00:29:18.671092 | 2026-02-08 00:29:18.671230 | TASK [Enable EPEL on RHEL] 2026-02-08 00:29:19.064337 | controller | skipping: Conditional result was False 2026-02-08 00:29:19.072609 | 2026-02-08 00:29:19.072711 | TASK [Install git and tox] 2026-02-08 00:31:26.578758 | controller | changed 2026-02-08 00:31:26.587517 | 2026-02-08 00:31:26.587660 | TASK [include_role : prepare-workspace] 2026-02-08 00:31:26.618046 | controller | ok 2026-02-08 00:31:26.644289 | 2026-02-08 00:31:26.644423 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-08 00:31:27.498574 | controller | ok 2026-02-08 00:31:27.509909 | 2026-02-08 00:31:27.510041 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-08 00:31:44.125734 | controller | Output suppressed because no_log was given 2026-02-08 00:31:44.136391 | 2026-02-08 00:31:44.136492 | TASK [include_role : prepare-workspace-openshift] 2026-02-08 00:31:44.160979 | controller | skipping: Conditional result was False 2026-02-08 00:31:44.186634 | 2026-02-08 00:31:44.186721 | PLAY [all:!appliance] 2026-02-08 00:31:44.204894 | 2026-02-08 00:31:44.205705 | TASK [Run add-build-sshkey role (RSA)] 2026-02-08 00:31:44.230924 | controller | ok 2026-02-08 00:31:44.248083 | 2026-02-08 00:31:44.248203 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-08 00:31:44.543783 | controller -> localhost | ok 2026-02-08 00:31:44.552611 | 2026-02-08 00:31:44.552727 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-08 00:31:44.585048 | controller | ok 2026-02-08 00:31:44.600973 | controller | included: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-08 00:31:44.607361 | 2026-02-08 00:31:44.607459 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-08 00:31:45.122490 | controller -> localhost | Generating public/private rsa key pair. 2026-02-08 00:31:45.122782 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/db7cdaeac9414d2cbb57bd5a1698a51d_id_rsa. 2026-02-08 00:31:45.122827 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/db7cdaeac9414d2cbb57bd5a1698a51d_id_rsa.pub. 2026-02-08 00:31:45.122860 | controller -> localhost | The key fingerprint is: 2026-02-08 00:31:45.122892 | controller -> localhost | SHA256:gmONpsSARfzk6lOjtFABmaJp5xAo1zkOVctN4CeVEeA zuul-build-sshkey 2026-02-08 00:31:45.122929 | controller -> localhost | The key's randomart image is: 2026-02-08 00:31:45.122960 | controller -> localhost | +---[RSA 2048]----+ 2026-02-08 00:31:45.122991 | controller -> localhost | |o*oo.o+o=+ | 2026-02-08 00:31:45.123072 | controller -> localhost | |Bo= =+ =. | 2026-02-08 00:31:45.123110 | controller -> localhost | |*o.B .E o | 2026-02-08 00:31:45.123142 | controller -> localhost | |o=..++ o | 2026-02-08 00:31:45.123171 | controller -> localhost | |..*.* o S | 2026-02-08 00:31:45.123213 | controller -> localhost | |..o=o. . | 2026-02-08 00:31:45.123254 | controller -> localhost | | +.+ . | 2026-02-08 00:31:45.123290 | controller -> localhost | | = | 2026-02-08 00:31:45.123323 | controller -> localhost | | . | 2026-02-08 00:31:45.123357 | controller -> localhost | +----[SHA256]-----+ 2026-02-08 00:31:45.123430 | controller -> localhost | ok: Runtime: 0:00:00.096248 2026-02-08 00:31:45.133853 | 2026-02-08 00:31:45.134031 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-08 00:31:45.165628 | controller | ok 2026-02-08 00:31:45.177405 | controller | included: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-08 00:31:45.189635 | 2026-02-08 00:31:45.189771 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-08 00:31:45.204968 | controller | skipping: Conditional result was False 2026-02-08 00:31:45.217151 | 2026-02-08 00:31:45.217304 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-08 00:31:46.332752 | controller | changed 2026-02-08 00:31:46.340312 | 2026-02-08 00:31:46.340398 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-08 00:31:46.973952 | controller | ok 2026-02-08 00:31:46.981035 | 2026-02-08 00:31:46.981172 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-08 00:31:49.960891 | controller | changed 2026-02-08 00:31:49.967497 | 2026-02-08 00:31:49.967595 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-08 00:31:52.914409 | controller | changed 2026-02-08 00:31:52.922590 | 2026-02-08 00:31:52.922701 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-08 00:31:52.947330 | controller | skipping: Conditional result was False 2026-02-08 00:31:52.954586 | 2026-02-08 00:31:52.954695 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-08 00:31:53.391942 | controller -> localhost | changed 2026-02-08 00:31:53.405551 | 2026-02-08 00:31:53.405710 | TASK [add-build-sshkey : Add back temp key] 2026-02-08 00:31:53.709332 | controller -> localhost | Identity added: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/db7cdaeac9414d2cbb57bd5a1698a51d_id_rsa (zuul-build-sshkey) 2026-02-08 00:31:53.709610 | controller -> localhost | ok: Runtime: 0:00:00.018030 2026-02-08 00:31:53.717126 | 2026-02-08 00:31:53.717210 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-08 00:31:54.643523 | controller | ok 2026-02-08 00:31:54.652851 | 2026-02-08 00:31:54.652968 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-08 00:31:54.703187 | controller | skipping: Conditional result was False 2026-02-08 00:31:54.729198 | 2026-02-08 00:31:54.729362 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-08 00:31:54.765719 | controller | ok 2026-02-08 00:31:54.793407 | 2026-02-08 00:31:54.793548 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-08 00:31:55.122123 | controller -> localhost | ok 2026-02-08 00:31:55.139236 | 2026-02-08 00:31:55.139400 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-08 00:31:55.173824 | controller | ok 2026-02-08 00:31:55.188172 | controller | included: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-08 00:31:55.197960 | 2026-02-08 00:31:55.198142 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-08 00:31:55.505220 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-08 00:31:55.505465 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/db7cdaeac9414d2cbb57bd5a1698a51d_id_ecdsa. 2026-02-08 00:31:55.505497 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/db7cdaeac9414d2cbb57bd5a1698a51d_id_ecdsa.pub. 2026-02-08 00:31:55.505528 | controller -> localhost | The key fingerprint is: 2026-02-08 00:31:55.505548 | controller -> localhost | SHA256:bk1gE8H/D4SE4xbPI8kaDuKPr3inleb7OiHBEEmmrt8 zuul-build-sshkey 2026-02-08 00:31:55.505566 | controller -> localhost | The key's randomart image is: 2026-02-08 00:31:55.505587 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-08 00:31:55.505614 | controller -> localhost | |o= .oo | 2026-02-08 00:31:55.505642 | controller -> localhost | |= =.. | 2026-02-08 00:31:55.505665 | controller -> localhost | |.o o+O . | 2026-02-08 00:31:55.505687 | controller -> localhost | |. + . ..*o* . | 2026-02-08 00:31:55.505712 | controller -> localhost | | o o o +S..+ | 2026-02-08 00:31:55.505739 | controller -> localhost | |. o ..o. o o | 2026-02-08 00:31:55.505767 | controller -> localhost | |. ++. o . o | 2026-02-08 00:31:55.505795 | controller -> localhost | | oo=+ . . | 2026-02-08 00:31:55.505822 | controller -> localhost | |..+=E=. | 2026-02-08 00:31:55.505850 | controller -> localhost | +----[SHA256]-----+ 2026-02-08 00:31:55.505910 | controller -> localhost | ok: Runtime: 0:00:00.025933 2026-02-08 00:31:55.519282 | 2026-02-08 00:31:55.519420 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-08 00:31:55.546844 | controller | ok 2026-02-08 00:31:55.556822 | controller | included: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-08 00:31:55.612598 | 2026-02-08 00:31:55.612799 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-08 00:31:55.639417 | controller | skipping: Conditional result was False 2026-02-08 00:31:55.647890 | 2026-02-08 00:31:55.648010 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-08 00:31:56.693851 | controller | changed 2026-02-08 00:31:56.702616 | 2026-02-08 00:31:56.702739 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-08 00:31:57.353255 | controller | ok 2026-02-08 00:31:57.360467 | 2026-02-08 00:31:57.360551 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-08 00:32:00.305103 | controller | changed 2026-02-08 00:32:00.312032 | 2026-02-08 00:32:00.312128 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-08 00:32:03.274348 | controller | changed 2026-02-08 00:32:03.283747 | 2026-02-08 00:32:03.283895 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-08 00:32:03.310513 | controller | skipping: Conditional result was False 2026-02-08 00:32:03.317959 | 2026-02-08 00:32:03.318227 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-08 00:32:03.589288 | controller -> localhost | changed 2026-02-08 00:32:03.602492 | 2026-02-08 00:32:03.602639 | TASK [add-build-sshkey : Add back temp key] 2026-02-08 00:32:03.916549 | controller -> localhost | Identity added: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/db7cdaeac9414d2cbb57bd5a1698a51d_id_ecdsa (zuul-build-sshkey) 2026-02-08 00:32:03.916813 | controller -> localhost | ok: Runtime: 0:00:00.009713 2026-02-08 00:32:03.923554 | 2026-02-08 00:32:03.923662 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-08 00:32:04.610926 | controller | ok 2026-02-08 00:32:04.618702 | 2026-02-08 00:32:04.618825 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-08 00:32:04.644851 | controller | skipping: Conditional result was False 2026-02-08 00:32:04.662372 | 2026-02-08 00:32:04.662505 | TASK [include_role : remove-zuul-sshkey] 2026-02-08 00:32:04.687757 | controller | skipping: Conditional result was False 2026-02-08 00:32:04.698210 | 2026-02-08 00:32:04.698336 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-08 00:32:05.322885 | controller | ok: "logs" 2026-02-08 00:32:05.323154 | controller | ok: All items complete 2026-02-08 00:32:05.323185 | 2026-02-08 00:32:05.998185 | controller | ok: "artifacts" 2026-02-08 00:32:06.618663 | controller | ok: "docs" 2026-02-08 00:32:06.641799 | 2026-02-08 00:32:06.641980 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-08 00:32:07.306035 | controller | changed: "logs" 2026-02-08 00:32:07.923907 | controller | changed: "artifacts" 2026-02-08 00:32:08.531196 | controller | changed: "docs" 2026-02-08 00:32:08.563239 | 2026-02-08 00:32:08.563342 | PLAY RECAP 2026-02-08 00:32:08.563388 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-08 00:32:08.563414 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-08 00:32:08.563433 | 2026-02-08 00:32:08.682234 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-08 00:32:08.684070 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-08 00:32:09.333595 | 2026-02-08 00:32:09.333739 | PLAY [all] 2026-02-08 00:32:09.358712 | 2026-02-08 00:32:09.358857 | TASK [Install binary dependencies] 2026-02-08 00:32:09.429474 | controller | ok 2026-02-08 00:32:09.449078 | 2026-02-08 00:32:09.449184 | TASK [bindep : Include find tasks] 2026-02-08 00:32:09.480548 | controller | ok 2026-02-08 00:32:09.490980 | controller | included: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-08 00:32:09.497952 | 2026-02-08 00:32:09.498260 | TASK [bindep : Look for bindep.txt] 2026-02-08 00:32:10.423789 | controller | ok 2026-02-08 00:32:10.431436 | 2026-02-08 00:32:10.431543 | TASK [bindep : Define bindep_file fact] 2026-02-08 00:32:10.458265 | controller | skipping: Conditional result was False 2026-02-08 00:32:10.466468 | 2026-02-08 00:32:10.466586 | TASK [bindep : Look for other-requirements.txt] 2026-02-08 00:32:11.090528 | controller | ok 2026-02-08 00:32:11.098826 | 2026-02-08 00:32:11.098925 | TASK [bindep : Define bindep_file fact] 2026-02-08 00:32:11.126157 | controller | skipping: Conditional result was False 2026-02-08 00:32:11.136486 | 2026-02-08 00:32:11.136582 | TASK [bindep : Look for bindep fallback file] 2026-02-08 00:32:11.163409 | controller | skipping: Conditional result was False 2026-02-08 00:32:11.172105 | 2026-02-08 00:32:11.172194 | TASK [bindep : Define bindep_file fact] 2026-02-08 00:32:11.209299 | controller | skipping: Conditional result was False 2026-02-08 00:32:11.217881 | 2026-02-08 00:32:11.217956 | TASK [bindep : Include bindep tasks] 2026-02-08 00:32:11.244044 | controller | skipping: Conditional result was False 2026-02-08 00:32:11.252329 | 2026-02-08 00:32:11.252408 | TASK [bindep : Include install tasks] 2026-02-08 00:32:11.278279 | controller | skipping: Conditional result was False 2026-02-08 00:32:11.286567 | 2026-02-08 00:32:11.286645 | LOOP [bindep : Include package tasks] 2026-02-08 00:32:11.365762 | 2026-02-08 00:32:11.366084 | TASK [Run test-setup role] 2026-02-08 00:32:11.391770 | controller | ok 2026-02-08 00:32:11.416827 | 2026-02-08 00:32:11.417044 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-08 00:32:12.110044 | controller | ok 2026-02-08 00:32:12.118375 | 2026-02-08 00:32:12.118499 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-08 00:32:12.482666 | controller | skipping: Conditional result was False 2026-02-08 00:32:12.528185 | 2026-02-08 00:32:12.528304 | PLAY RECAP 2026-02-08 00:32:12.528361 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-08 00:32:12.528390 | 2026-02-08 00:32:12.686220 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-08 00:32:12.687210 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-08 00:32:13.402332 | 2026-02-08 00:32:13.402452 | PLAY [controller] 2026-02-08 00:32:13.432666 | 2026-02-08 00:32:13.432830 | TASK [Create the /root directory] 2026-02-08 00:32:14.451660 | controller | ok 2026-02-08 00:32:14.463091 | 2026-02-08 00:32:14.463246 | TASK [Install glibc-langpack-en] 2026-02-08 00:32:22.301372 | controller | ok: Nothing to do 2026-02-08 00:32:22.307982 | 2026-02-08 00:32:22.308150 | TASK [Ensure controller directory exists] 2026-02-08 00:32:23.133785 | controller | changed 2026-02-08 00:32:23.139660 | 2026-02-08 00:32:23.139755 | TASK [Install container runtime] 2026-02-08 00:32:23.180105 | controller | ok 2026-02-08 00:32:23.219326 | 2026-02-08 00:32:23.219465 | LOOP [ensure-podman : Find distribution installation] 2026-02-08 00:32:23.243452 | controller | ok: "/var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-08 00:32:23.251306 | controller | included: /var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-08 00:32:23.258390 | 2026-02-08 00:32:23.258495 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-08 00:34:16.909923 | controller | changed 2026-02-08 00:34:16.917522 | 2026-02-08 00:34:16.917652 | TASK [ensure-podman : Fetch podman version] 2026-02-08 00:34:18.073482 | controller | Client: Podman Engine 2026-02-08 00:34:18.107278 | controller | Version: 4.6.2 2026-02-08 00:34:18.107333 | controller | API Version: 4.6.2 2026-02-08 00:34:18.107341 | controller | Go Version: go1.19.12 2026-02-08 00:34:18.107362 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-08 00:34:18.107369 | controller | OS/Arch: linux/amd64 2026-02-08 00:34:18.284107 | controller | ok: Runtime: 0:00:00.267200 2026-02-08 00:34:18.293882 | 2026-02-08 00:34:18.294306 | TASK [ensure-podman : Print podman version installed] 2026-02-08 00:34:18.330445 | Podman version: Client: Podman Engine 2026-02-08 00:34:18.330629 | Version: 4.6.2 2026-02-08 00:34:18.330834 | API Version: 4.6.2 2026-02-08 00:34:18.330881 | Go Version: go1.19.12 2026-02-08 00:34:18.330911 | Built: Mon Aug 28 19:38:31 2023 2026-02-08 00:34:18.330943 | OS/Arch: linux/amd64 2026-02-08 00:34:18.343812 | 2026-02-08 00:34:18.343942 | TASK [ensure-podman : Validate podman engine] 2026-02-08 00:34:18.712129 | controller | skipping: Conditional result was False 2026-02-08 00:34:18.719067 | 2026-02-08 00:34:18.719167 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-08 00:34:18.743921 | controller | skipping: Conditional result was False 2026-02-08 00:34:18.756776 | 2026-02-08 00:34:18.756907 | TASK [Ensure python3.8 is present] 2026-02-08 00:34:18.781755 | controller | skipping: Conditional result was False 2026-02-08 00:34:18.791595 | 2026-02-08 00:34:18.791818 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-08 00:34:18.816875 | controller | ok 2026-02-08 00:34:18.836804 | 2026-02-08 00:34:18.836922 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-08 00:34:22.139329 | controller | ok: Nothing to do 2026-02-08 00:34:22.145862 | 2026-02-08 00:34:22.145979 | TASK [our-ensure-python : Also install python3-devel] 2026-02-08 00:34:38.701903 | controller | changed 2026-02-08 00:34:38.720916 | 2026-02-08 00:34:38.721068 | TASK [Run ensure-virtualenv role] 2026-02-08 00:34:38.743994 | controller | ok 2026-02-08 00:34:38.773608 | 2026-02-08 00:34:38.773748 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-08 00:34:39.578724 | controller | /usr/bin/virtualenv 2026-02-08 00:34:40.189345 | controller | ok: Runtime: 0:00:00.004329 2026-02-08 00:34:40.205713 | 2026-02-08 00:34:40.205905 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-08 00:34:40.228312 | controller | skipping: Conditional result was False 2026-02-08 00:34:40.228564 | controller | ok: All items complete 2026-02-08 00:34:40.228591 | 2026-02-08 00:34:40.249255 | 2026-02-08 00:34:40.249407 | TASK [Find the full path of the Python interpreter] 2026-02-08 00:34:41.044789 | controller | /usr/bin/python3 2026-02-08 00:34:41.608738 | controller | ok 2026-02-08 00:34:41.618192 | 2026-02-08 00:34:41.618369 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-08 00:34:43.353211 | controller | created virtual environment CPython3.11.0.final.0-64 in 821ms 2026-02-08 00:34:43.447022 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-08 00:34:43.447733 | 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-08 00:34:43.448147 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-08 00:34:43.448397 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-08 00:34:44.002535 | controller | changed 2026-02-08 00:34:44.020071 | 2026-02-08 00:34:44.020244 | TASK [Set selinux package] 2026-02-08 00:34:44.062188 | controller | ok 2026-02-08 00:34:44.072919 | 2026-02-08 00:34:44.073090 | TASK [Set selinux package (Fedora)] 2026-02-08 00:34:44.125420 | controller | ok 2026-02-08 00:34:44.134442 | 2026-02-08 00:34:44.134598 | TASK [Install selinux into virtualenv] 2026-02-08 00:34:47.044547 | controller | Collecting selinux-please-lie-to-me 2026-02-08 00:34:47.109946 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-08 00:34:47.649315 | controller | Collecting setuptools<50.0.0 2026-02-08 00:34:47.656300 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-08 00:34:47.711463 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.0 MB/s eta 0:00:00 2026-02-08 00:34:47.854220 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-08 00:34:47.854552 | controller | Attempting uninstall: setuptools 2026-02-08 00:34:47.858585 | controller | Found existing installation: setuptools 62.6.0 2026-02-08 00:34:47.956867 | controller | Uninstalling setuptools-62.6.0: 2026-02-08 00:34:47.971401 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-08 00:34:48.694080 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-08 00:34:48.892834 | controller | 2026-02-08 00:34:49.161228 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-08 00:34:49.161281 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-08 00:34:49.527378 | controller | ok: Runtime: 0:00:04.213684 2026-02-08 00:34:49.536904 | 2026-02-08 00:34:49.537075 | TASK [Install pytest-forked into virtualenv] 2026-02-08 00:34:51.073230 | controller | Collecting pytest-forked 2026-02-08 00:34:51.141168 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-08 00:34:51.206965 | controller | Collecting py 2026-02-08 00:34:51.212074 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-08 00:34:51.248075 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.1 MB/s eta 0:00:00 2026-02-08 00:34:51.450907 | controller | Collecting pytest>=3.10 2026-02-08 00:34:51.456217 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-08 00:34:51.481526 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 17.4 MB/s eta 0:00:00 2026-02-08 00:34:51.542674 | controller | Collecting iniconfig>=1.0.1 2026-02-08 00:34:51.547969 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-08 00:34:51.634939 | controller | Collecting packaging>=22 2026-02-08 00:34:51.639682 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-08 00:34:51.650463 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 8.4 MB/s eta 0:00:00 2026-02-08 00:34:51.696709 | controller | Collecting pluggy<2,>=1.5 2026-02-08 00:34:51.704817 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-08 00:34:51.788812 | controller | Collecting pygments>=2.7.2 2026-02-08 00:34:51.794012 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-08 00:34:51.820082 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 61.1 MB/s eta 0:00:00 2026-02-08 00:34:51.943542 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-08 00:34:54.417131 | 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-08 00:34:54.431726 | controller | 2026-02-08 00:34:54.641185 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-08 00:34:54.641239 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-08 00:34:54.918650 | controller | ok: Runtime: 0:00:04.318918 2026-02-08 00:34:54.928671 | 2026-02-08 00:34:54.928812 | TASK [Update pip] 2026-02-08 00:34:56.261170 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-08 00:34:56.587576 | controller | Collecting pip 2026-02-08 00:34:56.671946 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-08 00:34:56.763859 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 21.0 MB/s eta 0:00:00 2026-02-08 00:34:56.880000 | controller | Installing collected packages: pip 2026-02-08 00:34:56.880320 | controller | Attempting uninstall: pip 2026-02-08 00:34:56.883681 | controller | Found existing installation: pip 22.2.2 2026-02-08 00:34:57.150643 | controller | Uninstalling pip-22.2.2: 2026-02-08 00:34:57.199102 | controller | Successfully uninstalled pip-22.2.2 2026-02-08 00:34:59.279035 | controller | Successfully installed pip-26.0.1 2026-02-08 00:34:59.802601 | controller | ok: Runtime: 0:00:03.798432 2026-02-08 00:34:59.813856 | 2026-02-08 00:34:59.814104 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-08 00:35:00.713200 | controller | changed 2026-02-08 00:35:00.720499 | 2026-02-08 00:35:00.720615 | TASK [Install ansible into virtualenv] 2026-02-08 00:35:02.012028 | controller | Processing ./src/github.com/ansible/ansible 2026-02-08 00:35:02.016152 | controller | Installing build dependencies: started 2026-02-08 00:35:03.843278 | controller | Installing build dependencies: finished with status 'done' 2026-02-08 00:35:03.844037 | controller | Getting requirements to build wheel: started 2026-02-08 00:35:05.353606 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-08 00:35:05.354417 | controller | Preparing metadata (pyproject.toml): started 2026-02-08 00:35:06.214314 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-08 00:35:06.216585 | 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-08 00:35:06.224140 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-08 00:35:06.597048 | controller | ERROR 2026-02-08 00:35:06.597212 | controller | { 2026-02-08 00:35:06.597243 | controller | "delta": "0:00:05.027889", 2026-02-08 00:35:06.597263 | controller | "end": "2026-02-08 00:35:06.398173", 2026-02-08 00:35:06.597281 | controller | "msg": "non-zero return code", 2026-02-08 00:35:06.597306 | controller | "rc": 1, 2026-02-08 00:35:06.597323 | controller | "start": "2026-02-08 00:35:01.370284" 2026-02-08 00:35:06.597340 | controller | } failure 2026-02-08 00:35:06.598685 | 2026-02-08 00:35:06.598739 | PLAY RECAP 2026-02-08 00:35:06.598826 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-08 00:35:06.598859 | 2026-02-08 00:35:06.728911 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-08 00:35:06.730318 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-08 00:35:07.345900 | 2026-02-08 00:35:07.346103 | PLAY [all] 2026-02-08 00:35:07.371405 | 2026-02-08 00:35:07.371565 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-08 00:35:09.182701 | controller | changed: non-zero return code 2026-02-08 00:35:09.190245 | 2026-02-08 00:35:09.190390 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-08 00:35:09.214877 | controller | skipping: Conditional result was False 2026-02-08 00:35:09.222203 | 2026-02-08 00:35:09.222332 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-08 00:35:09.246765 | 2026-02-08 00:35:09.246966 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-08 00:35:09.269220 | 2026-02-08 00:35:09.269430 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-08 00:35:09.283297 | controller | skipping: Conditional result was False 2026-02-08 00:35:09.290695 | 2026-02-08 00:35:09.290826 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-08 00:35:09.312348 | 2026-02-08 00:35:09.312565 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-08 00:35:09.327058 | controller | skipping: Conditional result was False 2026-02-08 00:35:09.333960 | 2026-02-08 00:35:09.334112 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-08 00:35:09.348435 | controller | skipping: Conditional result was False 2026-02-08 00:35:09.355811 | 2026-02-08 00:35:09.355936 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-08 00:35:09.370419 | controller | skipping: Conditional result was False 2026-02-08 00:35:09.406494 | 2026-02-08 00:35:09.406613 | PLAY RECAP 2026-02-08 00:35:09.406676 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-08 00:35:09.406712 | 2026-02-08 00:35:09.552230 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-08 00:35:09.553143 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-08 00:35:10.184967 | 2026-02-08 00:35:10.185104 | PLAY [all:!appliance*] 2026-02-08 00:35:10.208349 | 2026-02-08 00:35:10.208472 | TASK [unregister the node] 2026-02-08 00:35:10.563619 | controller | skipping: Conditional result was False 2026-02-08 00:35:10.573931 | 2026-02-08 00:35:10.574147 | TASK [include_role : fetch-output] 2026-02-08 00:35:10.608770 | controller | ok 2026-02-08 00:35:10.640849 | 2026-02-08 00:35:10.641010 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-08 00:35:10.687923 | controller | skipping: Conditional result was False 2026-02-08 00:35:10.696944 | 2026-02-08 00:35:10.697183 | TASK [fetch-output : Set log path for single node] 2026-02-08 00:35:10.740511 | controller | ok 2026-02-08 00:35:10.746633 | 2026-02-08 00:35:10.746760 | LOOP [fetch-output : Ensure local output dirs] 2026-02-08 00:35:11.166379 | controller -> localhost | ok: "/var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/logs" 2026-02-08 00:35:11.408407 | controller -> localhost | changed: "/var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/artifacts" 2026-02-08 00:35:11.646187 | controller -> localhost | changed: "/var/lib/zuul/builds/db7cdaeac9414d2cbb57bd5a1698a51d/work/docs" 2026-02-08 00:35:11.665926 | 2026-02-08 00:35:11.666122 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-08 00:35:13.880402 | controller | changed: 2026-02-08 00:35:13.880592 | controller | .d..t...... ./ 2026-02-08 00:35:13.880619 | controller | cd+++++++++ controller/ 2026-02-08 00:35:13.880651 | controller | changed: All items complete 2026-02-08 00:35:13.880670 | 2026-02-08 00:35:15.914195 | controller | changed: .d..t...... ./ 2026-02-08 00:35:18.127428 | controller | changed: .d..t...... ./ 2026-02-08 00:35:18.147298 | 2026-02-08 00:35:18.147458 | TASK [include_role : fetch-output-openshift] 2026-02-08 00:35:18.162189 | controller | skipping: Conditional result was False 2026-02-08 00:35:18.169011 | 2026-02-08 00:35:18.169121 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-08 00:35:18.195577 | controller | skipping: Conditional result was False 2026-02-08 00:35:18.203766 | controller | skipping: Conditional result was False 2026-02-08 00:35:18.242110 | 2026-02-08 00:35:18.242218 | PLAY [localhost] 2026-02-08 00:35:18.257256 | 2026-02-08 00:35:18.257381 | TASK [Run Zuul manifest role] 2026-02-08 00:35:18.278238 | localhost | ok 2026-02-08 00:35:18.295573 | 2026-02-08 00:35:18.295703 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-08 00:35:18.703043 | localhost | changed 2026-02-08 00:35:18.708287 | 2026-02-08 00:35:18.708376 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-08 00:35:18.739601 | localhost | ok 2026-02-08 00:35:18.752415 | 2026-02-08 00:35:18.752572 | TASK [Set zuul-log-path fact] 2026-02-08 00:35:18.775888 | localhost | ok 2026-02-08 00:35:18.833127 | 2026-02-08 00:35:18.833274 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-08 00:35:18.863315 | localhost | ok 2026-02-08 00:35:18.873602 | 2026-02-08 00:35:18.873722 | LOOP [Run upload-logs-swift role] 2026-02-08 00:35:18.897830 | localhost | Output suppressed because no_log was given 2026-02-08 00:35:18.933715 | 2026-02-08 00:35:18.933854 | TASK [Set zuul-log-path fact] 2026-02-08 00:35:18.957922 | localhost | skipping: Conditional result was False 2026-02-08 00:35:18.964553 | 2026-02-08 00:35:18.964677 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-08 00:35:19.367480 | localhost -> localhost | ok: Runtime: 0:00:00.007141 2026-02-08 00:35:19.373059 | 2026-02-08 00:35:19.373157 | TASK [upload-logs-swift : Upload logs to swift]