2026-01-08 00:23:44.116869 | Job console starting... 2026-01-08 00:23:44.126047 | Updating repositories 2026-01-08 00:23:44.237127 | Preparing job workspace 2026-01-08 00:23:49.103427 | Running Ansible setup... 2026-01-08 00:23:53.922984 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-08 00:23:54.542085 | 2026-01-08 00:23:54.542218 | PLAY [localhost] 2026-01-08 00:23:54.552096 | 2026-01-08 00:23:54.552206 | TASK [Gathering Facts] 2026-01-08 00:23:55.546170 | localhost | ok 2026-01-08 00:23:55.575029 | 2026-01-08 00:23:55.575246 | TASK [Setup log path fact] 2026-01-08 00:23:55.596035 | localhost | ok 2026-01-08 00:23:55.614910 | 2026-01-08 00:23:55.615068 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-08 00:23:55.647152 | localhost | ok 2026-01-08 00:23:55.659225 | 2026-01-08 00:23:55.659365 | TASK [emit-job-header : Print job information] 2026-01-08 00:23:55.700039 | # Job Information 2026-01-08 00:23:55.700333 | Ansible Version: 2.15.12 2026-01-08 00:23:55.700382 | Job: ansible-test-sanity-docker-devel 2026-01-08 00:23:55.700414 | Pipeline: periodic 2026-01-08 00:23:55.700442 | Executor: ze03.softwarefactory-project.io 2026-01-08 00:23:55.700470 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-01-08 00:23:55.700501 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/a10/ansible/a10247af512c4daab42128ee07954e1a/ 2026-01-08 00:23:55.700636 | Event ID: d4752e8c0ffe4b90a8171373176f7c90 2026-01-08 00:23:55.705549 | 2026-01-08 00:23:55.705627 | LOOP [emit-job-header : Print node information] 2026-01-08 00:23:55.802046 | localhost | ok: 2026-01-08 00:23:55.802229 | localhost | # Node Information 2026-01-08 00:23:55.802262 | localhost | Inventory Hostname: controller 2026-01-08 00:23:55.802288 | localhost | Hostname: np0005577452 2026-01-08 00:23:55.802312 | localhost | Username: zuul 2026-01-08 00:23:55.802337 | localhost | Distro: Fedora 37 2026-01-08 00:23:55.802362 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-01-08 00:23:55.802386 | localhost | Region: ca-ymq-1 2026-01-08 00:23:55.802409 | localhost | Label: ansible-fedora-37-1vcpu 2026-01-08 00:23:55.802432 | localhost | Product Name: OpenStack Nova 2026-01-08 00:23:55.802454 | localhost | Interface IP: 162.253.55.52 2026-01-08 00:23:55.829839 | 2026-01-08 00:23:55.829990 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-08 00:23:56.221388 | localhost -> localhost | changed 2026-01-08 00:23:56.226907 | 2026-01-08 00:23:56.226984 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-08 00:23:57.169151 | localhost -> localhost | changed 2026-01-08 00:23:57.189821 | 2026-01-08 00:23:57.189919 | PLAY [all:!appliance*] 2026-01-08 00:23:57.207624 | 2026-01-08 00:23:57.207774 | TASK [include_role : start-zuul-console] 2026-01-08 00:23:57.227408 | controller | ok 2026-01-08 00:23:57.241581 | 2026-01-08 00:23:57.241688 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-01-08 00:23:57.646544 | controller | ok 2026-01-08 00:23:57.668263 | 2026-01-08 00:23:57.668394 | TASK [use-our-mirror : Retrieve the IP address] 2026-01-08 00:23:58.607323 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-01-08 00:23:58.618612 | 2026-01-08 00:23:58.618791 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-01-08 00:23:59.163496 | controller | skipping: Conditional result was False 2026-01-08 00:23:59.172048 | 2026-01-08 00:23:59.172147 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-01-08 00:23:59.186869 | controller | skipping: Conditional result was False 2026-01-08 00:23:59.204903 | 2026-01-08 00:23:59.205121 | TASK [use-our-mirror : Create the podman configuration directory] 2026-01-08 00:23:59.253522 | controller | skipping: Conditional result was False 2026-01-08 00:23:59.268492 | 2026-01-08 00:23:59.268642 | TASK [use-our-mirror : Copy the podman configuration] 2026-01-08 00:23:59.295525 | controller | skipping: Conditional result was False 2026-01-08 00:23:59.309446 | 2026-01-08 00:23:59.309577 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-01-08 00:23:59.335969 | controller | skipping: Conditional result was False 2026-01-08 00:23:59.346503 | 2026-01-08 00:23:59.346645 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-01-08 00:23:59.371981 | controller | skipping: Conditional result was False 2026-01-08 00:23:59.384077 | 2026-01-08 00:23:59.384186 | TASK [Disable Fedora Modular] 2026-01-08 00:23:59.619644 | controller | changed 2026-01-08 00:23:59.626786 | 2026-01-08 00:23:59.626878 | TASK [Enable EPEL] 2026-01-08 00:23:59.651920 | controller | skipping: Conditional result was False 2026-01-08 00:23:59.660221 | 2026-01-08 00:23:59.660308 | TASK [Register the RHEL node] 2026-01-08 00:24:00.212165 | 2026-01-08 00:24:00.212419 | TASK [Show the subscription-manager status] 2026-01-08 00:24:00.784364 | controller | skipping: Conditional result was False 2026-01-08 00:24:00.791523 | 2026-01-08 00:24:00.791623 | TASK [Enable EPEL on RHEL] 2026-01-08 00:24:01.325502 | controller | skipping: Conditional result was False 2026-01-08 00:24:01.339426 | 2026-01-08 00:24:01.339603 | TASK [Install git and tox] 2026-01-08 00:25:53.782364 | controller | changed 2026-01-08 00:25:53.799811 | 2026-01-08 00:25:53.800000 | TASK [include_role : prepare-workspace] 2026-01-08 00:25:53.841212 | controller | ok 2026-01-08 00:25:53.880835 | 2026-01-08 00:25:53.880981 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-08 00:25:54.155288 | controller | ok 2026-01-08 00:25:54.171427 | 2026-01-08 00:25:54.171585 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-08 00:26:06.383980 | controller | Output suppressed because no_log was given 2026-01-08 00:26:06.399638 | 2026-01-08 00:26:06.399783 | TASK [include_role : prepare-workspace-openshift] 2026-01-08 00:26:06.416588 | controller | skipping: Conditional result was False 2026-01-08 00:26:06.482313 | 2026-01-08 00:26:06.482417 | PLAY [all:!appliance] 2026-01-08 00:26:06.499264 | 2026-01-08 00:26:06.499353 | TASK [Run add-build-sshkey role (RSA)] 2026-01-08 00:26:06.529609 | controller | ok 2026-01-08 00:26:06.547764 | 2026-01-08 00:26:06.547999 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-08 00:26:06.785486 | controller -> localhost | ok 2026-01-08 00:26:06.792755 | 2026-01-08 00:26:06.792845 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-08 00:26:06.822711 | controller | ok 2026-01-08 00:26:06.837100 | controller | included: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-08 00:26:06.844409 | 2026-01-08 00:26:06.844489 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-08 00:26:07.378185 | controller -> localhost | Generating public/private rsa key pair. 2026-01-08 00:26:07.378536 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/a10247af512c4daab42128ee07954e1a_id_rsa. 2026-01-08 00:26:07.378601 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/a10247af512c4daab42128ee07954e1a_id_rsa.pub. 2026-01-08 00:26:07.378649 | controller -> localhost | The key fingerprint is: 2026-01-08 00:26:07.378694 | controller -> localhost | SHA256:YyQG57U7lBmSZ3IOO/TcPI38LaEzi8kKqWGW2VYTUf8 zuul-build-sshkey 2026-01-08 00:26:07.378775 | controller -> localhost | The key's randomart image is: 2026-01-08 00:26:07.378821 | controller -> localhost | +---[RSA 2048]----+ 2026-01-08 00:26:07.378862 | controller -> localhost | | . +o+ | 2026-01-08 00:26:07.378904 | controller -> localhost | | +=++* | 2026-01-08 00:26:07.378945 | controller -> localhost | | .=@*+.o | 2026-01-08 00:26:07.378985 | controller -> localhost | | .o=+.*.o | 2026-01-08 00:26:07.379025 | controller -> localhost | | o.S +Eo | 2026-01-08 00:26:07.379079 | controller -> localhost | | + o o o+ o . | 2026-01-08 00:26:07.379126 | controller -> localhost | | * = . o + . | 2026-01-08 00:26:07.379168 | controller -> localhost | | o + . + . | 2026-01-08 00:26:07.379209 | controller -> localhost | | . .. | 2026-01-08 00:26:07.379255 | controller -> localhost | +----[SHA256]-----+ 2026-01-08 00:26:07.379340 | controller -> localhost | ok: Runtime: 0:00:00.087024 2026-01-08 00:26:07.395596 | 2026-01-08 00:26:07.395804 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-08 00:26:07.443959 | controller | ok 2026-01-08 00:26:07.465463 | controller | included: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-08 00:26:07.478451 | 2026-01-08 00:26:07.478541 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-08 00:26:07.504236 | controller | skipping: Conditional result was False 2026-01-08 00:26:07.522255 | 2026-01-08 00:26:07.522376 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-08 00:26:07.967550 | controller | changed 2026-01-08 00:26:07.976978 | 2026-01-08 00:26:07.977082 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-08 00:26:08.215607 | controller | ok 2026-01-08 00:26:08.225536 | 2026-01-08 00:26:08.225692 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-08 00:26:08.912197 | controller | changed 2026-01-08 00:26:08.928196 | 2026-01-08 00:26:08.928384 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-08 00:26:09.604933 | controller | changed 2026-01-08 00:26:09.622993 | 2026-01-08 00:26:09.623202 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-08 00:26:09.652170 | controller | skipping: Conditional result was False 2026-01-08 00:26:09.663609 | 2026-01-08 00:26:09.663783 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-08 00:26:10.137001 | controller -> localhost | changed 2026-01-08 00:26:10.148593 | 2026-01-08 00:26:10.148714 | TASK [add-build-sshkey : Add back temp key] 2026-01-08 00:26:10.447579 | controller -> localhost | Identity added: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/a10247af512c4daab42128ee07954e1a_id_rsa (zuul-build-sshkey) 2026-01-08 00:26:10.447800 | controller -> localhost | ok: Runtime: 0:00:00.013244 2026-01-08 00:26:10.454218 | 2026-01-08 00:26:10.454293 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-08 00:26:10.823465 | controller | ok 2026-01-08 00:26:10.839086 | 2026-01-08 00:26:10.839295 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-08 00:26:10.876655 | controller | skipping: Conditional result was False 2026-01-08 00:26:10.903129 | 2026-01-08 00:26:10.903283 | TASK [Run add-build-sshkey role (ECDSA)] 2026-01-08 00:26:10.945125 | controller | ok 2026-01-08 00:26:10.975879 | 2026-01-08 00:26:10.975986 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-08 00:26:11.321555 | controller -> localhost | ok 2026-01-08 00:26:11.328837 | 2026-01-08 00:26:11.328963 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-08 00:26:11.360847 | controller | ok 2026-01-08 00:26:11.372712 | controller | included: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-08 00:26:11.379821 | 2026-01-08 00:26:11.379946 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-08 00:26:11.731950 | controller -> localhost | Generating public/private ecdsa key pair. 2026-01-08 00:26:11.732344 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/a10247af512c4daab42128ee07954e1a_id_ecdsa. 2026-01-08 00:26:11.732434 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/a10247af512c4daab42128ee07954e1a_id_ecdsa.pub. 2026-01-08 00:26:11.732520 | controller -> localhost | The key fingerprint is: 2026-01-08 00:26:11.732571 | controller -> localhost | SHA256:2kxOCuOu0DElBQvqdpggrH2ji8CVAhc8CUCzYYdTIIk zuul-build-sshkey 2026-01-08 00:26:11.732618 | controller -> localhost | The key's randomart image is: 2026-01-08 00:26:11.732707 | controller -> localhost | +---[ECDSA 521]---+ 2026-01-08 00:26:11.732795 | controller -> localhost | |OX*=. | 2026-01-08 00:26:11.732840 | controller -> localhost | |E+O+ | 2026-01-08 00:26:11.732878 | controller -> localhost | |=o=.. | 2026-01-08 00:26:11.732915 | controller -> localhost | |*ooo. | 2026-01-08 00:26:11.732951 | controller -> localhost | |.*++= S | 2026-01-08 00:26:11.732990 | controller -> localhost | |o.+* + O | 2026-01-08 00:26:11.733027 | controller -> localhost | |o.o . o + | 2026-01-08 00:26:11.733063 | controller -> localhost | |.o o | 2026-01-08 00:26:11.733098 | controller -> localhost | |. o.. | 2026-01-08 00:26:11.733133 | controller -> localhost | +----[SHA256]-----+ 2026-01-08 00:26:11.733224 | controller -> localhost | ok: Runtime: 0:00:00.015846 2026-01-08 00:26:11.751642 | 2026-01-08 00:26:11.751875 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-08 00:26:11.793905 | controller | ok 2026-01-08 00:26:11.812178 | controller | included: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-08 00:26:11.827797 | 2026-01-08 00:26:11.827945 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-08 00:26:11.853656 | controller | skipping: Conditional result was False 2026-01-08 00:26:11.868146 | 2026-01-08 00:26:11.868300 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-08 00:26:12.183662 | controller | changed 2026-01-08 00:26:12.196989 | 2026-01-08 00:26:12.197132 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-08 00:26:12.438517 | controller | ok 2026-01-08 00:26:12.451674 | 2026-01-08 00:26:12.451876 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-08 00:26:13.127956 | controller | changed 2026-01-08 00:26:13.135532 | 2026-01-08 00:26:13.135652 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-08 00:26:13.749080 | controller | changed 2026-01-08 00:26:13.755820 | 2026-01-08 00:26:13.755946 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-08 00:26:13.781826 | controller | skipping: Conditional result was False 2026-01-08 00:26:13.791543 | 2026-01-08 00:26:13.791668 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-08 00:26:14.030909 | controller -> localhost | changed 2026-01-08 00:26:14.043448 | 2026-01-08 00:26:14.043558 | TASK [add-build-sshkey : Add back temp key] 2026-01-08 00:26:14.405445 | controller -> localhost | Identity added: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/a10247af512c4daab42128ee07954e1a_id_ecdsa (zuul-build-sshkey) 2026-01-08 00:26:14.405681 | controller -> localhost | ok: Runtime: 0:00:00.009211 2026-01-08 00:26:14.454344 | 2026-01-08 00:26:14.454481 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-08 00:26:14.687860 | controller | ok 2026-01-08 00:26:14.701897 | 2026-01-08 00:26:14.702086 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-08 00:26:14.730456 | controller | skipping: Conditional result was False 2026-01-08 00:26:14.746569 | 2026-01-08 00:26:14.746685 | TASK [include_role : remove-zuul-sshkey] 2026-01-08 00:26:14.763345 | controller | skipping: Conditional result was False 2026-01-08 00:26:14.776569 | 2026-01-08 00:26:14.776783 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-08 00:26:15.023347 | controller | ok: "logs" 2026-01-08 00:26:15.024868 | controller | ok: All items complete 2026-01-08 00:26:15.024973 | 2026-01-08 00:26:15.235126 | controller | ok: "artifacts" 2026-01-08 00:26:15.429578 | controller | ok: "docs" 2026-01-08 00:26:15.449614 | 2026-01-08 00:26:15.449800 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-08 00:26:15.689479 | controller | changed: "logs" 2026-01-08 00:26:15.907926 | controller | changed: "artifacts" 2026-01-08 00:26:16.119324 | controller | changed: "docs" 2026-01-08 00:26:16.178486 | 2026-01-08 00:26:16.178622 | PLAY RECAP 2026-01-08 00:26:16.178685 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-01-08 00:26:16.178721 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-08 00:26:16.178780 | 2026-01-08 00:26:16.305983 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-01-08 00:26:16.306827 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-08 00:26:16.882329 | 2026-01-08 00:26:16.882451 | PLAY [all] 2026-01-08 00:26:16.910965 | 2026-01-08 00:26:16.911109 | TASK [Install binary dependencies] 2026-01-08 00:26:16.954049 | controller | ok 2026-01-08 00:26:16.974767 | 2026-01-08 00:26:16.974891 | TASK [bindep : Include find tasks] 2026-01-08 00:26:17.004561 | controller | ok 2026-01-08 00:26:17.013105 | controller | included: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-01-08 00:26:17.022294 | 2026-01-08 00:26:17.022380 | TASK [bindep : Look for bindep.txt] 2026-01-08 00:26:17.381946 | controller | ok 2026-01-08 00:26:17.387917 | 2026-01-08 00:26:17.387995 | TASK [bindep : Define bindep_file fact] 2026-01-08 00:26:17.412541 | controller | skipping: Conditional result was False 2026-01-08 00:26:17.419424 | 2026-01-08 00:26:17.419526 | TASK [bindep : Look for other-requirements.txt] 2026-01-08 00:26:17.640474 | controller | ok 2026-01-08 00:26:17.653675 | 2026-01-08 00:26:17.653942 | TASK [bindep : Define bindep_file fact] 2026-01-08 00:26:17.679984 | controller | skipping: Conditional result was False 2026-01-08 00:26:17.689114 | 2026-01-08 00:26:17.689239 | TASK [bindep : Look for bindep fallback file] 2026-01-08 00:26:17.714255 | controller | skipping: Conditional result was False 2026-01-08 00:26:17.732102 | 2026-01-08 00:26:17.732305 | TASK [bindep : Define bindep_file fact] 2026-01-08 00:26:17.758718 | controller | skipping: Conditional result was False 2026-01-08 00:26:17.772652 | 2026-01-08 00:26:17.772868 | TASK [bindep : Include bindep tasks] 2026-01-08 00:26:17.799655 | controller | skipping: Conditional result was False 2026-01-08 00:26:17.813876 | 2026-01-08 00:26:17.814043 | TASK [bindep : Include install tasks] 2026-01-08 00:26:17.841125 | controller | skipping: Conditional result was False 2026-01-08 00:26:17.851795 | 2026-01-08 00:26:17.852050 | LOOP [bindep : Include package tasks] 2026-01-08 00:26:17.945314 | 2026-01-08 00:26:17.945515 | TASK [Run test-setup role] 2026-01-08 00:26:17.983705 | controller | ok 2026-01-08 00:26:18.010312 | 2026-01-08 00:26:18.010465 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-01-08 00:26:18.219895 | controller | ok 2026-01-08 00:26:18.226899 | 2026-01-08 00:26:18.227026 | TASK [test-setup : Run tools/test-setup.sh] 2026-01-08 00:26:18.764657 | controller | skipping: Conditional result was False 2026-01-08 00:26:18.792082 | 2026-01-08 00:26:18.792181 | PLAY RECAP 2026-01-08 00:26:18.792224 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-08 00:26:18.792244 | 2026-01-08 00:26:18.906788 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-01-08 00:26:18.907623 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-08 00:26:19.493032 | 2026-01-08 00:26:19.493203 | PLAY [controller] 2026-01-08 00:26:19.516047 | 2026-01-08 00:26:19.516199 | TASK [Create the /root directory] 2026-01-08 00:26:19.910924 | controller | ok 2026-01-08 00:26:19.919641 | 2026-01-08 00:26:19.919839 | TASK [Install glibc-langpack-en] 2026-01-08 00:26:23.886056 | controller | ok: Nothing to do 2026-01-08 00:26:23.893804 | 2026-01-08 00:26:23.893933 | TASK [Ensure controller directory exists] 2026-01-08 00:26:24.099854 | controller | changed 2026-01-08 00:26:24.110411 | 2026-01-08 00:26:24.110528 | TASK [Install container runtime] 2026-01-08 00:26:24.163021 | controller | ok 2026-01-08 00:26:24.210911 | 2026-01-08 00:26:24.211030 | LOOP [ensure-podman : Find distribution installation] 2026-01-08 00:26:24.238822 | controller | ok: "/var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-01-08 00:26:24.255879 | controller | included: /var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-01-08 00:26:24.263525 | 2026-01-08 00:26:24.263640 | TASK [ensure-podman : Install podman (RedHat)] 2026-01-08 00:27:28.281350 | controller | changed 2026-01-08 00:27:28.295263 | 2026-01-08 00:27:28.295394 | TASK [ensure-podman : Fetch podman version] 2026-01-08 00:27:28.822812 | controller | Client: Podman Engine 2026-01-08 00:27:28.822904 | controller | Version: 4.6.2 2026-01-08 00:27:28.822950 | controller | API Version: 4.6.2 2026-01-08 00:27:28.822993 | controller | Go Version: go1.19.12 2026-01-08 00:27:28.823045 | controller | Built: Mon Aug 28 19:38:31 2023 2026-01-08 00:27:28.823088 | controller | OS/Arch: linux/amd64 2026-01-08 00:27:29.345848 | controller | ok: Runtime: 0:00:00.188627 2026-01-08 00:27:29.359387 | 2026-01-08 00:27:29.359527 | TASK [ensure-podman : Print podman version installed] 2026-01-08 00:27:29.410993 | Podman version: Client: Podman Engine 2026-01-08 00:27:29.411225 | Version: 4.6.2 2026-01-08 00:27:29.411284 | API Version: 4.6.2 2026-01-08 00:27:29.411326 | Go Version: go1.19.12 2026-01-08 00:27:29.411364 | Built: Mon Aug 28 19:38:31 2023 2026-01-08 00:27:29.411402 | OS/Arch: linux/amd64 2026-01-08 00:27:29.424454 | 2026-01-08 00:27:29.424581 | TASK [ensure-podman : Validate podman engine] 2026-01-08 00:27:29.976164 | controller | skipping: Conditional result was False 2026-01-08 00:27:29.986933 | 2026-01-08 00:27:29.987078 | TASK [ensure-podman : Set up docker compatability socket] 2026-01-08 00:27:30.015626 | controller | skipping: Conditional result was False 2026-01-08 00:27:30.032294 | 2026-01-08 00:27:30.032392 | TASK [Ensure python3.8 is present] 2026-01-08 00:27:30.060177 | controller | skipping: Conditional result was False 2026-01-08 00:27:30.068845 | 2026-01-08 00:27:30.069093 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-01-08 00:27:30.095028 | controller | ok 2026-01-08 00:27:30.121427 | 2026-01-08 00:27:30.121589 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-01-08 00:27:31.532890 | controller | ok: Nothing to do 2026-01-08 00:27:31.546690 | 2026-01-08 00:27:31.546880 | TASK [our-ensure-python : Also install python3-devel] 2026-01-08 00:27:40.736677 | controller | changed 2026-01-08 00:27:40.762838 | 2026-01-08 00:27:40.763002 | TASK [Run ensure-virtualenv role] 2026-01-08 00:27:40.791026 | controller | ok 2026-01-08 00:27:40.825770 | 2026-01-08 00:27:40.825903 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-01-08 00:27:41.062595 | controller | /usr/bin/virtualenv 2026-01-08 00:27:41.362678 | controller | ok: Runtime: 0:00:00.004846 2026-01-08 00:27:41.370175 | 2026-01-08 00:27:41.370240 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-01-08 00:27:41.396865 | controller | skipping: Conditional result was False 2026-01-08 00:27:41.397275 | controller | ok: All items complete 2026-01-08 00:27:41.397313 | 2026-01-08 00:27:41.426421 | 2026-01-08 00:27:41.426602 | TASK [Find the full path of the Python interpreter] 2026-01-08 00:27:41.679673 | controller | /usr/bin/python3 2026-01-08 00:27:42.003342 | controller | ok 2026-01-08 00:27:42.011801 | 2026-01-08 00:27:42.011914 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-01-08 00:27:42.947573 | controller | created virtual environment CPython3.11.0.final.0-64 in 528ms 2026-01-08 00:27:42.982084 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-01-08 00:27:42.982101 | 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-01-08 00:27:42.982110 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-01-08 00:27:42.982123 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-01-08 00:27:43.057005 | controller | changed 2026-01-08 00:27:43.070537 | 2026-01-08 00:27:43.070681 | TASK [Set selinux package] 2026-01-08 00:27:43.111829 | controller | ok 2026-01-08 00:27:43.125510 | 2026-01-08 00:27:43.126231 | TASK [Set selinux package (Fedora)] 2026-01-08 00:27:43.189053 | controller | ok 2026-01-08 00:27:43.201207 | 2026-01-08 00:27:43.201350 | TASK [Install selinux into virtualenv] 2026-01-08 00:27:54.700542 | controller | Collecting selinux-please-lie-to-me 2026-01-08 00:28:06.956064 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-01-08 00:28:07.258529 | controller | Collecting setuptools<50.0.0 2026-01-08 00:28:07.263330 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-01-08 00:28:07.300419 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.2 MB/s eta 0:00:00 2026-01-08 00:28:07.381302 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-01-08 00:28:07.381420 | controller | Attempting uninstall: setuptools 2026-01-08 00:28:07.383799 | controller | Found existing installation: setuptools 62.6.0 2026-01-08 00:28:07.445154 | controller | Uninstalling setuptools-62.6.0: 2026-01-08 00:28:07.452955 | controller | Successfully uninstalled setuptools-62.6.0 2026-01-08 00:28:07.805808 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-01-08 00:28:19.333183 | controller | 2026-01-08 00:28:19.421422 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-08 00:28:19.421535 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-08 00:28:19.778349 | controller | ok: Runtime: 0:00:35.987090 2026-01-08 00:28:19.786961 | 2026-01-08 00:28:19.787148 | TASK [Install pytest-forked into virtualenv] 2026-01-08 00:28:31.575149 | controller | Collecting pytest-forked 2026-01-08 00:28:43.819436 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-01-08 00:28:43.862819 | controller | Collecting py 2026-01-08 00:28:43.867438 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-01-08 00:28:43.886203 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.8 MB/s eta 0:00:00 2026-01-08 00:28:43.992635 | controller | Collecting pytest>=3.10 2026-01-08 00:28:43.996023 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-01-08 00:28:44.021335 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 16.3 MB/s eta 0:00:00 2026-01-08 00:28:44.054864 | controller | Collecting iniconfig>=1.0.1 2026-01-08 00:28:44.058689 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-01-08 00:28:44.106146 | controller | Collecting packaging>=22 2026-01-08 00:28:44.110502 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2026-01-08 00:28:44.117638 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 12.6 MB/s eta 0:00:00 2026-01-08 00:28:44.149464 | controller | Collecting pluggy<2,>=1.5 2026-01-08 00:28:44.152762 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-01-08 00:28:44.199310 | controller | Collecting pygments>=2.7.2 2026-01-08 00:28:44.205183 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-01-08 00:28:44.242428 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 35.8 MB/s eta 0:00:00 2026-01-08 00:28:44.316920 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-01-08 00:28:45.364198 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-01-08 00:28:45.372865 | controller | 2026-01-08 00:28:45.439834 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2026-01-08 00:28:45.439867 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-01-08 00:28:45.844267 | controller | ok: Runtime: 0:00:25.442678 2026-01-08 00:28:45.858604 | 2026-01-08 00:28:45.858791 | TASK [Update pip] 2026-01-08 00:28:46.403839 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-01-08 00:28:53.705472 | controller | Collecting pip 2026-01-08 00:29:29.968282 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2026-01-08 00:29:30.017043 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 41.1 MB/s eta 0:00:00 2026-01-08 00:29:30.082391 | controller | Installing collected packages: pip 2026-01-08 00:29:30.082643 | controller | Attempting uninstall: pip 2026-01-08 00:29:30.084901 | controller | Found existing installation: pip 22.2.2 2026-01-08 00:29:30.221102 | controller | Uninstalling pip-22.2.2: 2026-01-08 00:29:30.236337 | controller | Successfully uninstalled pip-22.2.2 2026-01-08 00:29:31.019886 | controller | Successfully installed pip-25.3 2026-01-08 00:29:31.445603 | controller | ok: Runtime: 0:00:44.995894 2026-01-08 00:29:31.459086 | 2026-01-08 00:29:31.459289 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-01-08 00:29:31.676355 | controller | changed 2026-01-08 00:29:31.684821 | 2026-01-08 00:29:31.684986 | TASK [Install ansible into virtualenv] 2026-01-08 00:29:32.246108 | controller | Processing ./src/github.com/ansible/ansible 2026-01-08 00:29:32.249328 | controller | Installing build dependencies: started 2026-01-08 00:29:54.851692 | controller | Installing build dependencies: finished with status 'done' 2026-01-08 00:29:54.852814 | controller | Getting requirements to build wheel: started 2026-01-08 00:29:55.588598 | controller | Getting requirements to build wheel: finished with status 'done' 2026-01-08 00:29:55.589899 | controller | Preparing metadata (pyproject.toml): started 2026-01-08 00:29:56.051624 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-01-08 00:29:56.056787 | 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-01-08 00:29:56.060145 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-01-08 00:29:56.286904 | controller | ERROR 2026-01-08 00:29:56.287367 | controller | { 2026-01-08 00:29:56.287448 | controller | "delta": "0:00:24.185251", 2026-01-08 00:29:56.287493 | controller | "end": "2026-01-08 00:29:56.140932", 2026-01-08 00:29:56.287531 | controller | "msg": "non-zero return code", 2026-01-08 00:29:56.287595 | controller | "rc": 1, 2026-01-08 00:29:56.287631 | controller | "start": "2026-01-08 00:29:31.955681" 2026-01-08 00:29:56.287663 | controller | } failure 2026-01-08 00:29:56.292819 | 2026-01-08 00:29:56.293049 | PLAY RECAP 2026-01-08 00:29:56.293131 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-01-08 00:29:56.293162 | 2026-01-08 00:29:56.474349 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-01-08 00:29:56.475615 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-08 00:29:57.077780 | 2026-01-08 00:29:57.077900 | PLAY [all] 2026-01-08 00:29:57.100086 | 2026-01-08 00:29:57.100184 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-01-08 00:29:57.374156 | controller | changed: non-zero return code 2026-01-08 00:29:57.386936 | 2026-01-08 00:29:57.387099 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-01-08 00:29:57.413087 | controller | skipping: Conditional result was False 2026-01-08 00:29:57.422465 | 2026-01-08 00:29:57.422584 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-01-08 00:29:57.448503 | 2026-01-08 00:29:57.448704 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-01-08 00:29:57.473193 | 2026-01-08 00:29:57.473387 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-01-08 00:29:57.498653 | controller | skipping: Conditional result was False 2026-01-08 00:29:57.509579 | 2026-01-08 00:29:57.509673 | LOOP [fetch-subunit-output : Generate subunit file] 2026-01-08 00:29:57.543778 | 2026-01-08 00:29:57.543978 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-01-08 00:29:57.559207 | controller | skipping: Conditional result was False 2026-01-08 00:29:57.568824 | 2026-01-08 00:29:57.568929 | TASK [fetch-subunit-output : Remove the temporary file] 2026-01-08 00:29:57.583991 | controller | skipping: Conditional result was False 2026-01-08 00:29:57.593635 | 2026-01-08 00:29:57.593761 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-01-08 00:29:57.608495 | controller | skipping: Conditional result was False 2026-01-08 00:29:57.648385 | 2026-01-08 00:29:57.648493 | PLAY RECAP 2026-01-08 00:29:57.648540 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-01-08 00:29:57.648566 | 2026-01-08 00:29:57.748336 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-01-08 00:29:57.749242 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-01-08 00:29:58.338543 | 2026-01-08 00:29:58.338679 | PLAY [all:!appliance*] 2026-01-08 00:29:58.369358 | 2026-01-08 00:29:58.369490 | TASK [unregister the node] 2026-01-08 00:29:58.901101 | controller | skipping: Conditional result was False 2026-01-08 00:29:58.910201 | 2026-01-08 00:29:58.910401 | TASK [include_role : fetch-output] 2026-01-08 00:29:58.958431 | controller | ok 2026-01-08 00:29:58.992839 | 2026-01-08 00:29:58.993017 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-08 00:29:59.081470 | controller | skipping: Conditional result was False 2026-01-08 00:29:59.087991 | 2026-01-08 00:29:59.088064 | TASK [fetch-output : Set log path for single node] 2026-01-08 00:29:59.136607 | controller | ok 2026-01-08 00:29:59.149981 | 2026-01-08 00:29:59.150133 | LOOP [fetch-output : Ensure local output dirs] 2026-01-08 00:29:59.596779 | controller -> localhost | ok: "/var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/logs" 2026-01-08 00:29:59.885397 | controller -> localhost | changed: "/var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/artifacts" 2026-01-08 00:30:00.138354 | controller -> localhost | changed: "/var/lib/zuul/builds/a10247af512c4daab42128ee07954e1a/work/docs" 2026-01-08 00:30:00.156240 | 2026-01-08 00:30:00.156380 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-08 00:30:00.775761 | controller | changed: 2026-01-08 00:30:00.776023 | controller | .d..t...... ./ 2026-01-08 00:30:00.776062 | controller | cd+++++++++ controller/ 2026-01-08 00:30:00.776110 | controller | changed: All items complete 2026-01-08 00:30:00.776141 | 2026-01-08 00:30:01.241692 | controller | changed: .d..t...... ./ 2026-01-08 00:30:01.768303 | controller | changed: .d..t...... ./ 2026-01-08 00:30:01.807226 | 2026-01-08 00:30:01.807393 | TASK [include_role : fetch-output-openshift] 2026-01-08 00:30:01.835106 | controller | skipping: Conditional result was False 2026-01-08 00:30:01.849662 | 2026-01-08 00:30:01.849901 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-08 00:30:01.902296 | controller | skipping: Conditional result was False 2026-01-08 00:30:01.915470 | controller | skipping: Conditional result was False 2026-01-08 00:30:01.951855 | 2026-01-08 00:30:01.951967 | PLAY [localhost] 2026-01-08 00:30:01.965229 | 2026-01-08 00:30:01.965393 | TASK [Run Zuul manifest role] 2026-01-08 00:30:01.984031 | localhost | ok 2026-01-08 00:30:01.998330 | 2026-01-08 00:30:01.998422 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-08 00:30:02.393528 | localhost | changed 2026-01-08 00:30:02.398019 | 2026-01-08 00:30:02.398082 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-08 00:30:02.426278 | localhost | ok 2026-01-08 00:30:02.434285 | 2026-01-08 00:30:02.434361 | TASK [Set zuul-log-path fact] 2026-01-08 00:30:02.451974 | localhost | ok 2026-01-08 00:30:02.466027 | 2026-01-08 00:30:02.466093 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-08 00:30:02.495702 | localhost | ok 2026-01-08 00:30:02.507302 | 2026-01-08 00:30:02.507392 | LOOP [Run upload-logs-swift role] 2026-01-08 00:30:02.533332 | localhost | Output suppressed because no_log was given 2026-01-08 00:30:02.569871 | 2026-01-08 00:30:02.570023 | TASK [Set zuul-log-path fact] 2026-01-08 00:30:02.605967 | localhost | skipping: Conditional result was False 2026-01-08 00:30:02.611533 | 2026-01-08 00:30:02.611631 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-01-08 00:30:03.037307 | localhost -> localhost | ok: Runtime: 0:00:00.005438 2026-01-08 00:30:03.081438 | 2026-01-08 00:30:03.081594 | TASK [upload-logs-swift : Upload logs to swift]