2026-03-13 00:06:57.880563 | Job console starting... 2026-03-13 00:06:57.893930 | Updating repositories 2026-03-13 00:07:00.579466 | Preparing job workspace 2026-03-13 00:07:04.384916 | Running Ansible setup... 2026-03-13 00:07:09.345816 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-13 00:07:09.966555 | 2026-03-13 00:07:09.966677 | PLAY [localhost] 2026-03-13 00:07:09.975017 | 2026-03-13 00:07:09.975086 | TASK [Gathering Facts] 2026-03-13 00:07:10.978329 | localhost | ok 2026-03-13 00:07:10.992360 | 2026-03-13 00:07:10.992455 | TASK [Setup log path fact] 2026-03-13 00:07:11.020360 | localhost | ok 2026-03-13 00:07:11.032455 | 2026-03-13 00:07:11.032527 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-13 00:07:11.072414 | localhost | ok 2026-03-13 00:07:11.084452 | 2026-03-13 00:07:11.084553 | TASK [emit-job-header : Print job information] 2026-03-13 00:07:11.131643 | # Job Information 2026-03-13 00:07:11.131942 | Ansible Version: 2.15.12 2026-03-13 00:07:11.132029 | Job: ansible-test-sanity-docker-stable-2.11 2026-03-13 00:07:11.132091 | Pipeline: periodic 2026-03-13 00:07:11.132145 | Executor: ze03.softwarefactory-project.io 2026-03-13 00:07:11.132201 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-03-13 00:07:11.132282 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/5bb/ansible/5bbb39591b574ea4a1f30489226b105e/ 2026-03-13 00:07:11.132351 | Event ID: 650d3710832e42c2aa0cb22d47460854 2026-03-13 00:07:11.141293 | 2026-03-13 00:07:11.141580 | LOOP [emit-job-header : Print node information] 2026-03-13 00:07:11.261944 | localhost | ok: 2026-03-13 00:07:11.262287 | localhost | # Node Information 2026-03-13 00:07:11.262350 | localhost | Inventory Hostname: controller 2026-03-13 00:07:11.262396 | localhost | Hostname: np0005645843 2026-03-13 00:07:11.262442 | localhost | Username: zuul 2026-03-13 00:07:11.262491 | localhost | Distro: Fedora 37 2026-03-13 00:07:11.262534 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-03-13 00:07:11.262577 | localhost | Region: ca-ymq-1 2026-03-13 00:07:11.262616 | localhost | Label: ansible-fedora-37-1vcpu 2026-03-13 00:07:11.262655 | localhost | Product Name: OpenStack Nova 2026-03-13 00:07:11.262693 | localhost | Interface IP: 162.253.55.195 2026-03-13 00:07:11.279327 | 2026-03-13 00:07:11.279480 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-13 00:07:11.751420 | localhost -> localhost | changed 2026-03-13 00:07:11.757329 | 2026-03-13 00:07:11.757406 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-13 00:07:12.705996 | localhost -> localhost | changed 2026-03-13 00:07:12.730676 | 2026-03-13 00:07:12.730846 | PLAY [all:!appliance*] 2026-03-13 00:07:12.749673 | 2026-03-13 00:07:12.749855 | TASK [include_role : start-zuul-console] 2026-03-13 00:07:12.771507 | controller | ok 2026-03-13 00:07:12.787111 | 2026-03-13 00:07:12.787233 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-03-13 00:07:13.170528 | controller | ok 2026-03-13 00:07:13.196069 | 2026-03-13 00:07:13.196246 | TASK [use-our-mirror : Retrieve the IP address] 2026-03-13 00:07:14.045975 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-03-13 00:07:14.056002 | 2026-03-13 00:07:14.056154 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-03-13 00:07:14.598985 | controller | skipping: Conditional result was False 2026-03-13 00:07:14.606910 | 2026-03-13 00:07:14.607032 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-03-13 00:07:14.642216 | controller | skipping: Conditional result was False 2026-03-13 00:07:14.652148 | 2026-03-13 00:07:14.652271 | TASK [use-our-mirror : Create the podman configuration directory] 2026-03-13 00:07:14.687607 | controller | skipping: Conditional result was False 2026-03-13 00:07:14.701872 | 2026-03-13 00:07:14.702041 | TASK [use-our-mirror : Copy the podman configuration] 2026-03-13 00:07:14.729246 | controller | skipping: Conditional result was False 2026-03-13 00:07:14.738557 | 2026-03-13 00:07:14.738682 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-03-13 00:07:14.773834 | controller | skipping: Conditional result was False 2026-03-13 00:07:14.782657 | 2026-03-13 00:07:14.782785 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-03-13 00:07:14.807014 | controller | skipping: Conditional result was False 2026-03-13 00:07:14.825499 | 2026-03-13 00:07:14.825637 | TASK [Disable Fedora Modular] 2026-03-13 00:07:15.075210 | controller | changed 2026-03-13 00:07:15.081192 | 2026-03-13 00:07:15.081252 | TASK [Enable EPEL] 2026-03-13 00:07:15.104784 | controller | skipping: Conditional result was False 2026-03-13 00:07:15.110851 | 2026-03-13 00:07:15.110915 | TASK [Register the RHEL node] 2026-03-13 00:07:15.657902 | 2026-03-13 00:07:15.658876 | TASK [Show the subscription-manager status] 2026-03-13 00:07:16.244971 | controller | skipping: Conditional result was False 2026-03-13 00:07:16.251513 | 2026-03-13 00:07:16.251597 | TASK [Enable EPEL on RHEL] 2026-03-13 00:07:16.785267 | controller | skipping: Conditional result was False 2026-03-13 00:07:16.791489 | 2026-03-13 00:07:16.791625 | TASK [Install git and tox] 2026-03-13 00:08:43.132563 | controller | changed 2026-03-13 00:08:43.146441 | 2026-03-13 00:08:43.146571 | TASK [include_role : prepare-workspace] 2026-03-13 00:08:43.186135 | controller | ok 2026-03-13 00:08:43.221715 | 2026-03-13 00:08:43.221841 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-13 00:08:43.468939 | controller | ok 2026-03-13 00:08:43.488559 | 2026-03-13 00:08:43.488800 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-13 00:08:57.535988 | controller | Output suppressed because no_log was given 2026-03-13 00:08:57.588306 | 2026-03-13 00:08:57.588563 | TASK [include_role : prepare-workspace-openshift] 2026-03-13 00:08:57.605466 | controller | skipping: Conditional result was False 2026-03-13 00:08:57.630642 | 2026-03-13 00:08:57.630718 | PLAY [all:!appliance] 2026-03-13 00:08:57.648529 | 2026-03-13 00:08:57.648634 | TASK [Run add-build-sshkey role (RSA)] 2026-03-13 00:08:57.669436 | controller | ok 2026-03-13 00:08:57.685491 | 2026-03-13 00:08:57.685601 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-13 00:08:57.947520 | controller -> localhost | ok 2026-03-13 00:08:57.954238 | 2026-03-13 00:08:57.954336 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-13 00:08:57.988024 | controller | ok 2026-03-13 00:08:58.008778 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-13 00:08:58.017532 | 2026-03-13 00:08:58.017637 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-13 00:08:58.441163 | controller -> localhost | Generating public/private rsa key pair. 2026-03-13 00:08:58.441374 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/5bbb39591b574ea4a1f30489226b105e_id_rsa. 2026-03-13 00:08:58.441405 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/5bbb39591b574ea4a1f30489226b105e_id_rsa.pub. 2026-03-13 00:08:58.441427 | controller -> localhost | The key fingerprint is: 2026-03-13 00:08:58.441446 | controller -> localhost | SHA256:WBpKMk12FcpFkKDb6ptfkdmOxcm8YZs4CJ1c9YWWFl0 zuul-build-sshkey 2026-03-13 00:08:58.441465 | controller -> localhost | The key's randomart image is: 2026-03-13 00:08:58.441484 | controller -> localhost | +---[RSA 2048]----+ 2026-03-13 00:08:58.441502 | controller -> localhost | | +.o=*..=..E | 2026-03-13 00:08:58.441521 | controller -> localhost | | = o.+ .=.. | 2026-03-13 00:08:58.441539 | controller -> localhost | | + o = .o. | 2026-03-13 00:08:58.441557 | controller -> localhost | | O + % . | 2026-03-13 00:08:58.441574 | controller -> localhost | | o * * S | 2026-03-13 00:08:58.441604 | controller -> localhost | | o . B = | 2026-03-13 00:08:58.441629 | controller -> localhost | | . . = = | 2026-03-13 00:08:58.441649 | controller -> localhost | | . . . . | 2026-03-13 00:08:58.441668 | controller -> localhost | | +o. | 2026-03-13 00:08:58.441688 | controller -> localhost | +----[SHA256]-----+ 2026-03-13 00:08:58.441779 | controller -> localhost | ok: Runtime: 0:00:00.038873 2026-03-13 00:08:58.450389 | 2026-03-13 00:08:58.450473 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-13 00:08:58.480829 | controller | ok 2026-03-13 00:08:58.492046 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-13 00:08:58.501167 | 2026-03-13 00:08:58.501233 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-13 00:08:58.535092 | controller | skipping: Conditional result was False 2026-03-13 00:08:58.541589 | 2026-03-13 00:08:58.541670 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-13 00:14:02.068133 | controller | changed 2026-03-13 00:14:02.088714 | 2026-03-13 00:14:02.088849 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-13 00:14:02.314025 | controller | ok 2026-03-13 00:14:02.320142 | 2026-03-13 00:14:02.320238 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-13 00:14:02.965538 | controller | changed 2026-03-13 00:14:02.977461 | 2026-03-13 00:14:02.977617 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-13 00:14:03.639498 | controller | changed 2026-03-13 00:14:03.656996 | 2026-03-13 00:14:03.657119 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-13 00:14:03.681002 | controller | skipping: Conditional result was False 2026-03-13 00:14:03.688118 | 2026-03-13 00:14:03.688205 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-13 00:14:04.073843 | controller -> localhost | changed 2026-03-13 00:14:04.090384 | 2026-03-13 00:14:04.090553 | TASK [add-build-sshkey : Add back temp key] 2026-03-13 00:14:04.403106 | controller -> localhost | Identity added: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/5bbb39591b574ea4a1f30489226b105e_id_rsa (zuul-build-sshkey) 2026-03-13 00:14:04.403362 | controller -> localhost | ok: Runtime: 0:00:00.008090 2026-03-13 00:14:04.415337 | 2026-03-13 00:14:04.415450 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-13 00:14:04.767774 | controller | ok 2026-03-13 00:14:04.782793 | 2026-03-13 00:14:04.783130 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-13 00:14:04.820856 | controller | skipping: Conditional result was False 2026-03-13 00:14:04.881707 | 2026-03-13 00:14:04.881834 | TASK [Run add-build-sshkey role (ECDSA)] 2026-03-13 00:14:04.911925 | controller | ok 2026-03-13 00:14:04.928334 | 2026-03-13 00:14:04.928436 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-13 00:14:05.178360 | controller -> localhost | ok 2026-03-13 00:14:05.186036 | 2026-03-13 00:14:05.186326 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-13 00:14:05.216013 | controller | ok 2026-03-13 00:14:05.228401 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-13 00:14:05.235318 | 2026-03-13 00:14:05.235414 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-13 00:14:05.557260 | controller -> localhost | Generating public/private ecdsa key pair. 2026-03-13 00:14:05.557553 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/5bbb39591b574ea4a1f30489226b105e_id_ecdsa. 2026-03-13 00:14:05.557612 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/5bbb39591b574ea4a1f30489226b105e_id_ecdsa.pub. 2026-03-13 00:14:05.557673 | controller -> localhost | The key fingerprint is: 2026-03-13 00:14:05.557716 | controller -> localhost | SHA256:cFs60M2pWF+9MCmKiynrlTxvULGf/bPUfYbOrrLoRMo zuul-build-sshkey 2026-03-13 00:14:05.557796 | controller -> localhost | The key's randomart image is: 2026-03-13 00:14:05.557839 | controller -> localhost | +---[ECDSA 521]---+ 2026-03-13 00:14:05.557879 | controller -> localhost | | | 2026-03-13 00:14:05.557917 | controller -> localhost | | .. o . o | 2026-03-13 00:14:05.557955 | controller -> localhost | | oo+ * = . | 2026-03-13 00:14:05.557994 | controller -> localhost | | oB B o o . | 2026-03-13 00:14:05.558031 | controller -> localhost | | .o.So. . | 2026-03-13 00:14:05.558068 | controller -> localhost | | ..= +o.. . o | 2026-03-13 00:14:05.558105 | controller -> localhost | | . B.E . .. o +| 2026-03-13 00:14:05.558142 | controller -> localhost | | + o.. ...oo ..| 2026-03-13 00:14:05.558217 | controller -> localhost | | .o ...o .oo=+ | 2026-03-13 00:14:05.558256 | controller -> localhost | +----[SHA256]-----+ 2026-03-13 00:14:05.558346 | controller -> localhost | ok: Runtime: 0:00:00.035688 2026-03-13 00:14:05.576299 | 2026-03-13 00:14:05.576502 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-13 00:14:05.612819 | controller | ok 2026-03-13 00:14:05.624228 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-13 00:14:05.638814 | 2026-03-13 00:14:05.638912 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-13 00:14:05.664416 | controller | skipping: Conditional result was False 2026-03-13 00:14:05.673394 | 2026-03-13 00:14:05.673484 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-13 00:14:05.970755 | controller | changed 2026-03-13 00:14:05.979183 | 2026-03-13 00:14:05.979306 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-13 00:14:06.190312 | controller | ok 2026-03-13 00:14:06.197662 | 2026-03-13 00:14:06.197779 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-13 00:14:06.807561 | controller | changed 2026-03-13 00:14:06.824815 | 2026-03-13 00:14:06.825021 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-13 00:14:07.468876 | controller | changed 2026-03-13 00:14:07.485140 | 2026-03-13 00:14:07.485306 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-13 00:14:07.511374 | controller | skipping: Conditional result was False 2026-03-13 00:14:07.519292 | 2026-03-13 00:14:07.519397 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-13 00:14:07.809881 | controller -> localhost | changed 2026-03-13 00:14:07.823118 | 2026-03-13 00:14:07.823239 | TASK [add-build-sshkey : Add back temp key] 2026-03-13 00:14:08.132958 | controller -> localhost | Identity added: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/5bbb39591b574ea4a1f30489226b105e_id_ecdsa (zuul-build-sshkey) 2026-03-13 00:14:08.133221 | controller -> localhost | ok: Runtime: 0:00:00.022095 2026-03-13 00:14:08.141147 | 2026-03-13 00:14:08.141239 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-13 00:14:08.356709 | controller | ok 2026-03-13 00:14:08.363789 | 2026-03-13 00:14:08.363902 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-13 00:14:08.388555 | controller | skipping: Conditional result was False 2026-03-13 00:14:08.401408 | 2026-03-13 00:14:08.401531 | TASK [include_role : remove-zuul-sshkey] 2026-03-13 00:14:08.416266 | controller | skipping: Conditional result was False 2026-03-13 00:14:08.423339 | 2026-03-13 00:14:08.423588 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-13 00:14:08.647178 | controller | ok: "logs" 2026-03-13 00:14:08.647492 | controller | ok: All items complete 2026-03-13 00:14:08.647676 | 2026-03-13 00:14:08.847856 | controller | ok: "artifacts" 2026-03-13 00:14:09.039687 | controller | ok: "docs" 2026-03-13 00:14:09.057631 | 2026-03-13 00:14:09.057859 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-13 00:14:09.303769 | controller | changed: "logs" 2026-03-13 00:14:09.514440 | controller | changed: "artifacts" 2026-03-13 00:14:09.719768 | controller | changed: "docs" 2026-03-13 00:14:09.769637 | 2026-03-13 00:14:09.769864 | PLAY RECAP 2026-03-13 00:14:09.769984 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-03-13 00:14:09.770073 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-13 00:14:09.770147 | 2026-03-13 00:14:09.901668 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-13 00:14:09.903280 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-13 00:14:10.543580 | 2026-03-13 00:14:10.543851 | PLAY [all] 2026-03-13 00:14:10.570485 | 2026-03-13 00:14:10.570616 | TASK [Install binary dependencies] 2026-03-13 00:14:10.642989 | controller | ok 2026-03-13 00:14:10.667255 | 2026-03-13 00:14:10.667398 | TASK [bindep : Include find tasks] 2026-03-13 00:14:10.697561 | controller | ok 2026-03-13 00:14:10.707336 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-03-13 00:14:10.714000 | 2026-03-13 00:14:10.714069 | TASK [bindep : Look for bindep.txt] 2026-03-13 00:14:11.260971 | controller | ok 2026-03-13 00:14:11.276604 | 2026-03-13 00:14:11.276836 | TASK [bindep : Define bindep_file fact] 2026-03-13 00:14:11.315423 | controller | skipping: Conditional result was False 2026-03-13 00:14:11.325069 | 2026-03-13 00:14:11.325186 | TASK [bindep : Look for other-requirements.txt] 2026-03-13 00:14:11.554798 | controller | ok 2026-03-13 00:14:11.561300 | 2026-03-13 00:14:11.561440 | TASK [bindep : Define bindep_file fact] 2026-03-13 00:14:11.591548 | controller | skipping: Conditional result was False 2026-03-13 00:14:11.598048 | 2026-03-13 00:14:11.598253 | TASK [bindep : Look for bindep fallback file] 2026-03-13 00:14:11.622519 | controller | skipping: Conditional result was False 2026-03-13 00:14:11.630133 | 2026-03-13 00:14:11.630239 | TASK [bindep : Define bindep_file fact] 2026-03-13 00:14:11.656167 | controller | skipping: Conditional result was False 2026-03-13 00:14:11.664029 | 2026-03-13 00:14:11.664135 | TASK [bindep : Include bindep tasks] 2026-03-13 00:14:11.690622 | controller | skipping: Conditional result was False 2026-03-13 00:14:11.698809 | 2026-03-13 00:14:11.698912 | TASK [bindep : Include install tasks] 2026-03-13 00:14:11.723346 | controller | skipping: Conditional result was False 2026-03-13 00:14:11.732693 | 2026-03-13 00:14:11.732829 | LOOP [bindep : Include package tasks] 2026-03-13 00:14:11.810903 | 2026-03-13 00:14:11.811189 | TASK [Run test-setup role] 2026-03-13 00:14:11.855529 | controller | ok 2026-03-13 00:14:11.875159 | 2026-03-13 00:14:11.875332 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-03-13 00:14:12.080100 | controller | ok 2026-03-13 00:14:12.088580 | 2026-03-13 00:14:12.088707 | TASK [test-setup : Run tools/test-setup.sh] 2026-03-13 00:14:12.636533 | controller | skipping: Conditional result was False 2026-03-13 00:14:12.666295 | 2026-03-13 00:14:12.666407 | PLAY RECAP 2026-03-13 00:14:12.666456 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-13 00:14:12.666477 | 2026-03-13 00:14:12.793406 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-13 00:14:12.794293 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-13 00:14:13.425613 | 2026-03-13 00:14:13.425773 | PLAY [controller] 2026-03-13 00:14:13.449880 | 2026-03-13 00:14:13.450028 | TASK [Create the /root directory] 2026-03-13 00:14:14.018493 | controller | ok 2026-03-13 00:14:14.024124 | 2026-03-13 00:14:14.024196 | TASK [Install glibc-langpack-en] 2026-03-13 00:14:18.141791 | controller | ok: Nothing to do 2026-03-13 00:14:18.148558 | 2026-03-13 00:14:18.148632 | TASK [Ensure controller directory exists] 2026-03-13 00:14:18.382407 | controller | changed 2026-03-13 00:14:18.388671 | 2026-03-13 00:14:18.388763 | TASK [Install container runtime] 2026-03-13 00:14:18.440159 | controller | ok 2026-03-13 00:14:18.492586 | 2026-03-13 00:14:18.492714 | LOOP [ensure-docker : Gather variables for each operating system] 2026-03-13 00:14:18.533031 | controller | ok: "/var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml" 2026-03-13 00:14:18.545385 | 2026-03-13 00:14:18.545528 | TASK [ensure-docker : Sanity check for distro selection] 2026-03-13 00:14:18.559846 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.568070 | 2026-03-13 00:14:18.568180 | TASK [ensure-docker : Sanity check for distro install] 2026-03-13 00:14:18.597276 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.603672 | 2026-03-13 00:14:18.603780 | TASK [ensure-docker : Sanity check for upstream install] 2026-03-13 00:14:18.629483 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.642035 | 2026-03-13 00:14:18.642181 | TASK [ensure-docker : Sanity check for upstream install mirrors] 2026-03-13 00:14:18.667468 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.690874 | 2026-03-13 00:14:18.691059 | TASK [ensure-docker : Include tasks for docker install] 2026-03-13 00:14:18.711431 | controller | ok 2026-03-13 00:14:18.720336 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml 2026-03-13 00:14:18.728382 | 2026-03-13 00:14:18.728485 | TASK [ensure-docker : Not Implemented] 2026-03-13 00:14:18.743114 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.753828 | 2026-03-13 00:14:18.754021 | TASK [Set up docker mirrors] 2026-03-13 00:14:18.777069 | controller | ok 2026-03-13 00:14:18.800989 | 2026-03-13 00:14:18.801119 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info] 2026-03-13 00:14:18.836971 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.844562 | 2026-03-13 00:14:18.844756 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info] 2026-03-13 00:14:18.881326 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.889242 | 2026-03-13 00:14:18.889400 | TASK [use-docker-mirror : Set docker_mirror fact] 2026-03-13 00:14:18.924158 | controller | skipping: Conditional result was False 2026-03-13 00:14:18.932396 | 2026-03-13 00:14:18.932525 | TASK [use-docker-mirror : Set up docker mirrors] 2026-03-13 00:14:18.987213 | controller | skipping: Conditional result was False 2026-03-13 00:14:19.002311 | 2026-03-13 00:14:19.002449 | TASK [Add all repositories] 2026-03-13 00:14:19.033144 | controller | ok 2026-03-13 00:14:19.065822 | 2026-03-13 00:14:19.065968 | LOOP [ensure-package-repositories : Install repositories] 2026-03-13 00:14:19.097667 | controller | ok: "/var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml" 2026-03-13 00:14:19.097937 | controller | ok: All items complete 2026-03-13 00:14:19.097968 | 2026-03-13 00:14:19.151975 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml 2026-03-13 00:14:19.165265 | 2026-03-13 00:14:19.165421 | TASK [ensure-package-repositories : Create GPG key temp directory] 2026-03-13 00:14:19.556539 | controller | changed 2026-03-13 00:14:19.566065 | 2026-03-13 00:14:19.566163 | LOOP [ensure-package-repositories : Upload GPG keys] 2026-03-13 00:14:20.441194 | controller | changed: 2026-03-13 00:14:20.441664 | controller | { 2026-03-13 00:14:20.441930 | controller | "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n" 2026-03-13 00:14:20.442018 | controller | } 2026-03-13 00:14:20.459196 | 2026-03-13 00:14:20.459311 | LOOP [ensure-package-repositories : Import GPG keys] 2026-03-13 00:14:21.171252 | controller | changed: 2026-03-13 00:14:21.171457 | controller | { 2026-03-13 00:14:21.171484 | controller | "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n" 2026-03-13 00:14:21.171506 | controller | } 2026-03-13 00:14:21.171592 | controller | changed: All items complete 2026-03-13 00:14:21.171616 | 2026-03-13 00:14:21.188170 | 2026-03-13 00:14:21.188357 | TASK [ensure-package-repositories : Remove GPG temp directory] 2026-03-13 00:14:21.418983 | controller | changed 2026-03-13 00:14:21.430620 | 2026-03-13 00:14:21.430808 | LOOP [ensure-package-repositories : Add repositories] 2026-03-13 00:14:21.792508 | controller | changed: 2026-03-13 00:14:21.792740 | controller | { 2026-03-13 00:14:21.792781 | controller | "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable", 2026-03-13 00:14:21.792808 | controller | "description": "Docker CE Stable - $basearch", 2026-03-13 00:14:21.792831 | controller | "gpgcheck": true, 2026-03-13 00:14:21.792853 | controller | "name": "docker-ce-stable" 2026-03-13 00:14:21.792875 | controller | } 2026-03-13 00:14:21.812743 | 2026-03-13 00:14:21.812871 | TASK [ensure-docker : Install pre-reqs] 2026-03-13 00:14:24.465481 | controller | ok: Nothing to do 2026-03-13 00:14:24.471962 | 2026-03-13 00:14:24.472062 | TASK [ensure-docker : Remove packages] 2026-03-13 00:14:25.819946 | controller | ok: Nothing to do 2026-03-13 00:14:25.831240 | 2026-03-13 00:14:25.831350 | TASK [ensure-docker : Install upstream docker using package] 2026-03-13 00:15:14.169700 | controller | changed 2026-03-13 00:15:14.188317 | 2026-03-13 00:15:14.188601 | TASK [ensure-docker : Setup docker] 2026-03-13 00:15:14.217953 | controller | ok 2026-03-13 00:15:14.252502 | controller | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml 2026-03-13 00:15:14.271844 | 2026-03-13 00:15:14.271930 | TASK [ensure-docker : Ensure "docker" group exists] 2026-03-13 00:15:14.717771 | controller | ok 2026-03-13 00:15:14.731604 | 2026-03-13 00:15:14.731780 | TASK [ensure-docker : Add user to docker group] 2026-03-13 00:15:15.288073 | controller | changed 2026-03-13 00:15:15.302762 | 2026-03-13 00:15:15.302899 | TASK [Update docker daemon proxy configuration] 2026-03-13 00:15:15.341328 | controller | skipping: Conditional result was False 2026-03-13 00:15:15.350792 | 2026-03-13 00:15:15.350894 | TASK [Lower default MTU] 2026-03-13 00:15:15.375402 | controller | skipping: Conditional result was False 2026-03-13 00:15:15.386231 | 2026-03-13 00:15:15.386331 | TASK [ensure-docker : Get the status of the docket.socket unit] 2026-03-13 00:15:15.784531 | controller | inactive 2026-03-13 00:15:15.932101 | controller | ok: Runtime: 0:00:00.015896 2026-03-13 00:15:15.940005 | 2026-03-13 00:15:15.940097 | TASK [ensure-docker : Get the status of the docket unit] 2026-03-13 00:15:16.194384 | controller | inactive 2026-03-13 00:15:16.478526 | controller | ok: Runtime: 0:00:00.010919 2026-03-13 00:15:16.484936 | 2026-03-13 00:15:16.485001 | TASK [ensure-docker : Restart docker] 2026-03-13 00:15:16.524854 | Trigger a Docker restart 2026-03-13 00:15:16.531200 | 2026-03-13 00:15:16.531280 | TASK [ensure-docker : Reset ssh connection to pick up docker group] 2026-03-13 00:15:16.558680 | 2026-03-13 00:15:16.558842 | TASK [ensure-docker : Install docker-compose] 2026-03-13 00:15:16.573009 | controller | skipping: Conditional result was False 2026-03-13 00:15:16.624024 | 2026-03-13 00:15:16.624229 | TASK [ensure-docker : Flush handlers before role exit] 2026-03-13 00:15:16.639326 | 2026-03-13 00:15:16.639422 | TASK [ensure-docker : Stop docker.socket to avoid any conflict] 2026-03-13 00:15:17.822541 | controller | changed 2026-03-13 00:15:17.844621 | 2026-03-13 00:15:17.844822 | TASK [ensure-docker : Assure docker service is running] 2026-03-13 00:15:19.661789 | controller | changed 2026-03-13 00:15:19.677254 | 2026-03-13 00:15:19.677367 | TASK [ensure-docker : Assure docker.socket service is running] 2026-03-13 00:15:20.581438 | controller | ok 2026-03-13 00:15:20.592666 | 2026-03-13 00:15:20.592805 | TASK [ensure-docker : Correct group ownership on docker sock] 2026-03-13 00:15:21.223848 | controller | ok 2026-03-13 00:15:21.232561 | 2026-03-13 00:15:21.232671 | TASK [ensure-docker : Validate ability to talk with docker] 2026-03-13 00:15:21.849443 | controller | CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 2026-03-13 00:15:22.275676 | controller | ok: Runtime: 0:00:00.050700 2026-03-13 00:15:22.291391 | 2026-03-13 00:15:22.291570 | TASK [ensure-docker : Get version details] 2026-03-13 00:15:22.928092 | controller | Client: Docker Engine - Community 2026-03-13 00:15:22.928217 | controller | Version: 24.0.7 2026-03-13 00:15:22.928253 | controller | API version: 1.43 2026-03-13 00:15:22.928284 | controller | Go version: go1.20.10 2026-03-13 00:15:22.928322 | controller | Git commit: afdd53b 2026-03-13 00:15:22.928358 | controller | Built: Thu Oct 26 09:09:39 2023 2026-03-13 00:15:22.928395 | controller | OS/Arch: linux/amd64 2026-03-13 00:15:22.928432 | controller | Context: default 2026-03-13 00:15:22.928447 | controller | 2026-03-13 00:15:22.928480 | controller | Server: Docker Engine - Community 2026-03-13 00:15:22.928513 | controller | Engine: 2026-03-13 00:15:22.928611 | controller | Version: 24.0.7 2026-03-13 00:15:22.928644 | controller | API version: 1.43 (minimum version 1.12) 2026-03-13 00:15:22.928673 | controller | Go version: go1.20.10 2026-03-13 00:15:22.928703 | controller | Git commit: 311b9ff 2026-03-13 00:15:22.928738 | controller | Built: Thu Oct 26 09:08:11 2023 2026-03-13 00:15:22.928791 | controller | OS/Arch: linux/amd64 2026-03-13 00:15:22.928824 | controller | Experimental: false 2026-03-13 00:15:22.928843 | controller | containerd: 2026-03-13 00:15:22.928917 | controller | Version: 1.6.25 2026-03-13 00:15:22.928948 | controller | GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f 2026-03-13 00:15:22.928967 | controller | runc: 2026-03-13 00:15:22.929059 | controller | Version: 1.1.10 2026-03-13 00:15:22.929091 | controller | GitCommit: v1.1.10-0-g18a0cb0 2026-03-13 00:15:22.929112 | controller | docker-init: 2026-03-13 00:15:22.929200 | controller | Version: 0.19.0 2026-03-13 00:15:22.929300 | controller | GitCommit: de40ad0 2026-03-13 00:15:23.353399 | controller | ok: Runtime: 0:00:00.048645 2026-03-13 00:15:23.370350 | 2026-03-13 00:15:23.370533 | TASK [ensure-docker : Dump installed docker details] 2026-03-13 00:15:23.424179 | {'changed': True, 'stdout': 'Client: Docker Engine - Community\n Version: 24.0.7\n API version: 1.43\n Go version: go1.20.10\n Git commit: afdd53b\n Built: Thu Oct 26 09:09:39 2023\n OS/Arch: linux/amd64\n Context: default\n\nServer: Docker Engine - Community\n Engine:\n Version: 24.0.7\n API version: 1.43 (minimum version 1.12)\n Go version: go1.20.10\n Git commit: 311b9ff\n Built: Thu Oct 26 09:08:11 2023\n OS/Arch: linux/amd64\n Experimental: false\n containerd:\n Version: 1.6.25\n GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f\n runc:\n Version: 1.1.10\n GitCommit: v1.1.10-0-g18a0cb0\n docker-init:\n Version: 0.19.0\n GitCommit: de40ad0', 'stderr': '', 'rc': 0, 'cmd': ['docker', 'version'], 'start': '2026-03-13 00:15:22.885236', 'end': '2026-03-13 00:15:22.933881', 'delta': '0:00:00.048645', 'msg': '', 'zuul_log_id': 'fa163ef9-e89a-c0bf-fe59-000000000061-1-controller', 'stdout_lines': ['Client: Docker Engine - Community', ' Version: 24.0.7', ' API version: 1.43', ' Go version: go1.20.10', ' Git commit: afdd53b', ' Built: Thu Oct 26 09:09:39 2023', ' OS/Arch: linux/amd64', ' Context: default', '', 'Server: Docker Engine - Community', ' Engine:', ' Version: 24.0.7', ' API version: 1.43 (minimum version 1.12)', ' Go version: go1.20.10', ' Git commit: 311b9ff', ' Built: Thu Oct 26 09:08:11 2023', ' OS/Arch: linux/amd64', ' Experimental: false', ' containerd:', ' Version: 1.6.25', ' GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f', ' runc:', ' Version: 1.1.10', ' GitCommit: v1.1.10-0-g18a0cb0', ' docker-init:', ' Version: 0.19.0', ' GitCommit: de40ad0'], 'stderr_lines': [], 'failed': False} 2026-03-13 00:15:23.439827 | 2026-03-13 00:15:23.439969 | TASK [Use buildset registry] 2026-03-13 00:15:23.465592 | controller | skipping: Conditional result was False 2026-03-13 00:15:23.483339 | 2026-03-13 00:15:23.483456 | TASK [Ensure python3.8 is present] 2026-03-13 00:15:23.498791 | controller | skipping: Conditional result was False 2026-03-13 00:15:23.508947 | 2026-03-13 00:15:23.509068 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-03-13 00:15:23.532824 | controller | ok 2026-03-13 00:15:23.562005 | 2026-03-13 00:15:23.562106 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-03-13 00:15:25.754844 | controller | ok: Nothing to do 2026-03-13 00:15:25.767541 | 2026-03-13 00:15:25.767711 | TASK [our-ensure-python : Also install python3-devel] 2026-03-13 00:15:36.933159 | controller | changed 2026-03-13 00:15:36.954561 | 2026-03-13 00:15:36.954689 | TASK [Run ensure-virtualenv role] 2026-03-13 00:15:36.997610 | controller | ok 2026-03-13 00:15:37.026321 | 2026-03-13 00:15:37.026446 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-03-13 00:15:37.295127 | controller | /usr/bin/virtualenv 2026-03-13 00:15:37.601362 | controller | ok: Runtime: 0:00:00.003515 2026-03-13 00:15:37.614837 | 2026-03-13 00:15:37.614983 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-03-13 00:15:37.646268 | controller | skipping: Conditional result was False 2026-03-13 00:15:37.646561 | controller | changed: All items complete 2026-03-13 00:15:37.646590 | 2026-03-13 00:15:37.680119 | 2026-03-13 00:15:37.680353 | TASK [Find the full path of the Python interpreter] 2026-03-13 00:15:37.892719 | controller | /usr/bin/python3.9 2026-03-13 00:15:38.225459 | controller | ok 2026-03-13 00:15:38.231570 | 2026-03-13 00:15:38.231672 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-03-13 00:15:39.984825 | controller | created virtual environment CPython3.9.18.final.0-64 in 920ms 2026-03-13 00:15:40.032709 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-03-13 00:15:40.032744 | 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-13 00:15:40.032758 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-03-13 00:15:40.032770 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-03-13 00:15:40.265683 | controller | changed 2026-03-13 00:15:40.274274 | 2026-03-13 00:15:40.274389 | TASK [Set selinux package] 2026-03-13 00:15:40.297455 | controller | ok 2026-03-13 00:15:40.306983 | 2026-03-13 00:15:40.307091 | TASK [Set selinux package (Fedora)] 2026-03-13 00:15:40.351165 | controller | ok 2026-03-13 00:15:40.359797 | 2026-03-13 00:15:40.359941 | TASK [Install selinux into virtualenv] 2026-03-13 00:15:43.789820 | controller | Collecting selinux-please-lie-to-me 2026-03-13 00:15:43.917536 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-03-13 00:15:44.948473 | controller | Collecting setuptools<50.0.0 2026-03-13 00:15:44.977321 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-03-13 00:15:45.103553 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 6.6 MB/s eta 0:00:00 2026-03-13 00:15:45.305879 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-03-13 00:15:45.308018 | controller | Attempting uninstall: setuptools 2026-03-13 00:15:45.310004 | controller | Found existing installation: setuptools 62.6.0 2026-03-13 00:15:45.520268 | controller | Uninstalling setuptools-62.6.0: 2026-03-13 00:15:45.559470 | controller | Successfully uninstalled setuptools-62.6.0 2026-03-13 00:15:46.386097 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-03-13 00:15:46.745116 | controller | 2026-03-13 00:15:47.006123 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-13 00:15:47.006148 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2026-03-13 00:15:47.415033 | controller | ok: Runtime: 0:00:06.116982 2026-03-13 00:15:47.430512 | 2026-03-13 00:15:47.430670 | TASK [Install pytest-forked into virtualenv] 2026-03-13 00:15:49.060822 | controller | Collecting pytest-forked 2026-03-13 00:15:49.212625 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-03-13 00:15:49.254529 | controller | Collecting py 2026-03-13 00:15:49.324191 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-03-13 00:15:49.369370 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.2 MB/s eta 0:00:00 2026-03-13 00:15:49.664540 | controller | Collecting pytest>=3.10 2026-03-13 00:15:49.698337 | controller | Downloading pytest-8.4.2-py3-none-any.whl (365 kB) 2026-03-13 00:15:49.737821 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 10.0 MB/s eta 0:00:00 2026-03-13 00:15:49.822253 | controller | Collecting exceptiongroup>=1 2026-03-13 00:15:49.853749 | controller | Downloading exceptiongroup-1.3.1-py3-none-any.whl (16 kB) 2026-03-13 00:15:49.915010 | controller | Collecting pluggy<2,>=1.5 2026-03-13 00:15:49.941333 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-03-13 00:15:50.056337 | controller | Collecting tomli>=1 2026-03-13 00:15:50.096248 | controller | Downloading tomli-2.4.0-py3-none-any.whl (14 kB) 2026-03-13 00:15:50.125620 | controller | Collecting iniconfig>=1 2026-03-13 00:15:50.151214 | controller | Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB) 2026-03-13 00:15:50.256243 | controller | Collecting pygments>=2.7.2 2026-03-13 00:15:50.286789 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-03-13 00:15:50.327999 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 31.2 MB/s eta 0:00:00 2026-03-13 00:15:50.381212 | controller | Collecting packaging>=20 2026-03-13 00:15:50.404380 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-03-13 00:15:50.411637 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 12.5 MB/s eta 0:00:00 2026-03-13 00:15:50.461960 | controller | Collecting typing-extensions>=4.6.0 2026-03-13 00:15:50.485642 | controller | Downloading typing_extensions-4.15.0-py3-none-any.whl (44 kB) 2026-03-13 00:15:50.496681 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 44.6/44.6 kB 4.4 MB/s eta 0:00:00 2026-03-13 00:15:50.565896 | controller | Installing collected packages: typing-extensions, tomli, pygments, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked 2026-03-13 00:15:51.698322 | controller | Successfully installed exceptiongroup-1.3.1 iniconfig-2.1.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0 tomli-2.4.0 typing-extensions-4.15.0 2026-03-13 00:15:51.701430 | controller | 2026-03-13 00:15:51.783354 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-13 00:15:51.783399 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2026-03-13 00:15:51.999034 | controller | ok: Runtime: 0:00:03.828488 2026-03-13 00:15:52.009903 | 2026-03-13 00:15:52.010034 | TASK [Update pip] 2026-03-13 00:15:53.541723 | controller | Requirement already satisfied: pip in ./venv/lib/python3.9/site-packages (22.2.2) 2026-03-13 00:15:53.861224 | controller | Collecting pip 2026-03-13 00:15:53.986201 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-03-13 00:15:54.116284 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 14.1 MB/s eta 0:00:00 2026-03-13 00:15:54.174397 | controller | Installing collected packages: pip 2026-03-13 00:15:54.174567 | controller | Attempting uninstall: pip 2026-03-13 00:15:54.175162 | controller | Found existing installation: pip 22.2.2 2026-03-13 00:15:54.552294 | controller | Uninstalling pip-22.2.2: 2026-03-13 00:15:54.611435 | controller | Successfully uninstalled pip-22.2.2 2026-03-13 00:15:57.017348 | controller | Successfully installed pip-26.0.1 2026-03-13 00:15:57.579672 | controller | ok: Runtime: 0:00:04.632961 2026-03-13 00:15:57.585948 | 2026-03-13 00:15:57.586023 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-03-13 00:15:58.157607 | controller | changed 2026-03-13 00:15:58.172819 | 2026-03-13 00:15:58.173001 | TASK [Install ansible into virtualenv] 2026-03-13 00:15:59.576455 | controller | Processing ./src/github.com/ansible/ansible 2026-03-13 00:15:59.592733 | controller | Installing build dependencies: started 2026-03-13 00:16:01.648435 | controller | Installing build dependencies: finished with status 'done' 2026-03-13 00:16:01.649329 | controller | Getting requirements to build wheel: started 2026-03-13 00:16:02.507080 | controller | Getting requirements to build wheel: finished with status 'done' 2026-03-13 00:16:02.508235 | controller | Preparing metadata (pyproject.toml): started 2026-03-13 00:16:02.999206 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-03-13 00:16:03.080326 | controller | Collecting jinja2 (from ansible-core==2.11.12.post0) 2026-03-13 00:16:03.187516 | controller | Downloading jinja2-3.1.6-py3-none-any.whl.metadata (2.9 kB) 2026-03-13 00:16:03.274027 | controller | Collecting PyYAML (from ansible-core==2.11.12.post0) 2026-03-13 00:16:03.303572 | controller | Downloading pyyaml-6.0.3-cp39-cp39-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl.metadata (2.4 kB) 2026-03-13 00:16:03.589178 | controller | Collecting cryptography (from ansible-core==2.11.12.post0) 2026-03-13 00:16:03.615658 | controller | Downloading cryptography-46.0.5-cp38-abi3-manylinux_2_34_x86_64.whl.metadata (5.7 kB) 2026-03-13 00:16:03.632056 | controller | Requirement already satisfied: packaging in ./venv/lib/python3.9/site-packages (from ansible-core==2.11.12.post0) (26.0) 2026-03-13 00:21:06.080985 | controller | ERROR 2026-03-13 00:21:06.081872 | controller | { 2026-03-13 00:21:06.081970 | controller | "msg": "Data could not be sent to remote host \"162.253.55.195\". Make sure this host can be reached over ssh: ssh: connect to host 162.253.55.195 port 22: Connection timed out\r\n", 2026-03-13 00:21:06.082025 | controller | "unreachable": true 2026-03-13 00:21:06.082064 | controller | } unreachable 2026-03-13 00:21:06.083816 | 2026-03-13 00:21:06.083973 | PLAY RECAP 2026-03-13 00:21:06.084064 | controller | ok: 38 changed: 21 unreachable: 1 failed: 0 skipped: 15 rescued: 0 ignored: 0 2026-03-13 00:21:06.084112 | 2026-03-13 00:21:06.243676 | PRE-RUN END RESULT_UNREACHABLE: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-13 00:21:06.245056 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-13 00:21:06.861953 | 2026-03-13 00:21:06.862079 | PLAY [all] 2026-03-13 00:21:06.887472 | 2026-03-13 00:21:06.887636 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-03-13 00:21:07.381779 | controller | changed: non-zero return code 2026-03-13 00:21:07.387513 | 2026-03-13 00:21:07.387588 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-03-13 00:21:07.401344 | controller | skipping: Conditional result was False 2026-03-13 00:21:07.408984 | 2026-03-13 00:21:07.409120 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-03-13 00:21:07.429997 | 2026-03-13 00:21:07.430157 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-03-13 00:21:07.450687 | 2026-03-13 00:21:07.450882 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-03-13 00:21:07.464989 | controller | skipping: Conditional result was False 2026-03-13 00:21:07.473192 | 2026-03-13 00:21:07.473310 | LOOP [fetch-subunit-output : Generate subunit file] 2026-03-13 00:21:07.493334 | 2026-03-13 00:21:07.493494 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-03-13 00:21:07.506839 | controller | skipping: Conditional result was False 2026-03-13 00:21:07.524524 | 2026-03-13 00:21:07.524663 | TASK [fetch-subunit-output : Remove the temporary file] 2026-03-13 00:21:07.538665 | controller | skipping: Conditional result was False 2026-03-13 00:21:07.546904 | 2026-03-13 00:21:07.547017 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-03-13 00:21:07.565295 | controller | skipping: Conditional result was False 2026-03-13 00:21:07.594106 | 2026-03-13 00:21:07.594220 | PLAY RECAP 2026-03-13 00:21:07.594284 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-13 00:21:07.594308 | 2026-03-13 00:21:07.754485 | POST-RUN END RESULT_UNREACHABLE: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-13 00:21:07.755963 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-03-13 00:21:08.310297 | 2026-03-13 00:21:08.310417 | PLAY [all:!appliance*] 2026-03-13 00:21:08.347243 | 2026-03-13 00:21:08.347384 | TASK [unregister the node] 2026-03-13 00:21:08.879239 | controller | skipping: Conditional result was False 2026-03-13 00:21:08.887100 | 2026-03-13 00:21:08.887253 | TASK [include_role : fetch-output] 2026-03-13 00:21:08.919865 | controller | ok 2026-03-13 00:21:08.947324 | 2026-03-13 00:21:08.947462 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-13 00:21:09.003886 | controller | skipping: Conditional result was False 2026-03-13 00:21:09.013433 | 2026-03-13 00:21:09.013586 | TASK [fetch-output : Set log path for single node] 2026-03-13 00:21:09.059997 | controller | ok 2026-03-13 00:21:09.067438 | 2026-03-13 00:21:09.067569 | LOOP [fetch-output : Ensure local output dirs] 2026-03-13 00:21:09.464339 | controller -> localhost | ok: "/var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/logs" 2026-03-13 00:21:09.677984 | controller -> localhost | changed: "/var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/artifacts" 2026-03-13 00:21:09.916906 | controller -> localhost | changed: "/var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/work/docs" 2026-03-13 00:21:09.927323 | 2026-03-13 00:21:09.927447 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-13 00:21:10.601989 | controller | changed: 2026-03-13 00:21:10.602277 | controller | .d..t...... ./ 2026-03-13 00:21:10.602320 | controller | cd+++++++++ controller/ 2026-03-13 00:21:10.602367 | controller | changed: All items complete 2026-03-13 00:21:10.602396 | 2026-03-13 00:21:11.153730 | controller | changed: .d..t...... ./ 2026-03-13 00:21:11.605256 | controller | changed: .d..t...... ./ 2026-03-13 00:21:11.623716 | 2026-03-13 00:21:11.623978 | TASK [include_role : fetch-output-openshift] 2026-03-13 00:21:11.639967 | controller | skipping: Conditional result was False 2026-03-13 00:21:11.647335 | 2026-03-13 00:21:11.647432 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-13 00:21:11.674261 | controller | skipping: Conditional result was False 2026-03-13 00:21:11.683769 | controller | skipping: Conditional result was False 2026-03-13 00:21:11.722175 | 2026-03-13 00:21:11.722278 | PLAY [localhost] 2026-03-13 00:21:11.735329 | 2026-03-13 00:21:11.735425 | TASK [Run Zuul manifest role] 2026-03-13 00:21:11.754035 | localhost | ok 2026-03-13 00:21:11.768576 | 2026-03-13 00:21:11.768683 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-13 00:21:12.134328 | localhost | changed 2026-03-13 00:21:12.139283 | 2026-03-13 00:21:12.139383 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-13 00:21:12.177706 | localhost | ok 2026-03-13 00:21:12.185810 | 2026-03-13 00:21:12.185898 | TASK [Set zuul-log-path fact] 2026-03-13 00:21:12.203931 | localhost | ok 2026-03-13 00:21:12.217489 | 2026-03-13 00:21:12.217583 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-13 00:21:12.248540 | localhost | ok 2026-03-13 00:21:12.260680 | 2026-03-13 00:21:12.260819 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-03-13 00:21:12.288044 | localhost | ok: 2026-03-13 00:21:12.288292 | localhost | { 2026-03-13 00:21:12.288332 | localhost | "auth": { 2026-03-13 00:21:12.288364 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-03-13 00:21:12.288392 | localhost | "username": "9LF91O0RK7JU" 2026-03-13 00:21:12.288416 | localhost | }, 2026-03-13 00:21:12.288442 | localhost | "profile": "rackspace", 2026-03-13 00:21:12.288466 | localhost | "region_name": "ORD" 2026-03-13 00:21:12.288491 | localhost | } 2026-03-13 00:21:12.288532 | 2026-03-13 00:21:12.301995 | 2026-03-13 00:21:12.302095 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-03-13 00:21:12.320227 | localhost | Output suppressed because no_log was given 2026-03-13 00:21:12.332970 | 2026-03-13 00:21:12.333069 | TASK [upload-logs-failover : Initialize control vars] 2026-03-13 00:21:12.361128 | localhost | ok 2026-03-13 00:21:12.365829 | 2026-03-13 00:21:12.365909 | LOOP [upload-logs-failover : Perform log upload] 2026-03-13 00:21:12.394741 | localhost | Output suppressed because no_log was given 2026-03-13 00:21:12.402508 | localhost | included: /var/lib/zuul/builds/5bbb39591b574ea4a1f30489226b105e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-03-13 00:21:12.442271 | 2026-03-13 00:21:12.442373 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-03-13 00:21:12.529818 | localhost | Output suppressed because no_log was given 2026-03-13 00:21:12.538154 | 2026-03-13 00:21:12.538290 | TASK [Upload logs to swift] 2026-03-13 00:21:12.560145 | localhost | ok 2026-03-13 00:21:12.596273 | 2026-03-13 00:21:12.596385 | TASK [Set zuul-log-path fact] 2026-03-13 00:21:12.620594 | localhost | skipping: Conditional result was False 2026-03-13 00:21:12.626213 | 2026-03-13 00:21:12.626327 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-03-13 00:21:13.001493 | localhost -> localhost | ok: Runtime: 0:00:00.006270 2026-03-13 00:21:13.009043 | 2026-03-13 00:21:13.009158 | TASK [upload-logs-swift : Upload logs to swift]