2026-02-25 00:07:00.829922 | Job console starting... 2026-02-25 00:07:00.845967 | Updating repositories 2026-02-25 00:07:01.019729 | Preparing job workspace 2026-02-25 00:07:04.759562 | Running Ansible setup... 2026-02-25 00:07:09.672374 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-25 00:07:12.977338 | 2026-02-25 00:07:12.977468 | PLAY [localhost] 2026-02-25 00:07:12.988142 | 2026-02-25 00:07:12.988258 | TASK [Gathering Facts] 2026-02-25 00:07:14.065352 | localhost | ok 2026-02-25 00:07:14.081859 | 2026-02-25 00:07:14.082245 | TASK [Setup log path fact] 2026-02-25 00:07:14.100599 | localhost | ok 2026-02-25 00:07:14.114840 | 2026-02-25 00:07:14.114963 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-25 00:07:14.143748 | localhost | ok 2026-02-25 00:07:14.153721 | 2026-02-25 00:07:14.153873 | TASK [emit-job-header : Print job information] 2026-02-25 00:07:14.181867 | # Job Information 2026-02-25 00:07:14.182024 | Ansible Version: 2.15.12 2026-02-25 00:07:14.182054 | Job: ansible-test-sanity-docker-milestone 2026-02-25 00:07:14.182075 | Pipeline: periodic 2026-02-25 00:07:14.182094 | Executor: ze02.softwarefactory-project.io 2026-02-25 00:07:14.182112 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-02-25 00:07:14.182133 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/740/ansible/7404f3ad71da4a968e571f188214e448/ 2026-02-25 00:07:14.182151 | Event ID: 79c881336d75451aa1b30c2394aae9ec 2026-02-25 00:07:14.186725 | 2026-02-25 00:07:14.186798 | LOOP [emit-job-header : Print node information] 2026-02-25 00:07:14.304233 | localhost | ok: 2026-02-25 00:07:14.304489 | localhost | # Node Information 2026-02-25 00:07:14.304542 | localhost | Inventory Hostname: controller 2026-02-25 00:07:14.304566 | localhost | Hostname: np0005628848 2026-02-25 00:07:14.304593 | localhost | Username: zuul 2026-02-25 00:07:14.304614 | localhost | Distro: Fedora 37 2026-02-25 00:07:14.304632 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-02-25 00:07:14.304650 | localhost | Region: ca-ymq-1 2026-02-25 00:07:14.304686 | localhost | Label: ansible-fedora-37-1vcpu 2026-02-25 00:07:14.304705 | localhost | Product Name: OpenStack Nova 2026-02-25 00:07:14.304722 | localhost | Interface IP: 162.253.55.52 2026-02-25 00:07:14.321781 | 2026-02-25 00:07:14.321849 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-25 00:07:14.734338 | localhost -> localhost | changed 2026-02-25 00:07:14.742256 | 2026-02-25 00:07:14.742351 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-25 00:07:15.660069 | localhost -> localhost | changed 2026-02-25 00:07:15.681943 | 2026-02-25 00:07:15.682054 | PLAY [all:!appliance*] 2026-02-25 00:07:15.702655 | 2026-02-25 00:07:15.702835 | TASK [include_role : start-zuul-console] 2026-02-25 00:07:15.723480 | controller | ok 2026-02-25 00:07:15.740735 | 2026-02-25 00:07:15.740863 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-02-25 00:07:16.096233 | controller | ok 2026-02-25 00:07:16.121538 | 2026-02-25 00:07:16.121641 | TASK [use-our-mirror : Retrieve the IP address] 2026-02-25 00:07:16.959094 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-02-25 00:07:16.968729 | 2026-02-25 00:07:16.968823 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-02-25 00:07:17.508950 | controller | skipping: Conditional result was False 2026-02-25 00:07:17.526533 | 2026-02-25 00:07:17.526771 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-02-25 00:07:17.555658 | controller | skipping: Conditional result was False 2026-02-25 00:07:17.574596 | 2026-02-25 00:07:17.574829 | TASK [use-our-mirror : Create the podman configuration directory] 2026-02-25 00:07:17.613101 | controller | skipping: Conditional result was False 2026-02-25 00:07:17.627284 | 2026-02-25 00:07:17.627434 | TASK [use-our-mirror : Copy the podman configuration] 2026-02-25 00:07:17.656009 | controller | skipping: Conditional result was False 2026-02-25 00:07:17.669893 | 2026-02-25 00:07:17.669997 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-02-25 00:07:17.694954 | controller | skipping: Conditional result was False 2026-02-25 00:07:17.703656 | 2026-02-25 00:07:17.703776 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-02-25 00:07:17.728471 | controller | skipping: Conditional result was False 2026-02-25 00:07:17.746556 | 2026-02-25 00:07:17.746684 | TASK [Disable Fedora Modular] 2026-02-25 00:07:17.982009 | controller | changed 2026-02-25 00:07:17.988507 | 2026-02-25 00:07:17.988573 | TASK [Enable EPEL] 2026-02-25 00:07:18.013329 | controller | skipping: Conditional result was False 2026-02-25 00:07:18.020105 | 2026-02-25 00:07:18.020173 | TASK [Register the RHEL node] 2026-02-25 00:07:18.569834 | 2026-02-25 00:07:18.570123 | TASK [Show the subscription-manager status] 2026-02-25 00:07:19.157923 | controller | skipping: Conditional result was False 2026-02-25 00:07:19.172464 | 2026-02-25 00:07:19.172600 | TASK [Enable EPEL on RHEL] 2026-02-25 00:07:19.727256 | controller | skipping: Conditional result was False 2026-02-25 00:07:19.736473 | 2026-02-25 00:07:19.736571 | TASK [Install git and tox] 2026-02-25 00:08:55.728633 | controller | changed 2026-02-25 00:08:55.741512 | 2026-02-25 00:08:55.741656 | TASK [include_role : prepare-workspace] 2026-02-25 00:08:55.786136 | controller | ok 2026-02-25 00:08:55.825764 | 2026-02-25 00:08:55.825903 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-25 00:08:56.082513 | controller | ok 2026-02-25 00:08:56.091759 | 2026-02-25 00:08:56.091867 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-25 00:14:46.119784 | controller | Output suppressed because no_log was given 2026-02-25 00:14:46.195631 | 2026-02-25 00:14:46.195836 | TASK [include_role : prepare-workspace-openshift] 2026-02-25 00:14:46.222221 | controller | skipping: Conditional result was False 2026-02-25 00:14:46.256696 | 2026-02-25 00:14:46.256806 | PLAY [all:!appliance] 2026-02-25 00:14:46.281154 | 2026-02-25 00:14:46.281248 | TASK [Run add-build-sshkey role (RSA)] 2026-02-25 00:14:46.323372 | controller | ok 2026-02-25 00:14:46.339316 | 2026-02-25 00:14:46.339394 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-25 00:14:46.620119 | controller -> localhost | ok 2026-02-25 00:14:46.626936 | 2026-02-25 00:14:46.627001 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-25 00:14:46.659811 | controller | ok 2026-02-25 00:14:46.674384 | controller | included: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-25 00:14:46.680628 | 2026-02-25 00:14:46.680735 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-25 00:14:47.243641 | controller -> localhost | Generating public/private rsa key pair. 2026-02-25 00:14:47.244104 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/7404f3ad71da4a968e571f188214e448_id_rsa. 2026-02-25 00:14:47.244170 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/7404f3ad71da4a968e571f188214e448_id_rsa.pub. 2026-02-25 00:14:47.244224 | controller -> localhost | The key fingerprint is: 2026-02-25 00:14:47.244267 | controller -> localhost | SHA256:tfBsyafkytYLO670HGYCM437PZO/pYQwqKltSQQ1pag zuul-build-sshkey 2026-02-25 00:14:47.244311 | controller -> localhost | The key's randomart image is: 2026-02-25 00:14:47.244363 | controller -> localhost | +---[RSA 2048]----+ 2026-02-25 00:14:47.244422 | controller -> localhost | | .o.. | 2026-02-25 00:14:47.244479 | controller -> localhost | |.. o | 2026-02-25 00:14:47.244527 | controller -> localhost | |... . . | 2026-02-25 00:14:47.244569 | controller -> localhost | |. . + * o | 2026-02-25 00:14:47.244608 | controller -> localhost | |E. * + S O . | 2026-02-25 00:14:47.244702 | controller -> localhost | | .o = o = o | 2026-02-25 00:14:47.244772 | controller -> localhost | | .o.. o *o+ . | 2026-02-25 00:14:47.244816 | controller -> localhost | | oo o O**.o | 2026-02-25 00:14:47.244856 | controller -> localhost | |... o+O==o | 2026-02-25 00:14:47.244903 | controller -> localhost | +----[SHA256]-----+ 2026-02-25 00:14:47.245012 | controller -> localhost | ok: Runtime: 0:00:00.132583 2026-02-25 00:14:47.264552 | 2026-02-25 00:14:47.264659 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-25 00:14:47.298089 | controller | ok 2026-02-25 00:14:47.314818 | controller | included: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-25 00:14:47.327159 | 2026-02-25 00:14:47.327247 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-25 00:14:47.353430 | controller | skipping: Conditional result was False 2026-02-25 00:14:47.362713 | 2026-02-25 00:14:47.362807 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-25 00:14:48.071332 | controller | changed 2026-02-25 00:14:48.084377 | 2026-02-25 00:14:48.084504 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-25 00:14:48.340273 | controller | ok 2026-02-25 00:14:48.354055 | 2026-02-25 00:14:48.354201 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-25 00:14:48.981601 | controller | changed 2026-02-25 00:14:48.994893 | 2026-02-25 00:14:48.995010 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-25 00:14:49.620896 | controller | changed 2026-02-25 00:14:49.627138 | 2026-02-25 00:14:49.627208 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-25 00:14:49.653164 | controller | skipping: Conditional result was False 2026-02-25 00:14:49.660597 | 2026-02-25 00:14:49.660679 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-25 00:14:50.082266 | controller -> localhost | changed 2026-02-25 00:14:50.111886 | 2026-02-25 00:14:50.112058 | TASK [add-build-sshkey : Add back temp key] 2026-02-25 00:14:50.425970 | controller -> localhost | Identity added: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/7404f3ad71da4a968e571f188214e448_id_rsa (zuul-build-sshkey) 2026-02-25 00:14:50.426556 | controller -> localhost | ok: Runtime: 0:00:00.017190 2026-02-25 00:14:50.444923 | 2026-02-25 00:14:50.445127 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-25 00:14:50.827353 | controller | ok 2026-02-25 00:14:50.840951 | 2026-02-25 00:14:50.841105 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-25 00:14:50.871491 | controller | skipping: Conditional result was False 2026-02-25 00:14:50.890382 | 2026-02-25 00:14:50.890502 | TASK [Run add-build-sshkey role (ECDSA)] 2026-02-25 00:14:50.921906 | controller | ok 2026-02-25 00:14:50.938137 | 2026-02-25 00:14:50.938223 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-25 00:14:51.217627 | controller -> localhost | ok 2026-02-25 00:14:51.225096 | 2026-02-25 00:14:51.225284 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-25 00:14:51.258784 | controller | ok 2026-02-25 00:14:51.270530 | controller | included: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-25 00:14:51.276775 | 2026-02-25 00:14:51.276837 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-25 00:14:51.545057 | controller -> localhost | Generating public/private ecdsa key pair. 2026-02-25 00:14:51.545294 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/7404f3ad71da4a968e571f188214e448_id_ecdsa. 2026-02-25 00:14:51.545321 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/7404f3ad71da4a968e571f188214e448_id_ecdsa.pub. 2026-02-25 00:14:51.545355 | controller -> localhost | The key fingerprint is: 2026-02-25 00:14:51.545374 | controller -> localhost | SHA256:cixYHXxVzhPrnomN3xRv+JyZuPsEwsCbZ41XJuSZOmw zuul-build-sshkey 2026-02-25 00:14:51.545392 | controller -> localhost | The key's randomart image is: 2026-02-25 00:14:51.545419 | controller -> localhost | +---[ECDSA 521]---+ 2026-02-25 00:14:51.545437 | controller -> localhost | | .. ..oo | 2026-02-25 00:14:51.545454 | controller -> localhost | | .o.. oooo | 2026-02-25 00:14:51.545471 | controller -> localhost | | . .+ ==o | 2026-02-25 00:14:51.545488 | controller -> localhost | | o . * +.+. | 2026-02-25 00:14:51.545519 | controller -> localhost | | . o So E +.. | 2026-02-25 00:14:51.545539 | controller -> localhost | | + + +=.+o| 2026-02-25 00:14:51.545564 | controller -> localhost | | o *.+| 2026-02-25 00:14:51.545588 | controller -> localhost | | .o*+| 2026-02-25 00:14:51.545611 | controller -> localhost | | +==+| 2026-02-25 00:14:51.545632 | controller -> localhost | +----[SHA256]-----+ 2026-02-25 00:14:51.545716 | controller -> localhost | ok: Runtime: 0:00:00.010440 2026-02-25 00:14:51.553336 | 2026-02-25 00:14:51.553400 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-25 00:14:51.575488 | controller | ok 2026-02-25 00:14:51.584090 | controller | included: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-25 00:14:51.593176 | 2026-02-25 00:14:51.593262 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-25 00:14:51.617841 | controller | skipping: Conditional result was False 2026-02-25 00:14:51.625981 | 2026-02-25 00:14:51.626087 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-25 00:14:51.896838 | controller | changed 2026-02-25 00:14:51.910716 | 2026-02-25 00:14:51.910859 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-25 00:14:52.157165 | controller | ok 2026-02-25 00:14:52.172979 | 2026-02-25 00:14:52.173137 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-25 00:14:52.842382 | controller | changed 2026-02-25 00:14:52.859201 | 2026-02-25 00:14:52.859387 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-25 00:14:53.531003 | controller | changed 2026-02-25 00:14:53.575369 | 2026-02-25 00:14:53.575513 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-25 00:14:53.600293 | controller | skipping: Conditional result was False 2026-02-25 00:14:53.606830 | 2026-02-25 00:14:53.606918 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-25 00:14:53.854399 | controller -> localhost | changed 2026-02-25 00:14:53.866748 | 2026-02-25 00:14:53.866815 | TASK [add-build-sshkey : Add back temp key] 2026-02-25 00:14:54.190593 | controller -> localhost | Identity added: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/7404f3ad71da4a968e571f188214e448_id_ecdsa (zuul-build-sshkey) 2026-02-25 00:14:54.191320 | controller -> localhost | ok: Runtime: 0:00:00.016222 2026-02-25 00:14:54.226873 | 2026-02-25 00:14:54.227036 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-25 00:14:54.487319 | controller | ok 2026-02-25 00:14:54.495563 | 2026-02-25 00:14:54.495656 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-25 00:14:54.521970 | controller | skipping: Conditional result was False 2026-02-25 00:14:54.539192 | 2026-02-25 00:14:54.539304 | TASK [include_role : remove-zuul-sshkey] 2026-02-25 00:14:54.566376 | controller | skipping: Conditional result was False 2026-02-25 00:14:54.581639 | 2026-02-25 00:14:54.581869 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-25 00:14:54.823350 | controller | ok: "logs" 2026-02-25 00:14:54.828303 | controller | ok: All items complete 2026-02-25 00:14:54.828386 | 2026-02-25 00:14:55.051111 | controller | ok: "artifacts" 2026-02-25 00:14:55.247376 | controller | ok: "docs" 2026-02-25 00:14:55.262351 | 2026-02-25 00:14:55.262424 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-25 00:14:55.496403 | controller | changed: "logs" 2026-02-25 00:14:55.682715 | controller | changed: "artifacts" 2026-02-25 00:14:55.871981 | controller | changed: "docs" 2026-02-25 00:14:55.922294 | 2026-02-25 00:14:55.922421 | PLAY RECAP 2026-02-25 00:14:55.922487 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-02-25 00:14:55.922533 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-25 00:14:55.922567 | 2026-02-25 00:14:56.057345 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-02-25 00:14:56.058194 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-25 00:14:56.622349 | 2026-02-25 00:14:56.622470 | PLAY [all] 2026-02-25 00:14:56.646126 | 2026-02-25 00:14:56.646236 | TASK [Install binary dependencies] 2026-02-25 00:14:56.707290 | controller | ok 2026-02-25 00:14:56.731445 | 2026-02-25 00:14:56.731610 | TASK [bindep : Include find tasks] 2026-02-25 00:14:56.772572 | controller | ok 2026-02-25 00:14:56.789886 | controller | included: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-02-25 00:14:56.796890 | 2026-02-25 00:14:56.796993 | TASK [bindep : Look for bindep.txt] 2026-02-25 00:14:57.379212 | controller | ok 2026-02-25 00:14:57.398832 | 2026-02-25 00:14:57.399047 | TASK [bindep : Define bindep_file fact] 2026-02-25 00:14:57.426182 | controller | skipping: Conditional result was False 2026-02-25 00:14:57.436059 | 2026-02-25 00:14:57.436173 | TASK [bindep : Look for other-requirements.txt] 2026-02-25 00:14:57.652890 | controller | ok 2026-02-25 00:14:57.661424 | 2026-02-25 00:14:57.661588 | TASK [bindep : Define bindep_file fact] 2026-02-25 00:14:57.696696 | controller | skipping: Conditional result was False 2026-02-25 00:14:57.712109 | 2026-02-25 00:14:57.712290 | TASK [bindep : Look for bindep fallback file] 2026-02-25 00:14:57.749995 | controller | skipping: Conditional result was False 2026-02-25 00:14:57.768479 | 2026-02-25 00:14:57.768720 | TASK [bindep : Define bindep_file fact] 2026-02-25 00:14:57.797175 | controller | skipping: Conditional result was False 2026-02-25 00:14:57.810543 | 2026-02-25 00:14:57.810729 | TASK [bindep : Include bindep tasks] 2026-02-25 00:14:57.847730 | controller | skipping: Conditional result was False 2026-02-25 00:14:57.861130 | 2026-02-25 00:14:57.861257 | TASK [bindep : Include install tasks] 2026-02-25 00:14:57.888411 | controller | skipping: Conditional result was False 2026-02-25 00:14:57.901455 | 2026-02-25 00:14:57.901585 | LOOP [bindep : Include package tasks] 2026-02-25 00:14:57.976563 | 2026-02-25 00:14:57.976892 | TASK [Run test-setup role] 2026-02-25 00:14:58.004894 | controller | ok 2026-02-25 00:14:58.054352 | 2026-02-25 00:14:58.054458 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-02-25 00:14:58.255880 | controller | ok 2026-02-25 00:14:58.271473 | 2026-02-25 00:14:58.271639 | TASK [test-setup : Run tools/test-setup.sh] 2026-02-25 00:14:58.822133 | controller | skipping: Conditional result was False 2026-02-25 00:14:58.879444 | 2026-02-25 00:14:58.879605 | PLAY RECAP 2026-02-25 00:14:58.879702 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-25 00:14:58.879750 | 2026-02-25 00:14:59.000162 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-02-25 00:14:59.001373 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-25 00:14:59.590424 | 2026-02-25 00:14:59.590554 | PLAY [controller] 2026-02-25 00:14:59.610483 | 2026-02-25 00:14:59.610579 | TASK [Create the /root directory] 2026-02-25 00:15:00.209257 | controller | ok 2026-02-25 00:15:00.221619 | 2026-02-25 00:15:00.221839 | TASK [Install glibc-langpack-en] 2026-02-25 00:15:04.233219 | controller | ok: Nothing to do 2026-02-25 00:15:04.245413 | 2026-02-25 00:15:04.245548 | TASK [Ensure controller directory exists] 2026-02-25 00:15:04.475564 | controller | changed 2026-02-25 00:15:04.490352 | 2026-02-25 00:15:04.490609 | TASK [Install container runtime] 2026-02-25 00:15:04.571482 | controller | ok 2026-02-25 00:15:04.619527 | 2026-02-25 00:15:04.619702 | LOOP [ensure-podman : Find distribution installation] 2026-02-25 00:15:04.661812 | controller | ok: "/var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-02-25 00:15:04.669886 | controller | included: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-02-25 00:15:04.676986 | 2026-02-25 00:15:04.677062 | TASK [ensure-podman : Install podman (RedHat)] 2026-02-25 00:16:11.496672 | controller | changed 2026-02-25 00:16:11.515427 | 2026-02-25 00:16:11.515559 | TASK [ensure-podman : Fetch podman version] 2026-02-25 00:16:12.112560 | controller | Client: Podman Engine 2026-02-25 00:16:12.112743 | controller | Version: 4.6.2 2026-02-25 00:16:12.112846 | controller | API Version: 4.6.2 2026-02-25 00:16:12.112945 | controller | Go Version: go1.19.12 2026-02-25 00:16:12.113068 | controller | Built: Mon Aug 28 19:38:31 2023 2026-02-25 00:16:12.113166 | controller | OS/Arch: linux/amd64 2026-02-25 00:16:12.588289 | controller | ok: Runtime: 0:00:00.196860 2026-02-25 00:16:12.598997 | 2026-02-25 00:16:12.599123 | TASK [ensure-podman : Print podman version installed] 2026-02-25 00:16:12.633214 | Podman version: Client: Podman Engine 2026-02-25 00:16:12.633432 | Version: 4.6.2 2026-02-25 00:16:12.633471 | API Version: 4.6.2 2026-02-25 00:16:12.633499 | Go Version: go1.19.12 2026-02-25 00:16:12.633524 | Built: Mon Aug 28 19:38:31 2023 2026-02-25 00:16:12.633550 | OS/Arch: linux/amd64 2026-02-25 00:16:12.641485 | 2026-02-25 00:16:12.641571 | TASK [ensure-podman : Validate podman engine] 2026-02-25 00:16:13.434147 | controller | skipping: Conditional result was False 2026-02-25 00:16:13.442240 | 2026-02-25 00:16:13.442326 | TASK [ensure-podman : Set up docker compatability socket] 2026-02-25 00:16:13.457785 | controller | skipping: Conditional result was False 2026-02-25 00:16:13.475338 | 2026-02-25 00:16:13.475438 | TASK [Ensure python3.8 is present] 2026-02-25 00:16:13.501613 | controller | skipping: Conditional result was False 2026-02-25 00:16:13.508586 | 2026-02-25 00:16:13.508678 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-02-25 00:16:13.529563 | controller | ok 2026-02-25 00:16:13.549743 | 2026-02-25 00:16:13.549836 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-02-25 00:16:14.995391 | controller | ok: Nothing to do 2026-02-25 00:16:15.001223 | 2026-02-25 00:16:15.001292 | TASK [our-ensure-python : Also install python3-devel] 2026-02-25 00:16:25.159833 | controller | changed 2026-02-25 00:16:25.186798 | 2026-02-25 00:16:25.187008 | TASK [Run ensure-virtualenv role] 2026-02-25 00:16:25.213053 | controller | ok 2026-02-25 00:16:25.238898 | 2026-02-25 00:16:25.239022 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-02-25 00:16:25.449441 | controller | /usr/bin/virtualenv 2026-02-25 00:16:25.772870 | controller | ok: Runtime: 0:00:00.003531 2026-02-25 00:16:25.787074 | 2026-02-25 00:16:25.787237 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-02-25 00:16:25.813357 | controller | skipping: Conditional result was False 2026-02-25 00:16:25.813694 | controller | ok: All items complete 2026-02-25 00:16:25.813726 | 2026-02-25 00:16:25.842341 | 2026-02-25 00:16:25.842571 | TASK [Find the full path of the Python interpreter] 2026-02-25 00:16:26.087667 | controller | /usr/bin/python3 2026-02-25 00:16:26.394538 | controller | ok 2026-02-25 00:16:26.410047 | 2026-02-25 00:16:26.410197 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-02-25 00:16:27.480742 | controller | created virtual environment CPython3.11.0.final.0-64 in 606ms 2026-02-25 00:16:27.508751 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-02-25 00:16:27.508789 | 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-25 00:16:27.508798 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-02-25 00:16:27.508812 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-02-25 00:16:27.973145 | controller | changed 2026-02-25 00:16:27.980346 | 2026-02-25 00:16:27.980407 | TASK [Set selinux package] 2026-02-25 00:16:28.001587 | controller | ok 2026-02-25 00:16:28.006649 | 2026-02-25 00:16:28.006734 | TASK [Set selinux package (Fedora)] 2026-02-25 00:16:28.047271 | controller | ok 2026-02-25 00:16:28.052828 | 2026-02-25 00:16:28.052889 | TASK [Install selinux into virtualenv] 2026-02-25 00:16:53.525382 | controller | Collecting selinux-please-lie-to-me 2026-02-25 00:17:05.856749 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-02-25 00:17:06.197384 | controller | Collecting setuptools<50.0.0 2026-02-25 00:17:06.205186 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-02-25 00:17:06.259916 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 15.7 MB/s eta 0:00:00 2026-02-25 00:17:06.338264 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-02-25 00:17:06.338566 | controller | Attempting uninstall: setuptools 2026-02-25 00:17:06.340955 | controller | Found existing installation: setuptools 62.6.0 2026-02-25 00:17:06.401886 | controller | Uninstalling setuptools-62.6.0: 2026-02-25 00:17:06.410333 | controller | Successfully uninstalled setuptools-62.6.0 2026-02-25 00:17:06.783392 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-02-25 00:17:18.218344 | controller | 2026-02-25 00:17:18.310018 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-25 00:17:18.310058 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-25 00:17:18.612542 | controller | ok: Runtime: 0:00:50.049326 2026-02-25 00:17:18.625966 | 2026-02-25 00:17:18.626094 | TASK [Install pytest-forked into virtualenv] 2026-02-25 00:17:30.465029 | controller | Collecting pytest-forked 2026-02-25 00:17:54.655937 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-02-25 00:17:54.703539 | controller | Collecting py 2026-02-25 00:17:54.708911 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-02-25 00:17:54.730804 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.4 MB/s eta 0:00:00 2026-02-25 00:17:54.836910 | controller | Collecting pytest>=3.10 2026-02-25 00:17:54.842484 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-02-25 00:17:54.883648 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 9.4 MB/s eta 0:00:00 2026-02-25 00:17:54.914820 | controller | Collecting iniconfig>=1.0.1 2026-02-25 00:17:54.918183 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-02-25 00:17:54.954852 | controller | Collecting packaging>=22 2026-02-25 00:17:54.958341 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-02-25 00:17:54.964693 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 15.0 MB/s eta 0:00:00 2026-02-25 00:17:54.993768 | controller | Collecting pluggy<2,>=1.5 2026-02-25 00:17:54.997088 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-02-25 00:17:55.037103 | controller | Collecting pygments>=2.7.2 2026-02-25 00:17:55.041526 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-02-25 00:17:55.089580 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 26.9 MB/s eta 0:00:00 2026-02-25 00:17:55.156629 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-02-25 00:17:56.239704 | 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-25 00:17:56.248428 | controller | 2026-02-25 00:17:56.314563 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-02-25 00:17:56.314592 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-02-25 00:17:56.697294 | controller | ok: Runtime: 0:00:37.444559 2026-02-25 00:17:56.703978 | 2026-02-25 00:17:56.704039 | TASK [Update pip] 2026-02-25 00:17:57.234197 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-02-25 00:18:09.688966 | controller | Collecting pip 2026-02-25 00:18:21.876783 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-02-25 00:18:21.957668 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 24.0 MB/s eta 0:00:00 2026-02-25 00:18:22.026976 | controller | Installing collected packages: pip 2026-02-25 00:18:22.027136 | controller | Attempting uninstall: pip 2026-02-25 00:18:22.029451 | controller | Found existing installation: pip 22.2.2 2026-02-25 00:18:22.186836 | controller | Uninstalling pip-22.2.2: 2026-02-25 00:18:22.220590 | controller | Successfully uninstalled pip-22.2.2 2026-02-25 00:18:23.106484 | controller | Successfully installed pip-26.0.1 2026-02-25 00:18:23.289265 | controller | ok: Runtime: 0:00:26.260252 2026-02-25 00:18:23.297193 | 2026-02-25 00:18:23.297287 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-02-25 00:18:23.516046 | controller | changed 2026-02-25 00:18:23.523842 | 2026-02-25 00:18:23.523931 | TASK [Install ansible into virtualenv] 2026-02-25 00:18:24.050324 | controller | Processing ./src/github.com/ansible/ansible 2026-02-25 00:18:24.052915 | controller | Installing build dependencies: started 2026-02-25 00:18:46.966170 | controller | Installing build dependencies: finished with status 'done' 2026-02-25 00:18:46.966858 | controller | Getting requirements to build wheel: started 2026-02-25 00:18:47.769754 | controller | Getting requirements to build wheel: finished with status 'done' 2026-02-25 00:18:47.771298 | controller | Preparing metadata (pyproject.toml): started 2026-02-25 00:18:48.252942 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-02-25 00:18:48.257631 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-02-25 00:18:48.261502 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-02-25 00:18:48.576001 | controller | ERROR 2026-02-25 00:18:48.576270 | controller | { 2026-02-25 00:18:48.576337 | controller | "delta": "0:00:24.580441", 2026-02-25 00:18:48.576382 | controller | "end": "2026-02-25 00:18:48.338697", 2026-02-25 00:18:48.576421 | controller | "msg": "non-zero return code", 2026-02-25 00:18:48.576478 | controller | "rc": 1, 2026-02-25 00:18:48.576518 | controller | "start": "2026-02-25 00:18:23.758256" 2026-02-25 00:18:48.576555 | controller | } failure 2026-02-25 00:18:48.579572 | 2026-02-25 00:18:48.579717 | PLAY RECAP 2026-02-25 00:18:48.579832 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-02-25 00:18:48.579883 | 2026-02-25 00:18:48.719262 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-02-25 00:18:48.721402 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-25 00:18:49.378539 | 2026-02-25 00:18:49.378709 | PLAY [all] 2026-02-25 00:18:49.400577 | 2026-02-25 00:18:49.400676 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-02-25 00:18:49.878928 | controller | changed: non-zero return code 2026-02-25 00:18:49.891927 | 2026-02-25 00:18:49.892090 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-02-25 00:18:49.920077 | controller | skipping: Conditional result was False 2026-02-25 00:18:49.933494 | 2026-02-25 00:18:49.933640 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-02-25 00:18:49.976417 | 2026-02-25 00:18:49.976708 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-02-25 00:18:50.017207 | 2026-02-25 00:18:50.017499 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-02-25 00:18:50.044842 | controller | skipping: Conditional result was False 2026-02-25 00:18:50.060370 | 2026-02-25 00:18:50.060517 | LOOP [fetch-subunit-output : Generate subunit file] 2026-02-25 00:18:50.100566 | 2026-02-25 00:18:50.100878 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-02-25 00:18:50.128762 | controller | skipping: Conditional result was False 2026-02-25 00:18:50.141794 | 2026-02-25 00:18:50.141935 | TASK [fetch-subunit-output : Remove the temporary file] 2026-02-25 00:18:50.168866 | controller | skipping: Conditional result was False 2026-02-25 00:18:50.182083 | 2026-02-25 00:18:50.182220 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-02-25 00:18:50.209039 | controller | skipping: Conditional result was False 2026-02-25 00:18:50.258387 | 2026-02-25 00:18:50.258536 | PLAY RECAP 2026-02-25 00:18:50.258597 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-02-25 00:18:50.258625 | 2026-02-25 00:18:50.421121 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-02-25 00:18:50.422371 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-02-25 00:18:51.020363 | 2026-02-25 00:18:51.020484 | PLAY [all:!appliance*] 2026-02-25 00:18:51.043304 | 2026-02-25 00:18:51.043410 | TASK [unregister the node] 2026-02-25 00:18:51.575154 | controller | skipping: Conditional result was False 2026-02-25 00:18:51.584039 | 2026-02-25 00:18:51.584155 | TASK [include_role : fetch-output] 2026-02-25 00:18:51.627475 | controller | ok 2026-02-25 00:18:51.657083 | 2026-02-25 00:18:51.657209 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-25 00:18:51.734089 | controller | skipping: Conditional result was False 2026-02-25 00:18:51.747890 | 2026-02-25 00:18:51.748051 | TASK [fetch-output : Set log path for single node] 2026-02-25 00:18:51.797943 | controller | ok 2026-02-25 00:18:51.812634 | 2026-02-25 00:18:51.812835 | LOOP [fetch-output : Ensure local output dirs] 2026-02-25 00:18:52.261695 | controller -> localhost | ok: "/var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/logs" 2026-02-25 00:18:52.543832 | controller -> localhost | changed: "/var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/artifacts" 2026-02-25 00:18:52.775651 | controller -> localhost | changed: "/var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/work/docs" 2026-02-25 00:18:52.805865 | 2026-02-25 00:18:52.806092 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-25 00:18:53.504762 | controller | changed: 2026-02-25 00:18:53.504992 | controller | .d..t...... ./ 2026-02-25 00:18:53.505030 | controller | cd+++++++++ controller/ 2026-02-25 00:18:53.505170 | controller | changed: All items complete 2026-02-25 00:18:53.505206 | 2026-02-25 00:18:54.066630 | controller | changed: .d..t...... ./ 2026-02-25 00:18:54.570966 | controller | changed: .d..t...... ./ 2026-02-25 00:18:54.598140 | 2026-02-25 00:18:54.598250 | TASK [include_role : fetch-output-openshift] 2026-02-25 00:18:54.623579 | controller | skipping: Conditional result was False 2026-02-25 00:18:54.632011 | 2026-02-25 00:18:54.632103 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-25 00:18:54.675923 | controller | skipping: Conditional result was False 2026-02-25 00:18:54.688381 | controller | skipping: Conditional result was False 2026-02-25 00:18:54.734299 | 2026-02-25 00:18:54.734373 | PLAY [localhost] 2026-02-25 00:18:54.750806 | 2026-02-25 00:18:54.750887 | TASK [Run Zuul manifest role] 2026-02-25 00:18:54.772736 | localhost | ok 2026-02-25 00:18:54.792306 | 2026-02-25 00:18:54.792388 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-25 00:18:55.250995 | localhost | changed 2026-02-25 00:18:55.267356 | 2026-02-25 00:18:55.267539 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-25 00:18:55.306362 | localhost | ok 2026-02-25 00:18:55.327434 | 2026-02-25 00:18:55.327626 | TASK [Set zuul-log-path fact] 2026-02-25 00:18:55.361012 | localhost | ok 2026-02-25 00:18:55.383625 | 2026-02-25 00:18:55.383767 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-25 00:18:55.424109 | localhost | ok 2026-02-25 00:18:55.432526 | 2026-02-25 00:18:55.432597 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-02-25 00:18:55.481001 | localhost | ok: 2026-02-25 00:18:55.481435 | localhost | { 2026-02-25 00:18:55.481490 | localhost | "auth": { 2026-02-25 00:18:55.481537 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-02-25 00:18:55.481574 | localhost | "username": "9LF91O0RK7JU" 2026-02-25 00:18:55.481610 | localhost | }, 2026-02-25 00:18:55.481644 | localhost | "profile": "rackspace", 2026-02-25 00:18:55.481709 | localhost | "region_name": "IAD" 2026-02-25 00:18:55.481752 | localhost | } 2026-02-25 00:18:55.481813 | 2026-02-25 00:18:55.495738 | 2026-02-25 00:18:55.495890 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-02-25 00:18:55.518446 | localhost | Output suppressed because no_log was given 2026-02-25 00:18:55.538706 | 2026-02-25 00:18:55.538844 | TASK [upload-logs-failover : Initialize control vars] 2026-02-25 00:18:55.572982 | localhost | ok 2026-02-25 00:18:55.579555 | 2026-02-25 00:18:55.579648 | LOOP [upload-logs-failover : Perform log upload] 2026-02-25 00:18:55.684766 | localhost | Output suppressed because no_log was given 2026-02-25 00:18:55.696622 | localhost | included: /var/lib/zuul/builds/7404f3ad71da4a968e571f188214e448/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-02-25 00:18:55.711115 | 2026-02-25 00:18:55.711228 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-02-25 00:18:55.828806 | localhost | Output suppressed because no_log was given 2026-02-25 00:18:55.836550 | 2026-02-25 00:18:55.836635 | TASK [Upload logs to swift] 2026-02-25 00:18:55.877808 | localhost | ok 2026-02-25 00:18:55.906111 | 2026-02-25 00:18:55.906211 | TASK [Set zuul-log-path fact] 2026-02-25 00:18:55.943817 | localhost | skipping: Conditional result was False 2026-02-25 00:18:55.950265 | 2026-02-25 00:18:55.950356 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-02-25 00:18:56.325907 | localhost -> localhost | ok: Runtime: 0:00:00.011094 2026-02-25 00:18:56.340242 | 2026-02-25 00:18:56.340408 | TASK [upload-logs-swift : Upload logs to swift]