2026-02-24 00:06:47.189813 | Job console starting... 2026-02-24 00:06:47.202987 | Updating repositories 2026-02-24 00:06:50.534758 | Preparing job workspace 2026-02-24 00:06:54.937314 | Running Ansible setup... 2026-02-24 00:06:59.450840 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-24 00:07:00.107785 | 2026-02-24 00:07:00.107948 | PLAY [localhost] 2026-02-24 00:07:00.117402 | 2026-02-24 00:07:00.117524 | TASK [Gathering Facts] 2026-02-24 00:07:01.419650 | localhost | ok 2026-02-24 00:07:01.443389 | 2026-02-24 00:07:01.443492 | TASK [Setup log path fact] 2026-02-24 00:07:01.481537 | localhost | ok 2026-02-24 00:07:01.495774 | 2026-02-24 00:07:01.495854 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-24 00:07:01.555928 | localhost | ok 2026-02-24 00:07:01.573654 | 2026-02-24 00:07:01.573810 | TASK [emit-job-header : Print job information] 2026-02-24 00:07:01.622305 | # Job Information 2026-02-24 00:07:01.622461 | Ansible Version: 2.15.12 2026-02-24 00:07:01.622492 | Job: ansible-test-sanity-docker-milestone 2026-02-24 00:07:01.622513 | Pipeline: periodic 2026-02-24 00:07:01.622532 | Executor: ze04.softwarefactory-project.io 2026-02-24 00:07:01.622549 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-24 00:07:01.622569 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/3f0/ansible/3f004160a99545c086b11556934982a2/ 2026-02-24 00:07:01.622588 | Event ID: 023de3d20dba42aeae84d5f5ac7fcc8d 2026-02-24 00:07:01.628109 | 2026-02-24 00:07:01.628186 | LOOP [emit-job-header : Print node information] 2026-02-24 00:07:01.753371 | localhost | ok: 2026-02-24 00:07:01.753575 | localhost | # Node Information 2026-02-24 00:07:01.753603 | localhost | Inventory Hostname: controller 2026-02-24 00:07:01.753622 | localhost | Hostname: np0005627463 2026-02-24 00:07:01.753641 | localhost | Username: zuul 2026-02-24 00:07:01.753661 | localhost | Distro: Fedora 37 2026-02-24 00:07:01.753683 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-24 00:07:01.753722 | localhost | Region: ca-ymq-1 2026-02-24 00:07:01.753739 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-24 00:07:01.753755 | localhost | Product Name: OpenStack Nova 2026-02-24 00:07:01.753772 | localhost | Interface IP: 162.253.55.70 2026-02-24 00:07:01.767397 | 2026-02-24 00:07:01.767491 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-24 00:07:02.200387 | localhost -> localhost | changed 2026-02-24 00:07:02.206228 | 2026-02-24 00:07:02.206299 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-24 00:07:03.088215 | localhost -> localhost | changed 2026-02-24 00:07:03.118928 | 2026-02-24 00:07:03.119019 | PLAY [all:!appliance*] 2026-02-24 00:07:03.137931 | 2026-02-24 00:07:03.138038 | TASK [include_role : start-zuul-console] 2026-02-24 00:07:03.159612 | controller | ok 2026-02-24 00:07:03.176350 | 2026-02-24 00:07:03.176458 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-24 00:07:03.535108 | controller | ok 2026-02-24 00:07:03.548929 | 2026-02-24 00:07:03.549036 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-24 00:07:05.766827 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-24 00:07:05.780998 | 2026-02-24 00:07:05.781148 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-24 00:07:06.334157 | controller | skipping: Conditional result was False 2026-02-24 00:07:06.341053 | 2026-02-24 00:07:06.341129 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-24 00:07:06.365934 | controller | skipping: Conditional result was False 2026-02-24 00:07:06.375086 | 2026-02-24 00:07:06.375205 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-24 00:07:06.402023 | controller | skipping: Conditional result was False 2026-02-24 00:07:06.414410 | 2026-02-24 00:07:06.414540 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-24 00:07:06.440666 | controller | skipping: Conditional result was False 2026-02-24 00:07:06.450064 | 2026-02-24 00:07:06.450154 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-24 00:07:06.476621 | controller | skipping: Conditional result was False 2026-02-24 00:07:06.484957 | 2026-02-24 00:07:06.485134 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-24 00:07:06.511299 | controller | skipping: Conditional result was False 2026-02-24 00:07:06.525603 | 2026-02-24 00:07:06.525710 | TASK [Disable Fedora Modular] 2026-02-24 00:07:07.712338 | controller | changed 2026-02-24 00:07:07.727207 | 2026-02-24 00:07:07.727369 | TASK [Enable EPEL] 2026-02-24 00:07:07.754717 | controller | skipping: Conditional result was False 2026-02-24 00:07:07.765391 | 2026-02-24 00:07:07.765524 | TASK [Register the RHEL node] 2026-02-24 00:07:08.684516 | 2026-02-24 00:07:08.684790 | TASK [Show the subscription-manager status] 2026-02-24 00:07:09.227571 | controller | skipping: Conditional result was False 2026-02-24 00:07:09.235931 | 2026-02-24 00:07:09.236019 | TASK [Enable EPEL on RHEL] 2026-02-24 00:07:09.771234 | controller | skipping: Conditional result was False 2026-02-24 00:07:09.781172 | 2026-02-24 00:07:09.781271 | TASK [Install git and tox] 2026-02-24 00:08:33.971088 | controller | changed 2026-02-24 00:08:33.986785 | 2026-02-24 00:08:33.986941 | TASK [include_role : prepare-workspace] 2026-02-24 00:08:34.022890 | controller | ok 2026-02-24 00:08:34.056481 | 2026-02-24 00:08:34.056649 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-24 00:08:34.277828 | controller | ok 2026-02-24 00:08:34.285096 | 2026-02-24 00:08:34.285191 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-24 00:14:10.823466 | controller | Output suppressed because no_log was given 2026-02-24 00:14:10.833505 | 2026-02-24 00:14:10.833574 | TASK [include_role : prepare-workspace-openshift] 2026-02-24 00:14:10.849443 | controller | skipping: Conditional result was False 2026-02-24 00:14:10.872986 | 2026-02-24 00:14:10.873089 | PLAY [all:!appliance] 2026-02-24 00:14:10.890219 | 2026-02-24 00:14:10.890290 | TASK [Run add-build-sshkey role (RSA)] 2026-02-24 00:14:10.919653 | controller | ok 2026-02-24 00:14:10.937694 | 2026-02-24 00:14:10.937783 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-24 00:14:11.167062 | controller -> localhost | ok 2026-02-24 00:14:11.181537 | 2026-02-24 00:14:11.181674 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-24 00:14:11.205567 | controller | ok 2026-02-24 00:14:11.219945 | controller | included: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-24 00:14:11.225842 | 2026-02-24 00:14:11.225906 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-24 00:14:11.709526 | controller -> localhost | Generating public/private rsa key pair. 2026-02-24 00:14:11.709829 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/3f004160a99545c086b11556934982a2_id_rsa. 2026-02-24 00:14:11.709873 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/3f004160a99545c086b11556934982a2_id_rsa.pub. 2026-02-24 00:14:11.709901 | controller -> localhost | The key fingerprint is: 2026-02-24 00:14:11.709927 | controller -> localhost | SHA256:JTzj3c6XMwqFvRucvdAzDtOjTm81TIO0zKgBSVoQvc0 zuul-build-sshkey 2026-02-24 00:14:11.709953 | controller -> localhost | The key's randomart image is: 2026-02-24 00:14:11.709977 | controller -> localhost | +---[RSA 2048]----+ 2026-02-24 00:14:11.710001 | controller -> localhost | | o=o. | 2026-02-24 00:14:11.710026 | controller -> localhost | | o= . | 2026-02-24 00:14:11.710050 | controller -> localhost | | . X . = o | 2026-02-24 00:14:11.710074 | controller -> localhost | | o E = = o | 2026-02-24 00:14:11.710097 | controller -> localhost | | S = + o .| 2026-02-24 00:14:11.710129 | controller -> localhost | | . = * +.| 2026-02-24 00:14:11.710163 | controller -> localhost | | . % %..| 2026-02-24 00:14:11.710228 | controller -> localhost | | o %.B | 2026-02-24 00:14:11.710263 | controller -> localhost | | .=.+ | 2026-02-24 00:14:11.710293 | controller -> localhost | +----[SHA256]-----+ 2026-02-24 00:14:11.710359 | controller -> localhost | ok: Runtime: 0:00:00.063537 2026-02-24 00:14:11.722395 | 2026-02-24 00:14:11.722539 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-24 00:14:11.756611 | controller | ok 2026-02-24 00:14:11.772910 | controller | included: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-24 00:14:11.786890 | 2026-02-24 00:14:11.786999 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-24 00:14:11.813035 | controller | skipping: Conditional result was False 2026-02-24 00:14:11.819711 | 2026-02-24 00:14:11.819779 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-24 00:14:12.495315 | controller | changed 2026-02-24 00:14:12.502287 | 2026-02-24 00:14:12.502397 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-24 00:14:12.742287 | controller | ok 2026-02-24 00:14:12.753139 | 2026-02-24 00:14:12.753289 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-24 00:14:13.409136 | controller | changed 2026-02-24 00:14:13.416856 | 2026-02-24 00:14:13.416965 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-24 00:14:14.043860 | controller | changed 2026-02-24 00:14:14.063205 | 2026-02-24 00:14:14.063353 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-24 00:14:14.107060 | controller | skipping: Conditional result was False 2026-02-24 00:14:14.118108 | 2026-02-24 00:14:14.118244 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-24 00:14:14.525654 | controller -> localhost | changed 2026-02-24 00:14:14.555598 | 2026-02-24 00:14:14.555810 | TASK [add-build-sshkey : Add back temp key] 2026-02-24 00:14:14.929458 | controller -> localhost | Identity added: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/3f004160a99545c086b11556934982a2_id_rsa (zuul-build-sshkey) 2026-02-24 00:14:14.929833 | controller -> localhost | ok: Runtime: 0:00:00.010102 2026-02-24 00:14:14.937865 | 2026-02-24 00:14:14.937954 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-24 00:14:15.368596 | controller | ok 2026-02-24 00:14:15.380403 | 2026-02-24 00:14:15.380571 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-24 00:14:15.409873 | controller | skipping: Conditional result was False 2026-02-24 00:14:15.424495 | 2026-02-24 00:14:15.424637 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-24 00:14:15.446609 | controller | ok 2026-02-24 00:14:15.466005 | 2026-02-24 00:14:15.466118 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-24 00:14:15.717993 | controller -> localhost | ok 2026-02-24 00:14:15.727959 | 2026-02-24 00:14:15.728060 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-24 00:14:15.754361 | controller | ok 2026-02-24 00:14:15.767496 | controller | included: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-24 00:14:15.774636 | 2026-02-24 00:14:15.774734 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-24 00:14:16.066138 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-24 00:14:16.066333 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/3f004160a99545c086b11556934982a2_id_ecdsa. 2026-02-24 00:14:16.066362 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/3f004160a99545c086b11556934982a2_id_ecdsa.pub. 2026-02-24 00:14:16.066402 | controller -> localhost | The key fingerprint is: 2026-02-24 00:14:16.066425 | controller -> localhost | SHA256:d7u2vdKWULm98b3yckWjcTfogpup3bmHUIz8lb13iz0 zuul-build-sshkey 2026-02-24 00:14:16.066455 | controller -> localhost | The key's randomart image is: 2026-02-24 00:14:16.066475 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-24 00:14:16.066492 | controller -> localhost | | | 2026-02-24 00:14:16.066511 | controller -> localhost | | | 2026-02-24 00:14:16.066530 | controller -> localhost | | . o +. | 2026-02-24 00:14:16.066565 | controller -> localhost | | o o =o=o| 2026-02-24 00:14:16.066584 | controller -> localhost | | S = +.++=| 2026-02-24 00:14:16.066603 | controller -> localhost | | + +.+.o=| 2026-02-24 00:14:16.066633 | controller -> localhost | | = +oo.X| 2026-02-24 00:14:16.066653 | controller -> localhost | | .+..+B+Eo| 2026-02-24 00:14:16.066671 | controller -> localhost | | ... ==+B+o| 2026-02-24 00:14:16.066743 | controller -> localhost | +----[SHA256]-----+ 2026-02-24 00:14:16.066798 | controller -> localhost | ok: Runtime: 0:00:00.008812 2026-02-24 00:14:16.074441 | 2026-02-24 00:14:16.074547 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-24 00:14:16.100758 | controller | ok 2026-02-24 00:14:16.113438 | controller | included: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-24 00:14:16.125861 | 2026-02-24 00:14:16.125956 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-24 00:14:16.150885 | controller | skipping: Conditional result was False 2026-02-24 00:14:16.159673 | 2026-02-24 00:14:16.159833 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-24 00:14:16.471932 | controller | changed 2026-02-24 00:14:16.478668 | 2026-02-24 00:14:16.478797 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-24 00:14:16.703833 | controller | ok 2026-02-24 00:14:16.720817 | 2026-02-24 00:14:16.720993 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-24 00:14:17.398088 | controller | changed 2026-02-24 00:14:17.412833 | 2026-02-24 00:14:17.413048 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-24 00:14:18.098466 | controller | changed 2026-02-24 00:14:18.113099 | 2026-02-24 00:14:18.113325 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-24 00:14:18.151803 | controller | skipping: Conditional result was False 2026-02-24 00:14:18.214454 | 2026-02-24 00:14:18.214606 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-24 00:14:18.485184 | controller -> localhost | changed 2026-02-24 00:14:18.511192 | 2026-02-24 00:14:18.511364 | TASK [add-build-sshkey : Add back temp key] 2026-02-24 00:14:18.825630 | controller -> localhost | Identity added: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/3f004160a99545c086b11556934982a2_id_ecdsa (zuul-build-sshkey) 2026-02-24 00:14:18.825911 | controller -> localhost | ok: Runtime: 0:00:00.010439 2026-02-24 00:14:18.836325 | 2026-02-24 00:14:18.836542 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-24 00:14:19.058516 | controller | ok 2026-02-24 00:14:19.074849 | 2026-02-24 00:14:19.075014 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-24 00:14:19.113798 | controller | skipping: Conditional result was False 2026-02-24 00:14:19.142627 | 2026-02-24 00:14:19.142846 | TASK [include_role : remove-zuul-sshkey] 2026-02-24 00:14:19.170980 | controller | skipping: Conditional result was False 2026-02-24 00:14:19.187592 | 2026-02-24 00:14:19.188088 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-24 00:14:19.441209 | controller | ok: "logs" 2026-02-24 00:14:19.441866 | controller | ok: All items complete 2026-02-24 00:14:19.441952 | 2026-02-24 00:14:19.658868 | controller | ok: "artifacts" 2026-02-24 00:14:19.841802 | controller | ok: "docs" 2026-02-24 00:14:19.865980 | 2026-02-24 00:14:19.866240 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-24 00:14:20.096691 | controller | changed: "logs" 2026-02-24 00:14:20.300279 | controller | changed: "artifacts" 2026-02-24 00:14:20.516639 | controller | changed: "docs" 2026-02-24 00:14:20.565850 | 2026-02-24 00:14:20.565973 | PLAY RECAP 2026-02-24 00:14:20.566031 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-24 00:14:20.566066 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-24 00:14:20.566090 | 2026-02-24 00:14:20.727083 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-24 00:14:20.728281 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-24 00:14:21.384365 | 2026-02-24 00:14:21.384497 | PLAY [all] 2026-02-24 00:14:21.417047 | 2026-02-24 00:14:21.417208 | TASK [Install binary dependencies] 2026-02-24 00:14:21.468485 | controller | ok 2026-02-24 00:14:21.493760 | 2026-02-24 00:14:21.493907 | TASK [bindep : Include find tasks] 2026-02-24 00:14:21.526128 | controller | ok 2026-02-24 00:14:21.537629 | controller | included: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-24 00:14:21.546425 | 2026-02-24 00:14:21.546557 | TASK [bindep : Look for bindep.txt] 2026-02-24 00:14:22.137486 | controller | ok 2026-02-24 00:14:22.149372 | 2026-02-24 00:14:22.149493 | TASK [bindep : Define bindep_file fact] 2026-02-24 00:14:22.176167 | controller | skipping: Conditional result was False 2026-02-24 00:14:22.186391 | 2026-02-24 00:14:22.186553 | TASK [bindep : Look for other-requirements.txt] 2026-02-24 00:14:22.414658 | controller | ok 2026-02-24 00:14:22.420542 | 2026-02-24 00:14:22.420614 | TASK [bindep : Define bindep_file fact] 2026-02-24 00:14:22.445049 | controller | skipping: Conditional result was False 2026-02-24 00:14:22.451990 | 2026-02-24 00:14:22.452099 | TASK [bindep : Look for bindep fallback file] 2026-02-24 00:14:22.477052 | controller | skipping: Conditional result was False 2026-02-24 00:14:22.485223 | 2026-02-24 00:14:22.485336 | TASK [bindep : Define bindep_file fact] 2026-02-24 00:14:22.510021 | controller | skipping: Conditional result was False 2026-02-24 00:14:22.520127 | 2026-02-24 00:14:22.520246 | TASK [bindep : Include bindep tasks] 2026-02-24 00:14:22.544943 | controller | skipping: Conditional result was False 2026-02-24 00:14:22.555460 | 2026-02-24 00:14:22.555585 | TASK [bindep : Include install tasks] 2026-02-24 00:14:22.581625 | controller | skipping: Conditional result was False 2026-02-24 00:14:22.591107 | 2026-02-24 00:14:22.591217 | LOOP [bindep : Include package tasks] 2026-02-24 00:14:22.660949 | 2026-02-24 00:14:22.661142 | TASK [Run test-setup role] 2026-02-24 00:14:22.708378 | controller | ok 2026-02-24 00:14:22.756458 | 2026-02-24 00:14:22.756615 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-24 00:14:22.989287 | controller | ok 2026-02-24 00:14:23.003352 | 2026-02-24 00:14:23.003506 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-24 00:14:23.562561 | controller | skipping: Conditional result was False 2026-02-24 00:14:23.615123 | 2026-02-24 00:14:23.615332 | PLAY RECAP 2026-02-24 00:14:23.615403 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-24 00:14:23.615436 | 2026-02-24 00:14:23.732814 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-24 00:14:23.734819 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-24 00:14:24.378752 | 2026-02-24 00:14:24.378875 | PLAY [controller] 2026-02-24 00:14:24.399317 | 2026-02-24 00:14:24.399456 | TASK [Create the /root directory] 2026-02-24 00:14:25.021073 | controller | ok 2026-02-24 00:14:25.031424 | 2026-02-24 00:14:25.031583 | TASK [Install glibc-langpack-en] 2026-02-24 00:14:29.325826 | controller | ok: Nothing to do 2026-02-24 00:14:29.339191 | 2026-02-24 00:14:29.339352 | TASK [Ensure controller directory exists] 2026-02-24 00:14:29.558221 | controller | changed 2026-02-24 00:14:29.565170 | 2026-02-24 00:14:29.565243 | TASK [Install container runtime] 2026-02-24 00:14:29.618002 | controller | ok 2026-02-24 00:14:29.656610 | 2026-02-24 00:14:29.656746 | LOOP [ensure-podman : Find distribution installation] 2026-02-24 00:14:29.681114 | controller | ok: "/var/lib/zuul/builds/3f004160a99545c086b11556934982a2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-24 00:14:29.699291 | controller | included: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-24 00:14:29.708886 | 2026-02-24 00:14:29.709005 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-24 00:15:34.736163 | controller | changed 2026-02-24 00:15:34.753012 | 2026-02-24 00:15:34.753169 | TASK [ensure-podman : Fetch podman version] 2026-02-24 00:15:35.323582 | controller | Client: Podman Engine 2026-02-24 00:15:35.323707 | controller | Version: 4.6.2 2026-02-24 00:15:35.323768 | controller | API Version: 4.6.2 2026-02-24 00:15:35.323813 | controller | Go Version: go1.19.12 2026-02-24 00:15:35.323870 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-24 00:15:35.323917 | controller | OS/Arch: linux/amd64 2026-02-24 00:15:35.807094 | controller | ok: Runtime: 0:00:00.194428 2026-02-24 00:15:35.821448 | 2026-02-24 00:15:35.821633 | TASK [ensure-podman : Print podman version installed] 2026-02-24 00:15:35.861017 | Podman version: Client: Podman Engine 2026-02-24 00:15:35.861188 | Version: 4.6.2 2026-02-24 00:15:35.861225 | API Version: 4.6.2 2026-02-24 00:15:35.861255 | Go Version: go1.19.12 2026-02-24 00:15:35.861282 | Built: Mon Aug 28 19:38:31 2023 2026-02-24 00:15:35.861310 | OS/Arch: linux/amd64 2026-02-24 00:15:35.868965 | 2026-02-24 00:15:35.869069 | TASK [ensure-podman : Validate podman engine] 2026-02-24 00:15:36.402670 | controller | skipping: Conditional result was False 2026-02-24 00:15:36.417326 | 2026-02-24 00:15:36.417477 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-24 00:15:36.444929 | controller | skipping: Conditional result was False 2026-02-24 00:15:36.469467 | 2026-02-24 00:15:36.469613 | TASK [Ensure python3.8 is present] 2026-02-24 00:15:36.497138 | controller | skipping: Conditional result was False 2026-02-24 00:15:36.510456 | 2026-02-24 00:15:36.510612 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-24 00:15:36.540349 | controller | ok 2026-02-24 00:15:36.576827 | 2026-02-24 00:15:36.577053 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-24 00:15:38.049453 | controller | ok: Nothing to do 2026-02-24 00:15:38.064642 | 2026-02-24 00:15:38.064863 | TASK [our-ensure-python : Also install python3-devel] 2026-02-24 00:15:46.148268 | controller | changed 2026-02-24 00:15:46.166740 | 2026-02-24 00:15:46.166881 | TASK [Run ensure-virtualenv role] 2026-02-24 00:15:46.188123 | controller | ok 2026-02-24 00:15:46.212716 | 2026-02-24 00:15:46.212862 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-24 00:15:46.434929 | controller | /usr/bin/virtualenv 2026-02-24 00:15:46.747568 | controller | ok: Runtime: 0:00:00.003884 2026-02-24 00:15:46.758034 | 2026-02-24 00:15:46.758265 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-24 00:15:46.796362 | controller | skipping: Conditional result was False 2026-02-24 00:15:46.796769 | controller | ok: All items complete 2026-02-24 00:15:46.796801 | 2026-02-24 00:15:46.820656 | 2026-02-24 00:15:46.820840 | TASK [Find the full path of the Python interpreter] 2026-02-24 00:15:47.077372 | controller | /usr/bin/python3 2026-02-24 00:15:47.403526 | controller | ok 2026-02-24 00:15:47.420748 | 2026-02-24 00:15:47.421021 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-24 00:15:48.191456 | controller | created virtual environment CPython3.11.0.final.0-64 in 437ms 2026-02-24 00:15:48.209768 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-24 00:15:48.209809 | 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-24 00:15:48.209819 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-24 00:15:48.209835 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-24 00:15:48.485481 | controller | changed 2026-02-24 00:15:48.499266 | 2026-02-24 00:15:48.499402 | TASK [Set selinux package] 2026-02-24 00:15:48.535068 | controller | ok 2026-02-24 00:15:48.542400 | 2026-02-24 00:15:48.542488 | TASK [Set selinux package (Fedora)] 2026-02-24 00:15:48.576169 | controller | ok 2026-02-24 00:15:48.583224 | 2026-02-24 00:15:48.583308 | TASK [Install selinux into virtualenv] 2026-02-24 00:15:49.832148 | controller | Collecting selinux-please-lie-to-me 2026-02-24 00:15:49.879969 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-24 00:15:50.178376 | controller | Collecting setuptools<50.0.0 2026-02-24 00:15:50.186123 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-24 00:15:50.220255 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 26.5 MB/s eta 0:00:00 2026-02-24 00:15:50.302572 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-24 00:15:50.302798 | controller | Attempting uninstall: setuptools 2026-02-24 00:15:50.305178 | controller | Found existing installation: setuptools 62.6.0 2026-02-24 00:15:50.363919 | controller | Uninstalling setuptools-62.6.0: 2026-02-24 00:15:50.372219 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-24 00:15:50.736545 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-24 00:15:50.868346 | controller | 2026-02-24 00:15:50.957033 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-24 00:15:50.957100 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-24 00:15:51.147285 | controller | ok: Runtime: 0:00:02.170924 2026-02-24 00:15:51.156536 | 2026-02-24 00:15:51.156626 | TASK [Install pytest-forked into virtualenv] 2026-02-24 00:15:51.758713 | controller | Collecting pytest-forked 2026-02-24 00:15:51.793580 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-24 00:15:51.833908 | controller | Collecting py 2026-02-24 00:15:51.839174 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-24 00:15:51.857551 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.9 MB/s eta 0:00:00 2026-02-24 00:15:51.964814 | controller | Collecting pytest>=3.10 2026-02-24 00:15:51.968393 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-24 00:15:51.983246 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 31.2 MB/s eta 0:00:00 2026-02-24 00:15:52.025648 | controller | Collecting iniconfig>=1.0.1 2026-02-24 00:15:52.029393 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-24 00:15:52.084211 | controller | Collecting packaging>=22 2026-02-24 00:15:52.087755 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-24 00:15:52.096978 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 9.4 MB/s eta 0:00:00 2026-02-24 00:15:52.127570 | controller | Collecting pluggy<2,>=1.5 2026-02-24 00:15:52.131277 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-24 00:15:52.178420 | controller | Collecting pygments>=2.7.2 2026-02-24 00:15:52.183133 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-24 00:15:52.203477 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 68.8 MB/s eta 0:00:00 2026-02-24 00:15:52.271315 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-24 00:15:53.360309 | 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-24 00:15:53.368825 | controller | 2026-02-24 00:15:53.434194 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-24 00:15:53.434237 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-24 00:15:53.713559 | controller | ok: Runtime: 0:00:02.042154 2026-02-24 00:15:53.730198 | 2026-02-24 00:15:53.730437 | TASK [Update pip] 2026-02-24 00:15:54.305144 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-24 00:15:54.435970 | controller | Collecting pip 2026-02-24 00:15:54.474669 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-24 00:15:54.530614 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 34.9 MB/s eta 0:00:00 2026-02-24 00:15:54.593630 | controller | Installing collected packages: pip 2026-02-24 00:15:54.593858 | controller | Attempting uninstall: pip 2026-02-24 00:15:54.595986 | controller | Found existing installation: pip 22.2.2 2026-02-24 00:15:54.736118 | controller | Uninstalling pip-22.2.2: 2026-02-24 00:15:54.751227 | controller | Successfully uninstalled pip-22.2.2 2026-02-24 00:20:56.735140 | controller | ERROR 2026-02-24 00:20:56.735808 | controller | { 2026-02-24 00:20:56.735856 | controller | "msg": "Data could not be sent to remote host \"162.253.55.70\". Make sure this host can be reached over ssh: ssh: connect to host 162.253.55.70 port 22: No route to host\r\n", 2026-02-24 00:20:56.735882 | controller | "unreachable": true 2026-02-24 00:20:56.735899 | controller | } unreachable 2026-02-24 00:20:56.738450 | 2026-02-24 00:20:56.738499 | PLAY RECAP 2026-02-24 00:20:56.738539 | controller | ok: 16 changed: 8 unreachable: 1 failed: 0 skipped: 4 rescued: 0 ignored: 0 2026-02-24 00:20:56.738561 | 2026-02-24 00:20:56.894099 | PRE-RUN END RESULT_UNREACHABLE: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-24 00:20:56.895255 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-24 00:20:57.453877 | 2026-02-24 00:20:57.453997 | PLAY [all] 2026-02-24 00:20:57.477025 | 2026-02-24 00:20:57.477134 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-24 00:20:57.938201 | controller | changed: non-zero return code 2026-02-24 00:20:57.946351 | 2026-02-24 00:20:57.946464 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-24 00:20:57.973163 | controller | skipping: Conditional result was False 2026-02-24 00:20:57.981901 | 2026-02-24 00:20:57.982007 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-24 00:20:58.017304 | 2026-02-24 00:20:58.017505 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-24 00:20:58.051527 | 2026-02-24 00:20:58.051760 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-24 00:20:58.078126 | controller | skipping: Conditional result was False 2026-02-24 00:20:58.088026 | 2026-02-24 00:20:58.088127 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-24 00:20:58.122182 | 2026-02-24 00:20:58.122373 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-24 00:20:58.148319 | controller | skipping: Conditional result was False 2026-02-24 00:20:58.156669 | 2026-02-24 00:20:58.156793 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-24 00:20:58.182452 | controller | skipping: Conditional result was False 2026-02-24 00:20:58.191099 | 2026-02-24 00:20:58.191202 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-24 00:20:58.207087 | controller | skipping: Conditional result was False 2026-02-24 00:20:58.244341 | 2026-02-24 00:20:58.244442 | PLAY RECAP 2026-02-24 00:20:58.244486 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-24 00:20:58.244506 | 2026-02-24 00:20:58.344001 | POST-RUN END RESULT_UNREACHABLE: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-24 00:20:58.345183 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-24 00:20:59.070043 | 2026-02-24 00:20:59.070374 | PLAY [all:!appliance*] 2026-02-24 00:20:59.104673 | 2026-02-24 00:20:59.104883 | TASK [unregister the node] 2026-02-24 00:20:59.649111 | controller | skipping: Conditional result was False 2026-02-24 00:20:59.657168 | 2026-02-24 00:20:59.657268 | TASK [include_role : fetch-output] 2026-02-24 00:20:59.710929 | controller | ok 2026-02-24 00:20:59.738610 | 2026-02-24 00:20:59.738764 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-24 00:20:59.817709 | controller | skipping: Conditional result was False 2026-02-24 00:20:59.832043 | 2026-02-24 00:20:59.832193 | TASK [fetch-output : Set log path for single node] 2026-02-24 00:20:59.882262 | controller | ok 2026-02-24 00:20:59.894751 | 2026-02-24 00:20:59.894891 | LOOP [fetch-output : Ensure local output dirs] 2026-02-24 00:21:00.344591 | controller -> localhost | ok: "/var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/logs" 2026-02-24 00:21:00.600639 | controller -> localhost | changed: "/var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/artifacts" 2026-02-24 00:21:00.835323 | controller -> localhost | changed: "/var/lib/zuul/builds/3f004160a99545c086b11556934982a2/work/docs" 2026-02-24 00:21:00.846149 | 2026-02-24 00:21:00.846250 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-24 00:21:01.549835 | controller | changed: 2026-02-24 00:21:01.550022 | controller | .d..t...... ./ 2026-02-24 00:21:01.550051 | controller | cd+++++++++ controller/ 2026-02-24 00:21:01.550085 | controller | changed: All items complete 2026-02-24 00:21:01.550107 | 2026-02-24 00:21:02.052513 | controller | changed: .d..t...... ./ 2026-02-24 00:21:02.625265 | controller | changed: .d..t...... ./ 2026-02-24 00:21:02.640765 | 2026-02-24 00:21:02.640894 | TASK [include_role : fetch-output-openshift] 2026-02-24 00:21:02.656374 | controller | skipping: Conditional result was False 2026-02-24 00:21:02.667377 | 2026-02-24 00:21:02.667490 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-24 00:21:02.709356 | controller | skipping: Conditional result was False 2026-02-24 00:21:02.717766 | controller | skipping: Conditional result was False 2026-02-24 00:21:02.760848 | 2026-02-24 00:21:02.760964 | PLAY [localhost] 2026-02-24 00:21:02.779560 | 2026-02-24 00:21:02.779626 | TASK [Run Zuul manifest role] 2026-02-24 00:21:02.796947 | localhost | ok 2026-02-24 00:21:02.812357 | 2026-02-24 00:21:02.812425 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-24 00:21:03.218754 | localhost | changed 2026-02-24 00:21:03.230953 | 2026-02-24 00:21:03.231094 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-24 00:21:03.267862 | localhost | ok 2026-02-24 00:21:03.286328 | 2026-02-24 00:21:03.286482 | TASK [Set zuul-log-path fact] 2026-02-24 00:21:03.316473 | localhost | ok 2026-02-24 00:21:03.337854 | 2026-02-24 00:21:03.337996 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-24 00:21:03.380029 | localhost | ok 2026-02-24 00:21:03.392199 | 2026-02-24 00:21:03.392323 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-02-24 00:21:03.418452 | localhost | ok: 2026-02-24 00:21:03.418630 | localhost | { 2026-02-24 00:21:03.418664 | localhost | "auth": { 2026-02-24 00:21:03.418715 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-02-24 00:21:03.418741 | localhost | "username": "9LF91O0RK7JU" 2026-02-24 00:21:03.418760 | localhost | }, 2026-02-24 00:21:03.418782 | localhost | "profile": "rackspace", 2026-02-24 00:21:03.418802 | localhost | "project_name": "1251317", 2026-02-24 00:21:03.418828 | localhost | "region_name": "DFW" 2026-02-24 00:21:03.418848 | localhost | } 2026-02-24 00:21:03.418882 | 2026-02-24 00:21:03.426605 | 2026-02-24 00:21:03.426765 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-02-24 00:21:03.446964 | localhost | Output suppressed because no_log was given 2026-02-24 00:21:03.466476 | 2026-02-24 00:21:03.466573 | TASK [upload-logs-failover : Initialize control vars] 2026-02-24 00:21:03.497898 | localhost | ok 2026-02-24 00:21:03.504399 | 2026-02-24 00:21:03.504493 | LOOP [upload-logs-failover : Perform log upload] 2026-02-24 00:21:03.541726 | localhost | Output suppressed because no_log was given 2026-02-24 00:21:03.583180 | localhost | included: /var/lib/zuul/builds/3f004160a99545c086b11556934982a2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-02-24 00:21:03.591932 | 2026-02-24 00:21:03.592023 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-02-24 00:21:03.679217 | localhost | Output suppressed because no_log was given 2026-02-24 00:21:03.685241 | 2026-02-24 00:21:03.685316 | TASK [Upload logs to swift] 2026-02-24 00:21:03.714281 | localhost | ok 2026-02-24 00:21:03.754223 | 2026-02-24 00:21:03.754379 | TASK [Set zuul-log-path fact] 2026-02-24 00:21:03.790423 | localhost | skipping: Conditional result was False 2026-02-24 00:21:03.798123 | 2026-02-24 00:21:03.798215 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-24 00:21:04.263928 | localhost -> localhost | ok: Runtime: 0:00:00.009267 2026-02-24 00:21:04.275980 | 2026-02-24 00:21:04.276122 | TASK [upload-logs-swift : Upload logs to swift]